[Varnish] #1033: purge; in vcl_pass
Varnish
varnish-bugs at varnish-cache.org
Mon Apr 30 12:48:22 CEST 2012
#1033: purge; in vcl_pass
----------------------+-----------------------------------------------------
Reporter: kristian | Owner:
Type: defect | Status: new
Priority: normal | Milestone:
Component: varnishd | Version: trunk
Severity: normal | Keywords:
----------------------+-----------------------------------------------------
Description changed by kristian:
Old description:
> 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
> }}}
New description:
In short: without purge; in vcl_pass, hitpass objects become an issue.
Longer: We currently offer purge; in vcl_hit and vcl_miss, but NOT in
vcl_pass. This means that we can not purge hitpass objects, since a
hitpass object would take us through vcl_pass. This is also why we've
discussed using 'return (purge);' or similar semantics in vcl_lookup
instead.
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#comment:1>
Varnish <https://varnish-cache.org/>
The Varnish HTTP Accelerator
More information about the varnish-bugs
mailing list