Not seeing a successful purge

John Norman john at 7fff.com
Fri Feb 12 17:54:52 CET 2010


Here's a bit more on my "purge" problem -- a comparison of a purge
that works on my development machine, vs. one that doesn't work on my
staging system.

On both, the browser request goes to haproxy, then to varnish. The VCL
is identical, as quoted in a prior e-mail. The backends are different:
on my local, it's the Ruby webrick server; on staging, it's
Apache+Passenger.

Again, I'm not purging through varnishadm: This is using the
pseudo-http-method PURGE.

One thing I can say about the staging environment if that if I do a
non-browser request using mechanize from the staging system itself,
then the later purge DOES work. In that case, the two differences are:
The user-agent is the same for both the get and the purge; and
requesting IP would be the same for both the get and the purge.

Here are the log details.

DEVELOPMENT -- first the browser request, showing the hit; then the
purge, showing the hit. Awesome!

11 ReqStart     c 127.0.0.1 50808 1691945259
11 RxRequest    c GET
11 RxURL        c /products/sillyputty
11 RxProtocol   c HTTP/1.1
11 RxHeader     c Host: localhost
11 RxHeader     c User-Agent: Mozilla/5.0 (Macintosh; U; Intel Mac OS
X 10.5; en-US; rv:1.9.1.7) Gecko/20091221 Firefox/3.5.7 GTB7.0
11 RxHeader     c Accept:
text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
11 RxHeader     c Accept-Language: en-us,en;q=0.5
11 RxHeader     c Accept-Encoding: gzip,deflate
11 RxHeader     c Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
11 RxHeader     c Keep-Alive: 300
11 RxHeader     c Connection: close
11 RxHeader     c Referer: http://localhost/
11 RxHeader     c Cookie:
remember_token=f27172bfab54dc47d20b6d8c853afb8677fa2d11
11 RxHeader     c X-Forwarded-For: 127.0.0.1
11 VCL_call     c recv
11 VCL_return   c lookup
11 VCL_call     c hash
11 VCL_return   c hash
11 Hit          c 1691945214
11 VCL_call     c hit
11 VCL_return   c deliver
11 Length       c 201518
11 VCL_call     c deliver
11 VCL_return   c deliver
11 TxProtocol   c HTTP/1.1
11 TxStatus     c 200
11 TxResponse   c OK
11 TxHeader     c Cache-Control: max-age=8280, public
11 TxHeader     c X-Runtime: 818
11 TxHeader     c Content-Type: text/html; charset=utf-8
11 TxHeader     c Etag: "f29fbc0160d276fb97a298bf5bce8ff3"
11 TxHeader     c Server: WEBrick/1.3.1 (Ruby/1.9.1/2009-07-16)
11 TxHeader     c Content-Length: 201518
11 TxHeader     c Date: Fri, 12 Feb 2010 16:19:33 GMT
11 TxHeader     c X-Varnish: 1691945259 1691945214
11 TxHeader     c Age: 14
11 TxHeader     c Via: 1.1 varnish
11 TxHeader     c Connection: close
11 ReqEnd       c 1691945259 1265991573.541040897 1265991573.547173977
0.000077009 0.000055075 0.006078005

