varnish 3 - odd behaviour with using PURGE against cached objects

Wed Aug 14 07:56:47 CEST 2013

Hi all,

I've got varnish currently configured to server cached content for 300 secs.

I've also allowed varnish to accept purge requests (coming from a trusted list of IPs)

Watching varnish (using varnishlog), I can see a  PURGE request get successfully handled (I am sending the purge via php/curl_init  - even if I telnet directly to varnish and issue a direct http request, I still get the same 'success')

In this example, I want to clear the front page for a joomla site, from cache:

   11 SessionOpen  c 10.2.35.5 36978 :6081
   11 ReqStart     c 10.2.35.5 36978 806561070
   11 RxRequest    c PURGE
   11 RxURL        c /
   11 RxProtocol   c HTTP/1.0
   11 RxHeader     c Host: staging.site.com.au<http://staging.site.com.au/>
   11 RxHeader     c X-Real-IP: 117.53.165.104
   11 RxHeader     c X-Forwarded-For: 117.53.165.104
   11 RxHeader     c Connection: close
   11 RxHeader     c Accept: */*
   11 VCL_call     c recv
   11 VCL_acl      c MATCH purge 10.2.35.5
   11 VCL_return   c lookup
   11 VCL_call     c hash
   11 Hash         c /
   11 Hash         c staging.site.com.au<http://staging.site.com.au/>
   11 VCL_return   c hash
   11 Hit          c 806560950
   11 VCL_call     c hit error
   11 VCL_call     c error deliver
   11 VCL_call     c deliver deliver
   11 TxProtocol   c HTTP/1.1
   11 TxStatus     c 200
   11 TxResponse   c Purged.
   11 TxHeader     c Server: Varnish
   11 TxHeader     c Content-Type: text/html; charset=utf-8
   11 TxHeader     c Retry-After: 5
   11 TxHeader     c Content-Length: 382
   11 TxHeader     c Accept-Ranges: bytes
   11 TxHeader     c Date: Tue, 13 Aug 2013 06:17:36 GMT
   11 TxHeader     c X-Varnish: 806561070
   11 TxHeader     c Age: 0
   11 TxHeader     c Via: 1.1 varnish
   11 TxHeader     c Connection: close
   11 TxHeader     c X-Cache: MISS
   11 Length       c 382
   11 ReqEnd       c 806561070 1376374656.189619780 1376374656.189839363 0.000064850 0.000157595 0.000061989
   11 SessionClose c error
   11 StatSess     c 10.2.35.5 36978 0 1 1 0 0 0 259 382

BUT, if I then immediately hit that site, I serves up a page from cache that should have just been purged.

   11 SessionOpen  c 10.2.35.5 36979 :6081
   11 ReqStart     c 10.2.35.5 36979 806561071
   11 RxRequest    c GET
   11 RxURL        c /
   11 RxProtocol   c HTTP/1.0
   11 RxHeader     c Host: staging.site.com.au<http://staging.site.com.au/>
   11 RxHeader     c X-Real-IP: 150.101.113.35
   11 RxHeader     c X-Forwarded-For: 150.101.113.35
   11 RxHeader     c Connection: close
   11 RxHeader     c Cache-Control: no-cache
   11 RxHeader     c Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
   11 RxHeader     c Pragma: no-cache
   11 RxHeader     c User-Agent: Mozilla/5.0 (Windows NT 6.2; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/28.0.1500.95 Safari/537.36
   11 RxHeader     c Accept-Encoding: gzip,deflate,sdch
   11 RxHeader     c Accept-Language: en-US,en;q=0.8
   11 RxHeader     c Cookie: __gads=ID=1f70b5d5bf2eb903:T=1373344524:S=ALNI_MYS1RK-nxaklQLEIiCBMgSvpVDOXg; __utma=4009333.1369734685.1373238769.1373587007.1373846521.4; __utmc=4009333; __utmz=4009333.1373238769.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none); the_cookie194=
   11 VCL_call     c recv lookup
   11 VCL_call     c hash
   11 Hash         c /
   11 Hash         c staging.site.com.au<http://staging.site.com.au/>
   11 VCL_return   c hash
   11 Hit          c 806560950
   11 VCL_call     c hit deliver
   11 VCL_call     c deliver deliver
   11 TxProtocol   c HTTP/1.1
   11 TxStatus     c 200
   11 TxResponse   c OK
   11 TxHeader     c Server: Apache/2.2.22 (Ubuntu)
   11 TxHeader     c X-Powered-By: PHP/5.3.10-1ubuntu3.7
   11 TxHeader     c X-Logged-In: False
   11 TxHeader     c P3P: CP="NOI ADM DEV PSAi COM NAV OUR OTRo STP IND DEM"
   11 TxHeader     c Content-Encoding: gzip
   11 TxHeader     c X-Content-Encoded-By: Joomla! 2.5
   11 TxHeader     c Content-Type: text/html; charset=utf-8
   11 TxHeader     c Content-Length: 12287
   11 TxHeader     c Accept-Ranges: bytes
   11 TxHeader     c Date: Tue, 13 Aug 2013 06:17:49 GMT
   11 TxHeader     c X-Varnish: 806561071 806560950
   11 TxHeader     c Age: 288
   11 TxHeader     c Via: 1.1 varnish
   11 TxHeader     c Connection: close
   11 TxHeader     c X-Cache: HIT
   11 TxHeader     c X-Cache-Hits: 4
   11 Length       c 12287
   11 ReqEnd       c 806561071 1376374669.010172367 1376374669.010374069 0.000091553 0.000092268 0.000109434
   11 SessionClose c Connection: close

Here are the relevant snippets from the default.vcl

sub vcl_recv {
....
..
.
    if (req.request == "PURGE") {
        if (!client.ip ~ purge) {
        error 405 "Not allowed.";
    }
         return (lookup);
}

.....
..
.
}

sub vcl_hit {
   if (req.request == "PURGE") {
    error 200 "Purged.";
    }
}

sub vcl_miss {
    if (req.request == "PURGE") {
    error 404 "Not in cache.";
  }
}

The cached content isn't something that has been generated after the cache being cleared, as its age precedes the PURGE being issued.

Unless someone out there knows of a varnish plugin for joomla (similar to the 'varnish http purge' available for wordpress), then I need to be able to manually issue cache purges.

Cheers,

--
Paul McInerney
Senior Systems Administrator
Faredge Technology

P:   +2  8425 1410
F:   +2  8425 1489
M: +61 435 348 435
E:   paul.mcinerney at faredge.com.au

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://www.varnish-cache.org/lists/pipermail/varnish-misc/attachments/20130814/2fd2c6be/attachment-0001.html>