Hi Jason, Can you provide a full varnishlog output ? (not only -c nor -b)
Thierry ----------------- De : [email protected] [mailto:[email protected]] De la part de Jason Price Envoyé : vendredi 24 janvier 2014 22:29 À : [email protected] Objet : Re: beresp.ttl set to -1.000? 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
