Open
Description
Context:
- A client makes a partial request against Varnish:
Range: bytes=10-19. - Varnish is configured to
passthe request - The server responds with
Content-Range: bytes 10-19/*(andTransfer-Encoding: chunked, but not sure if that's necessary to reproduce)
Expected behavior:
- Varnish passes the partial response through (because
Content-Range: bytes 10-19/*appears to be correct?)
Current behavior:
- Varnish responds with a 503; varnishlog shows
Invalid content-range header
After delving deeper, this happens in cache_http.c at http_GetContentRange: lo gets set to 10, hi to 19, cl to -1, as expected; but then if (*lo >= cl || *hi >= cl) return (-2); returns -2 and fails the request, because 10 >= -1.
varnish-cache/bin/varnishd/cache/cache_http.c
Line 954 in 8f2c364
Not sure I fully understand the function, but should the condition be closer to if (*hi - *lo < cl) return (-2); ?
Here's a MWE VTC. Feel free to reuse.
varnishtest "Content-Range failure reproducer"
server s1 {
rxreq
txresp -status 206 -hdr "Transfer-Encoding: chunked" -hdr "content-range: bytes 10-19/*"
chunkedlen 10
chunkedlen 0
} -start
varnish v1 -vcl+backend {
sub vcl_recv {
return (pass);
}
} -start
client c1 {
txreq -hdr "range: bytes=10-19"
rxresp
expect resp.status != 503
} -run
Metadata
Metadata
Assignees
Labels
No labels
Type
Projects
Milestone
Relationships
Participants
Activity
range: New http_GetContentRange() semantics
dridi commentedon Mar 27, 2024
Can you please give #4091 a try?
delthas commentedon Mar 27, 2024
Thanks for the quick fix.
Testing with #4091, the issue looks partially fixed (no more 503 Invalid content-range header); but I'm seeing a very strange behavior. Varnish is sometimes responding with 416 "Requested Range Not Satisfiable" (just after it logs
Filters range). When I keep making the same request, it sometimes responds with 416 and sometimes with 206. I can't reproduce it in varnishtest (always 206).My cURL (repeated many times):
curl -v 'http://varnish/file.mp4' -H 'Range: bytes=52364-92712' -H 'Cache-Control: no-cache'varnishlog (censored) for 206:
varnishlog (censored) for 416:
The varnishlogs are exactly the same (except for stamps and ids), except after the
rangefilter, where in one case Varnish responds with 206, and in the other case it replies with 416. Repeating the cURL varies between the two responses, seemingly randomly.Edit: Managed to enable the Debug logs and got
RANGE_FAIL low range beyond objecton 416.This happens in http_GetRange:
https://github.com/varnishcache/varnish-cache/blob/master/bin/varnishd/cache/cache_http.c#L1010-L1024
In both cases, *lo = 33318; *hi=16769 (at the time of return). However in the 206 case, len = -1, so this returns early, and in the 416 case, len = 16770.
Looks like some race condition?
Edit: Looks like some race condition because adding a sleep in vcl_deliver makes it 406 almost 100% instead of 10%:
Sadly I still cannot reproduce this in varnishtest.
nigoroll commentedon May 24, 2024
@dridi I would think that, with streaming enabled, we would need to add
ObjWaitExtend(..., lo, ...).dridi commentedon May 27, 2024
This looks harder than I expected given how #4091 is structured.
tuaris commentedon Nov 7, 2024
I started seeing this after doing an upgrade from Varnish 6 to 7. Only happening with one of my backends that runs Backrop CMS
After some searching, I was able to 'make it work' by adding this to my VCL according to https://varnish-cache.org/docs/7.4/whats-new/upgrading-7.0.html. I'm not exactly sure if this is the correct way to fix it.
Happy to provide more information if needed: