<div dir="ltr"><div>Thank you for your help... In preparing the varnishlog output, I found my mistake.<br><br>The default.vcl code was checking for an Authorization header, and was instructing all code to return(pass); due to that.<br>
<br></div>--Jason<br><div><div><div><div><br><br></div></div></div></div></div><div class="gmail_extra"><br><br><div class="gmail_quote">On Mon, Jan 27, 2014 at 8:54 AM, MAGNIEN, Thierry <span dir="ltr"><<a href="mailto:thierry.magnien@sfr.com" target="_blank">thierry.magnien@sfr.com</a>></span> wrote:<br>
<blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">Hi Jason,<br>
<br>
Can you provide a full varnishlog output ? (not only -c nor -b)<br>
<br>
Thierry<br>
<br>
-----------------<br>
De : varnish-misc-bounces+thierry.magnien=<a href="mailto:sfr.com@varnish-cache.org">sfr.com@varnish-cache.org</a> [mailto:<a href="mailto:varnish-misc-bounces%2Bthierry.magnien">varnish-misc-bounces+thierry.magnien</a>=<a href="mailto:sfr.com@varnish-cache.org">sfr.com@varnish-cache.org</a>] De la part de Jason Price<br>

Envoyé : vendredi 24 janvier 2014 22:29<br>
À : <a href="mailto:varnish-misc@varnish-cache.org">varnish-misc@varnish-cache.org</a><br>
Objet : Re: beresp.ttl set to -1.000?<br>
<div class="HOEnZb"><div class="h5"><br>
So, no one has seen anything like this?<br>
I'm watching varnish override the backend's given TTL... and I can't fathom what is going on here.<br>
<br>
On Mon, Jan 20, 2014 at 9:00 PM, Jason Price <<a href="mailto:japrice@gmail.com">japrice@gmail.com</a>> wrote:<br>
I'm very confused. <br>
Despite backend headers instructing caching for 15 minutes, beresp.ttl get's overridden to be -1.000 immediately before vcl_fetch starts running.<br>
<br>
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.<br>
<br>
Backend response headers (via tcpdump/wireshark):<br>
<br>
Expires: Tue, 21 Jan 2014 01:35:54 GMT<br>
Cache-Control: max-age=900, s-maxage=900, public<br>
Vary: Accept-Encoding<br>
Vary: Accept-Encoding<br>
Content-Type: application/json<br>
<br>
Varnishlog output showing the two TTL lines.<br>
<br>
   10 TTL          c 562972947 RFC 900 -1 -1 1390267254 0 1390267254 1390268154 900<br>
   10 VCL_call     c fetch<br>
   10 TTL          c 562972947 VCL 120 -1 -1 1390267254 -0<br>
   10 VCL_return   c hit_for_pass<br>
<br>
So, vcl_fetch changes the ttl?<br>
<br>
Here's my modified vcl_fetch (faintly adapted from default.vcl for debugging):<br>
<br>
sub vcl_fetch {<br>
  if (beresp.ttl <= 0s) {<br>
    std.syslog((3*8)+5, "ttl fail");<br>
  }    <br>
  if (beresp.http.Set-Cookie) {<br>
    std.syslog((3*8)+5, "cookie fail");<br>
  }    <br>
  if (beresp.http.Vary == "*") {<br>
    std.syslog((3*8)+5, "Very fail");<br>
  }    <br>
  if (beresp.ttl <= 0s || beresp.http.Set-Cookie || beresp.http.Vary == "*") {<br>
    if (beresp.status == 400) {<br>
      set beresp.ttl = 5 s;<br>
      return (deliver);<br>
    } else if (beresp.status == 500) {<br>
      set beresp.ttl = 5 s;<br>
      std.syslog((3*8)+5, "beresp status code 500 for url request " + req.url);<br>
      return (deliver);<br>
    } else {   <br>
      /*               <br>
      * Mark as "Hit-For-Pass" for the next 2 minutes<br>
      */               <br>
      std.syslog((3 * 8) + 5, "what? beresp.ttl " + beresp.ttl +<br>
          " beresp.proto " + beresp.proto +<br>
          " beresp.status " + beresp.status +<br>
          " beresp.response " + beresp.response +<br>
          " beresp.backend.ip " + beresp.backend.ip +<br>
          " beresp.http.Set-Cookie is " + beresp.http.Set-Cookie + <br>
          " beresp.http.Vary is " + beresp.http.Vary +<br>
          " req.url is " + req.url);   <br>
      set beresp.ttl = 120 s;<br>
      return (hit_for_pass);<br>
    }          <br>
  }    <br>
  return (deliver);<br>
}<br>
And indeed, the logs show:<br>
<br>
Jan 21 01:20:54 devvcache4x00 varnishd[4761]: ttl fail<br>
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><br>

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).<br>
Varnish 3.0.4, with vmod_redis, vmod_digest<br>
Thank you for any help;<br>
Jason<br>
<br>
</div></div></blockquote></div><br></div>