So, no one has seen anything like this? I'm watching varnish override the backend's given TTL... and I can't fathom what is going on here.
On Mon, Jan 20, 2014 at 9:00 PM, Jason Price <[email protected]> wrote: > I'm very confused. > > Despite backend headers instructing caching for 15 minutes, beresp.ttl > get's overridden to be -1.000 immediately before vcl_fetch starts running. > > For the test, I restarted varnish, ran the test with an empty cache, and > validated at the end that only one connection/request had come in via > varnishstat. > > Backend response headers (via tcpdump/wireshark): > > Expires: Tue, 21 Jan 2014 01:35:54 GMT > Cache-Control: max-age=900, s-maxage=900, public > Vary: Accept-Encoding > Vary: Accept-Encoding > Content-Type: application/json > > Varnishlog output showing the two TTL lines. > > 10 TTL c 562972947 RFC 900 -1 -1 1390267254 0 1390267254 > 1390268154 900 > 10 VCL_call c fetch > 10 TTL c 562972947 VCL 120 -1 -1 1390267254 -0 > 10 VCL_return c hit_for_pass > > So, vcl_fetch changes the ttl? > > Here's my modified vcl_fetch (faintly adapted from default.vcl for > debugging): > > sub vcl_fetch { > if (beresp.ttl <= 0s) { > std.syslog((3*8)+5, "ttl fail"); > } > if (beresp.http.Set-Cookie) { > std.syslog((3*8)+5, "cookie fail"); > } > if (beresp.http.Vary == "*") { > std.syslog((3*8)+5, "Very fail"); > } > if (beresp.ttl <= 0s || beresp.http.Set-Cookie || beresp.http.Vary == > "*") { > if (beresp.status == 400) { > set beresp.ttl = 5 s; > return (deliver); > } else if (beresp.status == 500) { > set beresp.ttl = 5 s; > std.syslog((3*8)+5, "beresp status code 500 for url request " + > req.url); > return (deliver); > } else { > /* > * Mark as "Hit-For-Pass" for the next 2 minutes > */ > std.syslog((3 * 8) + 5, "what? beresp.ttl " + beresp.ttl + > " beresp.proto " + beresp.proto + > " beresp.status " + beresp.status + > " beresp.response " + beresp.response + > " beresp.backend.ip " + beresp.backend.ip + > " beresp.http.Set-Cookie is " + beresp.http.Set-Cookie + > " beresp.http.Vary is " + beresp.http.Vary + > " req.url is " + req.url); > set beresp.ttl = 120 s; > return (hit_for_pass); > } > } > return (deliver); > } > > And indeed, the logs show: > > Jan 21 01:20:54 devvcache4x00 varnishd[4761]: *ttl fail* > Jan 21 01:20:54 devvcache4x00 varnishd[4761]: what? *beresp.ttl > -1.000*beresp.proto HTTP/1.1 beresp.status 200 beresp.response OK > beresp.backend.ip 10.224.4.167 beresp.http.Set-Cookie is beresp.http.Vary > is Accept-Encoding, Accept-Encoding req.url is <elided> > > Why is beresp.ttl getting set to -1.000 ? I can't find anything > modifying beresp.ttl in my code (except what's above to set it to something > positive). > > Varnish 3.0.4, with vmod_redis, vmod_digest > > Thank you for any help; > Jason >
_______________________________________________ varnish-misc mailing list [email protected] https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc
