<div dir="ltr"><div class="gmail_extra">Is there any chance that:</div><div class="gmail_extra">- someone requested the object between the purge and the subsequent hit?</div><div class="gmail_extra">- you re-processed the request again, changing the cache (non-idempotent URL rewrite, maybe?)</div><div class="gmail_extra"><br clear="all"><div><div class="gmail_signature" data-smartmail="gmail_signature"><div dir="ltr"><div>-- <br></div>Guillaume Quintard<br></div></div></div>
<br><div class="gmail_quote">On Thu, Apr 13, 2017 at 8:21 AM, Nigel Peck <span dir="ltr"><<a href="mailto:np.lists@sharphosting.uk" target="_blank">np.lists@sharphosting.uk</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><br>
I have a strange problem, where it seems that purged objects are not being purged immediately, so the restarted request hits the object that was supposed to be purged, and then the next request for that object misses. Here are the relevant fields from a set of requests for the same object showing the sequence. That second restarted request should not be getting a hit, since it is a restart from a purge of that same object.<br>
<br>
This is CentOS 7/Varnish 4.0.4. No varying except on Accept-Encoding. Very little VCL. All cookies are removed in VCL_recv. TTL is set to 7 days in vcl_backend_response on anything that comes back with a 200 or 304.<br>
<br>
Any input greatly appreciated. It only seems to happen on images.<br>
<br>
--<br>
<br>
My VCL_purge is:<br>
<br>
sub vcl_purge {<br>
    set req.method = "GET";<br>
    return (restart);<br>
}<br>
<br>
In VCL_recv I have:<br>
<br>
if (req.method == "PURGE") {<br>
    if (!client.ip ~ purgers) {<br>
        return (synth(405, "Purging not allowed for " + client.ip));<br>
    }<br>
    return (purge);<br>
}<br>
<br>
--<br>
<br>
*   << Request  >> 100892<br>
-   Begin          req 100891 rxreq<br>
-   ReqMethod      PURGE<br>
-   VCL_call       RECV<br>
-   VCL_return     purge<br>
-   VCL_call       HASH<br>
-   VCL_return     lookup<br>
-   VCL_call       PURGE<br>
-   ReqMethod      GET<br>
-   VCL_return     restart<br>
-   Timestamp      Restart: 1492038073.166852 0.000092 0.000092<br>
-   Link           req 100893 restart<br>
-   End<br>
<br>
*   << Request  >> 100893<br>
-   Begin          req 100892 restart<br>
-   ReqMethod      GET<br>
-   VCL_call       RECV<br>
-   VCL_return     hash<br>
-   VCL_call       HASH<br>
-   VCL_return     lookup<br>
-   Hit            100603<br>
-   VCL_call       HIT<br>
-   VCL_return     deliver<br>
-   VCL_call       DELIVER<br>
-   VCL_return     deliver<br>
-   Timestamp      Process: 1492038073.166894 0.000133 0.000041<br>
-   Debug          "RES_MODE 2"<br>
-   Timestamp      Resp: 1492038073.166977 0.000216 0.000083<br>
-   Debug          "XXX REF 2"<br>
-   ReqAcct        275 0 275 347 4481 4828<br>
-   End<br>
<br>
*   << Request  >> 364403<br>
-   Begin          req 364402 rxreq<br>
-   ReqMethod      GET<br>
-   VCL_call       RECV<br>
-   VCL_return     hash<br>
-   VCL_call       HASH<br>
-   VCL_return     lookup<br>
-   Debug          "XXXX MISS"<br>
-   VCL_call       MISS<br>
-   VCL_return     fetch<br>
-   VCL_call       DELIVER<br>
-   RespHeader     X-Cache: MISS<br>
-   VCL_return     deliver<br>
-   Timestamp      Process: 1492046821.365675 0.003335 0.000031<br>
-   Debug          "RES_MODE 2"<br>
-   Timestamp      Resp: 1492046821.365740 0.003400 0.000065<br>
-   Debug          "XXX REF 2"<br>
-   ReqAcct        545 0 545 323 4481 4804<br>
-   End<br>
<br>
*   << Request  >> 364767<br>
-   Begin          req 364766 rxreq<br>
-   ReqMethod      GET<br>
-   VCL_call       RECV<br>
-   VCL_return     hash<br>
-   VCL_call       HASH<br>
-   VCL_return     lookup<br>
-   Hit            364404<br>
-   VCL_call       HIT<br>
-   VCL_return     deliver<br>
-   VCL_call       DELIVER<br>
-   RespHeader     X-Cache: HIT<br>
-   VCL_return     deliver<br>
-   Timestamp      Process: 1492056635.579030 0.000051 0.000051<br>
-   Debug          "RES_MODE 2"<br>
-   Timestamp      Resp: 1492056635.579060 0.000081 0.000031<br>
-   Debug          "XXX REF 2"<br>
-   ReqAcct        487 0 487 349 4481 4830<br>
-   End<br>
<br>
______________________________<wbr>_________________<br>
varnish-misc mailing list<br>
<a href="mailto:varnish-misc@varnish-cache.org" target="_blank">varnish-misc@varnish-cache.org</a><br>
<a href="https://www.varnish-cache.org/lists/mailman/listinfo/varnish-misc" rel="noreferrer" target="_blank">https://www.varnish-cache.org/<wbr>lists/mailman/listinfo/varnish<wbr>-misc</a><br>
</blockquote></div><br></div></div>