[Varnish] #1033: purge; in vcl_pass

Varnish varnish-bugs at varnish-cache.org
Thu Oct 13 15:13:48 CEST 2011


#1033: purge; in vcl_pass
----------------------+-----------------------------------------------------
 Reporter:  kristian  |       Owner:       
     Type:  defect    |      Status:  new  
 Priority:  normal    |   Milestone:       
Component:  varnishd  |     Version:  trunk
 Severity:  normal    |    Keywords:       
----------------------+-----------------------------------------------------
 In short: without purge; in vcl_pass, hitpass objects become an issue.

 Demonstration:
 {{{

 varnishtest "Test purge;"

 # This test first gets object 1, then purges it, then gets object 2, which
 # is a hit-for-pass, then issues a purge-command, then gets object 3,
 which
 # is supposed to be cached, then tries to get object 3 once more.
 # Lack of purge; in vcl_pass, however, means that the hit-for-pass object
 # resulting from object 2 is kept, so object 3 doesn't get cached and the
 # last request instead gets a fourth object.

 server s1 {
         rxreq
         txresp -status 200 -hdr foo:1

         rxreq
         txresp -status 200 -hdr foo:2

         rxreq
         txresp -status 200 -hdr foo:3

         rxreq
         txresp -status 200 -hdr foo:4
 } -start

 varnish v1 -vcl+backend {
         sub vcl_recv {
                 return (lookup);
         }
         sub vcl_hit {
                 if (req.request == "PURGE") {
                         purge;
                         error 200 "PURGED";
                 }
         }
         sub vcl_miss {
                 if (req.request == "PURGE") {
                         purge;
                         error 200 "PURGED404";
                 }
         }
         sub vcl_pass {
                 if (req.request == "PURGE") {
                         // purge; NOT SUPPORTED
                         error 200 "PURGEPASS";
                 }
         }
         sub vcl_fetch {
                 set beresp.ttl = 5s;
                 if (beresp.http.foo ~ "2") {
                         return (hit_for_pass);
                 }
         }
 } -start

 client c1 {
         txreq -req GET
         rxresp
         expect resp.status == 200
         expect resp.http.foo == 1

         txreq -req PURGE
         rxresp
         expect resp.status == 200
 } -run

 delay 0.5

 client c2 {
         txreq -req GET
         rxresp
         expect resp.status == 200
         expect resp.http.foo == 2

         txreq -req PURGE
         rxresp
         expect resp.status == 200
 } -run

 delay 0.5

 client c3 {
         txreq -req GET
         rxresp
         expect resp.status == 200
         expect resp.http.foo == 3

         txreq -req GET
         rxresp
         expect resp.status == 200
         expect resp.http.foo == 3
 } -run
 }}}

 Output snippets:

 {{{

 kristian at freud:~$ varnishtest foo.vtc | grep -v 'vsl|'
 [...]
 *    top   0.0 TEST foo.vtc starting
 [...]
 **   c1    0.3 Starting client
 [...]
 **** c1    0.3 txreq| GET / HTTP/1.1\r\n
 **** c1    0.3 txreq| \r\n
 ***  c1    0.3 rxresp
 ***  s1    0.3 accepted fd 4
 ***  s1    0.3 rxreq
 **** s1    0.3 rxhdr| GET / HTTP/1.1\r\n
 **** s1    0.3 rxhdr| X-Varnish: 1001\r\n
 **** s1    0.3 rxhdr| Accept-Encoding: gzip\r\n
 **** s1    0.3 rxhdr| Host: 127.0.0.1\r\n
 **** s1    0.3 rxhdr| \r\n
 **** s1    0.3 http[ 0] | GET
 **** s1    0.3 http[ 1] | /
 **** s1    0.3 http[ 2] | HTTP/1.1
 **** s1    0.3 http[ 3] | X-Varnish: 1001
 **** s1    0.3 http[ 4] | Accept-Encoding: gzip
 **** s1    0.3 http[ 5] | Host: 127.0.0.1
 **** s1    0.3 bodylen = 0
 ***  s1    0.3 txresp
 **** s1    0.3 txresp| HTTP/1.1 200 Ok\r\n
 **** s1    0.3 txresp| foo:1\r\n
 **** s1    0.3 txresp| Content-Length: 0\r\n
 **** s1    0.3 txresp| \r\n
 ***  s1    0.3 rxreq
 **** c1    0.3 rxhdr| HTTP/1.1 200 Ok\r\n
 **** c1    0.3 rxhdr| foo:1\r\n
 **** c1    0.3 rxhdr| Content-Length: 0\r\n
 **** c1    0.3 rxhdr| Accept-Ranges: bytes\r\n
 **** c1    0.3 rxhdr| Date: Thu, 13 Oct 2011 13:09:57 GMT\r\n
 **** c1    0.3 rxhdr| X-Varnish: 1001\r\n
 **** c1    0.3 rxhdr| Age: 0\r\n
 **** c1    0.3 rxhdr| Via: 1.1 varnish\r\n
 **** c1    0.3 rxhdr| Connection: keep-alive\r\n
 **** c1    0.3 rxhdr| \r\n
 **** c1    0.3 http[ 0] | HTTP/1.1
 **** c1    0.3 http[ 1] | 200
 **** c1    0.3 http[ 2] | Ok
 **** c1    0.3 http[ 3] | foo:1
 **** c1    0.3 http[ 4] | Content-Length: 0
 **** c1    0.3 http[ 5] | Accept-Ranges: bytes
 **** c1    0.3 http[ 6] | Date: Thu, 13 Oct 2011 13:09:57 GMT
 **** c1    0.3 http[ 7] | X-Varnish: 1001
 **** c1    0.3 http[ 8] | Age: 0
 **** c1    0.3 http[ 9] | Via: 1.1 varnish
 **** c1    0.3 http[10] | Connection: keep-alive
 **** c1    0.3 bodylen = 0
 ***  c1    0.3 expect
 **** c1    0.3 EXPECT resp.status (200) == 200 (200) match
 ***  c1    0.3 expect
 **** c1    0.3 EXPECT resp.http.foo (1) == 1 (1) match
 ***  c1    0.3 txreq
 **** c1    0.3 txreq| PURGE / HTTP/1.1\r\n
 **** c1    0.3 txreq| \r\n
 ***  c1    0.3 rxresp
 **** c1    0.3 rxhdr| HTTP/1.1 200 PURGED\r\n
 **** c1    0.3 rxhdr| Server: Varnish\r\n
 **** c1    0.3 rxhdr| Content-Type: text/html; charset=utf-8\r\n
 **** c1    0.3 rxhdr| Retry-After: 5\r\n
 **** c1    0.3 rxhdr| Content-Length: 374\r\n
 **** c1    0.3 rxhdr| Accept-Ranges: bytes\r\n
 **** c1    0.3 rxhdr| Date: Thu, 13 Oct 2011 13:09:57 GMT\r\n
 **** c1    0.3 rxhdr| X-Varnish: 1002\r\n
 **** c1    0.3 rxhdr| Age: 0\r\n
 **** c1    0.3 rxhdr| Via: 1.1 varnish\r\n
 **** c1    0.3 rxhdr| Connection: close\r\n
 **** c1    0.3 rxhdr| \r\n
 **** c1    0.3 http[ 0] | HTTP/1.1
 **** c1    0.3 http[ 1] | 200
 **** c1    0.3 http[ 2] | PURGED
 **** c1    0.3 http[ 3] | Server: Varnish
 **** c1    0.3 http[ 4] | Content-Type: text/html; charset=utf-8
 **** c1    0.3 http[ 5] | Retry-After: 5
 **** c1    0.3 http[ 6] | Content-Length: 374
 **** c1    0.3 http[ 7] | Accept-Ranges: bytes
 **** c1    0.3 http[ 8] | Date: Thu, 13 Oct 2011 13:09:57 GMT
 **** c1    0.3 http[ 9] | X-Varnish: 1002
 **** c1    0.3 http[10] | Age: 0
 **** c1    0.3 http[11] | Via: 1.1 varnish
 **** c1    0.3 http[12] | Connection: close
 **** c1    0.3 body| \n
 [...]
 **** c1    0.3 bodylen = 374
 ***  c1    0.3 expect
 **** c1    0.3 EXPECT resp.status (200) == 200 (200) match
 ***  c1    0.3 closing fd 10
 **   c1    0.3 Ending
 ***  top   0.3 delay
 ***  top   0.3 delaying 0.5 second(s)

 ***  top   0.8 client
 **   c2    0.8 Starting client
 **   c2    0.8 Waiting for client
 ***  c2    0.8 Connect to 127.0.0.1 59523
 ***  c2    0.8 connected fd 10 from 127.0.0.1 36136 to 127.0.0.1 59523
 ***  c2    0.8 txreq
 **** c2    0.8 txreq| GET / HTTP/1.1\r\n
 **** c2    0.8 txreq| \r\n
 ***  c2    0.8 rxresp
 **** s1    0.8 rxhdr| GET / HTTP/1.1\r\n
 **** s1    0.8 rxhdr| X-Varnish: 1003\r\n
 **** s1    0.8 rxhdr| Accept-Encoding: gzip\r\n
 **** s1    0.8 rxhdr| Host: 127.0.0.1\r\n
 **** s1    0.8 rxhdr| \r\n
 **** s1    0.8 http[ 0] | GET
 **** s1    0.8 http[ 1] | /
 **** s1    0.8 http[ 2] | HTTP/1.1
 **** s1    0.8 http[ 3] | X-Varnish: 1003
 **** s1    0.8 http[ 4] | Accept-Encoding: gzip
 **** s1    0.8 http[ 5] | Host: 127.0.0.1
 **** s1    0.8 bodylen = 0
 ***  s1    0.8 txresp
 **** s1    0.8 txresp| HTTP/1.1 200 Ok\r\n
 **** s1    0.8 txresp| foo:2\r\n
 **** s1    0.8 txresp| Content-Length: 0\r\n
 **** s1    0.8 txresp| \r\n
 ***  s1    0.8 rxreq
 **** c2    0.8 rxhdr| HTTP/1.1 200 Ok\r\n
 **** c2    0.8 rxhdr| foo:2\r\n
 **** c2    0.8 rxhdr| Content-Length: 0\r\n
 **** c2    0.8 rxhdr| Accept-Ranges: bytes\r\n
 **** c2    0.8 rxhdr| Date: Thu, 13 Oct 2011 13:09:57 GMT\r\n
 **** c2    0.8 rxhdr| X-Varnish: 1003\r\n
 **** c2    0.8 rxhdr| Age: 0\r\n
 **** c2    0.8 rxhdr| Via: 1.1 varnish\r\n
 **** c2    0.8 rxhdr| Connection: keep-alive\r\n
 **** c2    0.8 rxhdr| \r\n
 **** c2    0.8 http[ 0] | HTTP/1.1
 **** c2    0.8 http[ 1] | 200
 **** c2    0.8 http[ 2] | Ok
 **** c2    0.8 http[ 3] | foo:2
 **** c2    0.8 http[ 4] | Content-Length: 0
 **** c2    0.8 http[ 5] | Accept-Ranges: bytes
 **** c2    0.8 http[ 6] | Date: Thu, 13 Oct 2011 13:09:57 GMT
 **** c2    0.8 http[ 7] | X-Varnish: 1003
 **** c2    0.8 http[ 8] | Age: 0
 **** c2    0.8 http[ 9] | Via: 1.1 varnish
 **** c2    0.8 http[10] | Connection: keep-alive
 **** c2    0.8 bodylen = 0
 ***  c2    0.8 expect
 **** c2    0.8 EXPECT resp.status (200) == 200 (200) match
 ***  c2    0.8 expect
 **** c2    0.8 EXPECT resp.http.foo (2) == 2 (2) match
 ***  c2    0.8 txreq
 **** c2    0.8 txreq| PURGE / HTTP/1.1\r\n
 **** c2    0.8 txreq| \r\n
 ***  c2    0.8 rxresp
 **** c2    0.8 rxhdr| HTTP/1.1 200 PURGEPASS\r\n
 **** c2    0.8 rxhdr| Server: Varnish\r\n
 **** c2    0.8 rxhdr| Content-Type: text/html; charset=utf-8\r\n
 **** c2    0.8 rxhdr| Retry-After: 5\r\n
 **** c2    0.8 rxhdr| Content-Length: 383\r\n
 **** c2    0.8 rxhdr| Accept-Ranges: bytes\r\n
 **** c2    0.8 rxhdr| Date: Thu, 13 Oct 2011 13:09:57 GMT\r\n
 **** c2    0.8 rxhdr| X-Varnish: 1004\r\n
 **** c2    0.8 rxhdr| Age: 0\r\n
 **** c2    0.8 rxhdr| Via: 1.1 varnish\r\n
 **** c2    0.8 rxhdr| Connection: close\r\n
 **** c2    0.8 rxhdr| \r\n
 **** c2    0.8 http[ 0] | HTTP/1.1
 **** c2    0.8 http[ 1] | 200
 **** c2    0.8 http[ 2] | PURGEPASS
 **** c2    0.8 http[ 3] | Server: Varnish
 **** c2    0.8 http[ 4] | Content-Type: text/html; charset=utf-8
 **** c2    0.8 http[ 5] | Retry-After: 5
 **** c2    0.8 http[ 6] | Content-Length: 383
 **** c2    0.8 http[ 7] | Accept-Ranges: bytes
 **** c2    0.8 http[ 8] | Date: Thu, 13 Oct 2011 13:09:57 GMT
 **** c2    0.8 http[ 9] | X-Varnish: 1004
 **** c2    0.8 http[10] | Age: 0
 **** c2    0.8 http[11] | Via: 1.1 varnish
 **** c2    0.8 http[12] | Connection: close
 **** c2    0.8 body| \n
 [...]
 **** c2    0.8 bodylen = 383
 ***  c2    0.8 expect
 **** c2    0.8 EXPECT resp.status (200) == 200 (200) match
 ***  c2    0.8 closing fd 10
 **   c2    0.8 Ending
 ***  top   0.8 delay
 ***  top   0.8 delaying 0.5 second(s)
 ***  top   1.3 client
 **   c3    1.3 Starting client
 **   c3    1.3 Waiting for client
 ***  c3    1.3 Connect to 127.0.0.1 59523
 ***  c3    1.3 connected fd 10 from 127.0.0.1 36137 to 127.0.0.1 59523
 ***  c3    1.3 txreq
 **** c3    1.3 txreq| GET / HTTP/1.1\r\n
 **** c3    1.3 txreq| \r\n
 ***  c3    1.3 rxresp
 **** s1    1.3 rxhdr| GET / HTTP/1.1\r\n
 **** s1    1.3 rxhdr| X-Varnish: 1005\r\n
 **** s1    1.3 rxhdr| Host: 127.0.0.1\r\n
 **** s1    1.3 rxhdr| \r\n
 **** s1    1.3 http[ 0] | GET
 **** s1    1.3 http[ 1] | /
 **** s1    1.3 http[ 2] | HTTP/1.1
 **** s1    1.3 http[ 3] | X-Varnish: 1005
 **** s1    1.3 http[ 4] | Host: 127.0.0.1
 **** s1    1.3 bodylen = 0
 ***  s1    1.3 txresp
 **** s1    1.3 txresp| HTTP/1.1 200 Ok\r\n
 **** s1    1.3 txresp| foo:3\r\n
 **** s1    1.3 txresp| Content-Length: 0\r\n
 **** s1    1.3 txresp| \r\n
 ***  s1    1.3 rxreq
 **** c3    1.3 rxhdr| HTTP/1.1 200 Ok\r\n
 **** c3    1.3 rxhdr| foo:3\r\n
 **** c3    1.3 rxhdr| Content-Length: 0\r\n
 **** c3    1.3 rxhdr| Accept-Ranges: bytes\r\n
 **** c3    1.3 rxhdr| Date: Thu, 13 Oct 2011 13:09:58 GMT\r\n
 **** c3    1.3 rxhdr| X-Varnish: 1005\r\n
 **** c3    1.3 rxhdr| Age: 0\r\n
 **** c3    1.3 rxhdr| Via: 1.1 varnish\r\n
 **** c3    1.3 rxhdr| Connection: keep-alive\r\n
 **** c3    1.3 rxhdr| \r\n
 **** c3    1.3 http[ 0] | HTTP/1.1
 **** c3    1.3 http[ 1] | 200
 **** c3    1.3 http[ 2] | Ok
 **** c3    1.3 http[ 3] | foo:3
 **** c3    1.3 http[ 4] | Content-Length: 0
 **** c3    1.3 http[ 5] | Accept-Ranges: bytes
 **** c3    1.3 http[ 6] | Date: Thu, 13 Oct 2011 13:09:58 GMT
 **** c3    1.3 http[ 7] | X-Varnish: 1005
 **** c3    1.3 http[ 8] | Age: 0
 **** c3    1.3 http[ 9] | Via: 1.1 varnish
 **** c3    1.3 http[10] | Connection: keep-alive
 **** c3    1.3 bodylen = 0
 ***  c3    1.3 expect
 **** c3    1.3 EXPECT resp.status (200) == 200 (200) match
 ***  c3    1.3 expect
 **** c3    1.3 EXPECT resp.http.foo (3) == 3 (3) match
 ***  c3    1.3 txreq
 **** c3    1.3 txreq| GET / HTTP/1.1\r\n
 **** c3    1.3 txreq| \r\n
 ***  c3    1.3 rxresp
 **** s1    1.3 rxhdr| GET / HTTP/1.1\r\n
 **** s1    1.3 rxhdr| X-Varnish: 1006\r\n
 **** s1    1.3 rxhdr| Host: 127.0.0.1\r\n
 **** s1    1.3 rxhdr| \r\n
 **** s1    1.3 http[ 0] | GET
 **** s1    1.3 http[ 1] | /
 **** s1    1.3 http[ 2] | HTTP/1.1
 **** s1    1.3 http[ 3] | X-Varnish: 1006
 **** s1    1.3 http[ 4] | Host: 127.0.0.1
 **** s1    1.3 bodylen = 0
 ***  s1    1.3 txresp
 **** s1    1.3 txresp| HTTP/1.1 200 Ok\r\n
 **** s1    1.3 txresp| foo:4\r\n
 **** s1    1.3 txresp| Content-Length: 0\r\n
 **** s1    1.3 txresp| \r\n
 ***  s1    1.3 shutting fd 4
 **   s1    1.3 Ending
 **** c3    1.3 rxhdr| HTTP/1.1 200 Ok\r\n
 **** c3    1.3 rxhdr| foo:4\r\n
 **** c3    1.3 rxhdr| Content-Length: 0\r\n
 **** c3    1.3 rxhdr| Accept-Ranges: bytes\r\n
 **** c3    1.3 rxhdr| Date: Thu, 13 Oct 2011 13:09:58 GMT\r\n
 **** c3    1.3 rxhdr| X-Varnish: 1006\r\n
 **** c3    1.3 rxhdr| Age: 0\r\n
 **** c3    1.3 rxhdr| Via: 1.1 varnish\r\n
 **** c3    1.3 rxhdr| Connection: keep-alive\r\n
 **** c3    1.3 rxhdr| \r\n
 **** c3    1.3 http[ 0] | HTTP/1.1
 **** c3    1.3 http[ 1] | 200
 **** c3    1.3 http[ 2] | Ok
 **** c3    1.3 http[ 3] | foo:4
 **** c3    1.3 http[ 4] | Content-Length: 0
 **** c3    1.3 http[ 5] | Accept-Ranges: bytes
 **** c3    1.3 http[ 6] | Date: Thu, 13 Oct 2011 13:09:58 GMT
 **** c3    1.3 http[ 7] | X-Varnish: 1006
 **** c3    1.3 http[ 8] | Age: 0
 **** c3    1.3 http[ 9] | Via: 1.1 varnish
 **** c3    1.3 http[10] | Connection: keep-alive
 **** c3    1.3 bodylen = 0
 ***  c3    1.3 expect
 **** c3    1.3 EXPECT resp.status (200) == 200 (200) match
 ***  c3    1.3 expect
 ---- c3    1.3 EXPECT resp.http.foo (4) == 3 (3) failed
 *    top   1.3 RESETTING after foo.vtc
 **   s1    1.3 Waiting for server
 **** s1    1.3 macro undef s1_addr
 **** s1    1.3 macro undef s1_port
 **** s1    1.3 macro undef s1_sock
 **   v1    2.3 Wait
 **   v1    2.3 R 22659 Status: 0000
 *    top   2.3 TEST foo.vtc FAILED

 #     top  TEST foo.vtc FAILED (2.349) exit=1
 }}}

-- 
Ticket URL: <https://www.varnish-cache.org/trac/ticket/1033>
Varnish <https://varnish-cache.org/>
The Varnish HTTP Accelerator




More information about the varnish-bugs mailing list