11 ReqStart     c ::1 51006 1691945309
11 RxRequest    c PURGE
11 RxURL        c /products/sillyputty
11 RxProtocol   c HTTP/1.1
11 RxHeader     c Accept: */*
11 RxHeader     c User-Agent: WWW-Mechanize/1.0.0
(http://rubyforge.org/projects/mechanize/)
11 RxHeader     c Connection: keep-alive
11 RxHeader     c Keep-Alive: 300
11 RxHeader     c Accept-Encoding: gzip,identity
11 RxHeader     c Accept-Language: en-us,en;q=0.5
11 RxHeader     c Host: localhost:8000
11 RxHeader     c Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
11 VCL_call     c recv
11 VCL_return   c lookup
11 VCL_call     c hash
11 VCL_return   c hash
11 Hit          c 1691945214
11 VCL_call     c hit
11 TTL          c 1691945214 VCL 0 1265991617
 0 Debug        - "VCL_error(200, Purged.)"
11 VCL_return   c error
11 VCL_call     c error
11 VCL_return   c deliver
11 Length       c 322
11 VCL_call     c deliver
11 VCL_return   c deliver
11 TxProtocol   c HTTP/1.1
11 TxStatus     c 200
11 TxResponse   c Purged.
11 TxHeader     c Server: Varnish
11 TxHeader     c Retry-After: 0
11 TxHeader     c Content-Type: text/html; charset=utf-8
11 TxHeader     c Content-Length: 322
11 TxHeader     c Date: Fri, 12 Feb 2010 16:20:16 GMT
11 TxHeader     c X-Varnish: 1691945309
11 TxHeader     c Age: 0
11 TxHeader     c Via: 1.1 varnish
11 TxHeader     c Connection: close
11 ReqEnd       c 1691945309 1265991616.884471893 1265991616.884622097
0.000173807 0.000099182 0.000051022

---------------------------------------

Now my problematic STAGING system -- first the GET with the hit, then
the purge that fails to hit.

4 ReqStart     c 10.253.191.95 45944 904319331
4 RxRequest    c GET
4 RxURL        c /products/sillyputty
4 RxProtocol   c HTTP/1.1
4 RxHeader     c Host: staging1.example.com
4 RxHeader     c User-Agent: Mozilla/5.0 (Macintosh; U; Intel Mac OS X
10.5; en-US; rv:1.9.1.7) Gecko/20091221 Firefox/3.5.7 GTB7.0
4 RxHeader     c Accept:
text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
4 RxHeader     c Accept-Language: en-us,en;q=0.5
4 RxHeader     c Accept-Encoding: gzip,deflate
4 RxHeader     c Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
4 RxHeader     c Keep-Alive: 300
4 RxHeader     c Connection: keep-alive
4 RxHeader     c Referer: http://staging1.example.com/
4 RxHeader     c Cookie: cehq-id=10.252.66.194.1263417178788050;
__utma=240927894.185175319.1263417179.1265907679.1265923273.61;
__utmz=240927894.1263591912.11.2.utmcsr=localhost:3000|utmccn=(referral)|utmcmd=referral|utmcct=/;
__utma=229000926.194920698.1263480064.126592
4 RxHeader     c X-Forwarded-For: 75.150.106.113
4 VCL_call     c recv
4 VCL_return   c lookup
4 VCL_call     c hash
4 VCL_return   c hash
4 Hit          c 904319258
4 VCL_call     c hit
4 VCL_return   c deliver
4 Length       c 8471
4 VCL_call     c deliver
4 VCL_return   c deliver
4 TxProtocol   c HTTP/1.1
4 TxStatus     c 200
4 TxResponse   c OK
4 TxHeader     c Server: Apache/2.2.12 (Ubuntu)
4 TxHeader     c X-Powered-By: Phusion Passenger (mod_rails/mod_rack) 2.2.9
4 TxHeader     c Cache-Control: max-age=8520, public
4 TxHeader     c X-Runtime: 6052
4 TxHeader     c ETag: "94c1d0e1f26f0117dfc9bf3573a39f5a"
4 TxHeader     c Status: 200
4 TxHeader     c Vary: Accept-Encoding,User-Agent
4 TxHeader     c Content-Encoding: gzip
4 TxHeader     c Content-Type: text/html; charset=utf-8
4 TxHeader     c Content-Length: 8471
4 TxHeader     c Date: Fri, 12 Feb 2010 16:07:58 GMT
4 TxHeader     c X-Varnish: 904319331 904319258
4 TxHeader     c Age: 180
4 TxHeader     c Via: 1.1 varnish
4 TxHeader     c Connection: keep-alive
4 ReqEnd       c 904319331 1265990878.630007267 1265990878.630154371
0.000055075 0.000094652 0.000052452


4 ReqStart     c 10.253.191.95 38696 904319371
4 RxRequest    c PURGE
4 RxURL        c /products/sillyputty
4 RxProtocol   c HTTP/1.1
4 RxHeader     c Accept: */*
4 RxHeader     c User-Agent: WWW-Mechanize/1.0.0
(http://rubyforge.org/projects/mechanize/)
4 RxHeader     c Connection: keep-alive
4 RxHeader     c Keep-Alive: 300
4 RxHeader     c Accept-Encoding: gzip,identity
4 RxHeader     c Accept-Language: en-us,en;q=0.5
4 RxHeader     c Host: staging1.example.com:8000
4 RxHeader     c Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
4 VCL_call     c recv
4 VCL_return   c lookup
4 VCL_call     c hash
4 VCL_return   c hash
4 VCL_call     c miss
0 Debug        - "VCL_error(404, Not in cache.)"
4 VCL_return   c error
4 VCL_call     c error
4 VCL_return   c deliver
4 Length       c 340
4 VCL_call     c deliver
4 VCL_return   c deliver
4 TxProtocol   c HTTP/1.1
4 TxStatus     c 404
4 TxResponse   c Not in cache.
4 TxHeader     c Server: Varnish
4 TxHeader     c Retry-After: 0
4 TxHeader     c Content-Type: text/html; charset=utf-8
4 TxHeader     c Content-Length: 340
4 TxHeader     c Date: Fri, 12 Feb 2010 16:09:58 GMT
4 TxHeader     c X-Varnish: 904319371
4 TxHeader     c Age: 0
4 TxHeader     c Via: 1.1 varnish
4 TxHeader     c Connection: close
4 ReqEnd       c 904319371 1265990998.368539810 1265990998.368721724
0.000052691 0.000142813 0.000039101



More information about the varnish-misc mailing list