Skip to content

Instantly share code, notes, and snippets.

@andreacampi

andreacampi/gist:1437973

Created December 6, 2011 12:05
Show Gist options
  • Save andreacampi/1437973 to your computer and use it in GitHub Desktop.
Save andreacampi/1437973 to your computer and use it in GitHub Desktop.
Download ZIP
TEST ./tests/v00036.vtc FAILED
Raw
gistfile1.txt
# top TEST ./tests/v00034.vtc passed (0.553)
**** top 0.0 macro def varnishd=../varnishd/varnishd
**** top 0.0 macro def pwd=/usr/src/packages/BUILD/varnish-3.0.2/bin/varnishtest
**** top 0.0 macro def topbuild=/usr/src/packages/BUILD/varnish-3.0.2/bin/varnishtest/../..
**** top 0.0 macro def bad_ip=10.255.255.255
**** top 0.0 macro def tmpdir=/tmp/vtc.7037.6ff6e66c
* top 0.0 TEST ./tests/v00036.vtc starting
*** top 0.0 varnishtest
* top 0.0 TEST Test fallback director
*** top 0.0 server
** s1 0.0 Starting server
**** s1 0.0 macro def s1_addr=127.0.0.1
**** s1 0.0 macro def s1_port=52948
**** s1 0.0 macro def s1_sock=127.0.0.1 52948
* s1 0.0 Listen on 127.0.0.1 52948
** s1 0.0 Started on 127.0.0.1 52948
*** top 0.0 server
** s2 0.0 Starting server
**** s2 0.0 macro def s2_addr=127.0.0.1
**** s2 0.0 macro def s2_port=55240
**** s2 0.0 macro def s2_sock=127.0.0.1 55240
* s2 0.0 Listen on 127.0.0.1 55240
** s2 0.0 Started on 127.0.0.1 55240
*** top 0.0 server
** s3 0.0 Starting server
**** s3 0.0 macro def s3_addr=127.0.0.1
**** s3 0.0 macro def s3_port=44161
**** s3 0.0 macro def s3_sock=127.0.0.1 44161
* s3 0.0 Listen on 127.0.0.1 44161
** s3 0.0 Started on 127.0.0.1 44161
*** top 0.0 varnish
** v1 0.0 Launch
*** v1 0.0 CMD: cd ${pwd} && ${varnishd} -d -d -n /tmp/vtc.7037.6ff6e66c/v1 -l 10m,1m,- -p auto_restart=off -p syslog_cli_traffic=off -a '127.0.0.1:0' -S /tmp/vtc.7037.6ff6e66c/v1/_S -M '127.0.0.1 36896' -P /tmp/vtc.7037.6ff6e66c/v1/varnishd.pid -sfile,/tmp/vtc.7037.6ff6e66c/v1,10M
*** v1 0.0 CMD: cd /usr/src/packages/BUILD/varnish-3.0.2/bin/varnishtest && ../varnishd/varnishd -d -d -n /tmp/vtc.7037.6ff6e66c/v1 -l 10m,1m,- -p auto_restart=off -p syslog_cli_traffic=off -a '127.0.0.1:0' -S /tmp/vtc.7037.6ff6e66c/v1/_S -M '127.0.0.1 36896' -P /tmp/vtc.7037.6ff6e66c/v1/varnishd.pid -sfile,/tmp/vtc.7037.6ff6e66c/v1,10M
*** v1 0.0 PID: 21629
*** v1 0.0 debug| Platform: Linux,2.6.31.5-0.1-desktop,x86_64,-sfile,-smalloc,-hcritbit\n
*** v1 0.0 debug| 200 246 \n
*** v1 0.0 debug| -----------------------------\n
*** v1 0.0 debug| Varnish Cache CLI 1.0\n
*** v1 0.0 debug| -----------------------------\n
*** v1 0.0 debug| Linux,2.6.31.5-0.1-desktop,x86_64,-sfile,-smalloc,-hcritbit\n
*** v1 0.0 debug| \n
*** v1 0.0 debug| Type 'help' for command list.\n
*** v1 0.0 debug| Type 'quit' to close CLI session.\n
*** v1 0.0 debug| Type 'start' to launch worker process.\n
*** v1 0.0 debug| \n
**** v1 0.1 CLIPOLL 1 0x1 0x0
*** v1 0.1 CLI connection fd = 13
*** v1 0.1 CLI RX 107
**** v1 0.1 CLI RX| pxfqssckqymkofkwwuluhhlcgngbrqag\n
**** v1 0.1 CLI RX| \n
**** v1 0.1 CLI RX| Authentication required.\n
**** v1 0.1 CLI TX| auth 921dfcd45619c0ae459905861b68c73b924bfe4f3437f3f39836d5941d455905\n
*** v1 0.1 CLI RX 200
**** v1 0.1 CLI RX| -----------------------------\n
**** v1 0.1 CLI RX| Varnish Cache CLI 1.0\n
**** v1 0.1 CLI RX| -----------------------------\n
**** v1 0.1 CLI RX| Linux,2.6.31.5-0.1-desktop,x86_64,-sfile,-smalloc,-hcritbit\n
**** v1 0.1 CLI RX| \n
**** v1 0.1 CLI RX| Type 'help' for command list.\n
**** v1 0.1 CLI RX| Type 'quit' to close CLI session.\n
**** v1 0.1 CLI RX| Type 'start' to launch worker process.\n
**** v1 0.1 CLI TX| vcl.inline vcl1 << %XJEIFLH|)Xspa8P\n
**** v1 0.1 CLI TX| \n
**** v1 0.1 CLI TX| \n
**** v1 0.1 CLI TX| \tprobe p1 {\n
**** v1 0.1 CLI TX| \t\t.url = "/";\n
**** v1 0.1 CLI TX| \t\t.timeout = 1s;\n
**** v1 0.1 CLI TX| \t\t.interval = 1s;\n
**** v1 0.1 CLI TX| \t\t.window = 4;\n
**** v1 0.1 CLI TX| \t\t.threshold = 3;\n
**** v1 0.1 CLI TX| \t\t.initial = 0;\n
**** v1 0.1 CLI TX| \t}\n
**** v1 0.1 CLI TX| \tprobe p2 {\n
**** v1 0.1 CLI TX| \t\t.url = "/";\n
**** v1 0.1 CLI TX| \t\t.timeout = 1s;\n
**** v1 0.1 CLI TX| \t\t.interval = 1s;\n
**** v1 0.1 CLI TX| \t\t.window = 3;\n
**** v1 0.1 CLI TX| \t\t.threshold = 2;\n
**** v1 0.1 CLI TX| \t\t.initial = 0;\n
**** v1 0.1 CLI TX| \t}\n
**** v1 0.1 CLI TX| \n
**** v1 0.1 CLI TX| \tbackend b1 {\n
**** v1 0.1 CLI TX| \t\t.host = "127.0.0.1";\n
**** v1 0.1 CLI TX| \t\t.port = "52948";\n
**** v1 0.1 CLI TX| \t\t.max_connections = 1;\n
**** v1 0.1 CLI TX| \t\t.probe = p1;\n
**** v1 0.1 CLI TX| \t}\n
**** v1 0.1 CLI TX| \tbackend b2 {\n
**** v1 0.1 CLI TX| \t\t.host = "127.0.0.1";\n
**** v1 0.1 CLI TX| \t\t.port = "55240";\n
**** v1 0.1 CLI TX| \t\t.max_connections = 1;\n
**** v1 0.1 CLI TX| \t\t.probe = p2;\n
**** v1 0.1 CLI TX| \t}\n
**** v1 0.1 CLI TX| \tbackend b3 {\n
**** v1 0.1 CLI TX| \t\t.host = "127.0.0.1";\n
**** v1 0.1 CLI TX| \t\t.port = "4416...
*** v1 0.2 CLI RX 200
**** v1 0.2 CLI RX| VCL compiled.
**** v1 0.2 CLI TX| vcl.use vcl1
*** v1 0.2 CLI RX 200
** v1 0.2 Start
**** v1 0.2 CLI TX| start
*** v1 0.3 debug| child (21686) Started\n
**** v1 0.3 vsl| 0 WorkThread - 0x2b70c4e01cc0 start
**** v1 0.3 vsl| 0 CLI - Rd vcl.load "vcl1" ./vcl.GRfqjZzm.so
*** s1 0.3 accepted fd 4
*** s1 0.3 rxreq
**** s1 0.3 rxhdr| GET / HTTP/1.1\r\n
**** s1 0.3 rxhdr| Host: 127.0.0.1\r\n
**** s1 0.3 rxhdr| Connection: close\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] | Host: 127.0.0.1
**** s1 0.3 http[ 4] | Connection: close
**** s1 0.3 bodylen = 0
*** s1 0.3 expect
**** s1 0.3 EXPECT req.url (/) == / (/) match
*** s1 0.3 txresp
**** s1 0.3 txresp| HTTP/1.1 200 Ok\r\n
**** s1 0.3 txresp| Content-Length: 5\r\n
**** s1 0.3 txresp| \r\n
**** s1 0.3 txresp| slash
*** s1 0.3 close
**** s1 0.3 Closed
*** s1 0.3 sema
**** s1 0.3 Sema(r1) wait 1 of 3
*** s2 0.3 accepted fd 6
*** s2 0.3 rxreq
**** s2 0.3 rxhdr| GET / HTTP/1.1\r\n
**** s2 0.3 rxhdr| Host: 127.0.0.1\r\n
**** s2 0.3 rxhdr| Connection: close\r\n
**** s2 0.3 rxhdr| \r\n
**** s2 0.3 http[ 0] | GET
**** s2 0.3 http[ 1] | /
**** s2 0.3 http[ 2] | HTTP/1.1
**** s2 0.3 http[ 3] | Host: 127.0.0.1
**** s2 0.3 http[ 4] | Connection: close
**** s2 0.3 bodylen = 0
*** s2 0.3 expect
**** s2 0.3 EXPECT req.url (/) == / (/) match
*** s2 0.3 txresp
**** s2 0.3 txresp| HTTP/1.1 200 Ok\r\n
**** s2 0.3 txresp| Content-Length: 5\r\n
**** s2 0.3 txresp| \r\n
**** s2 0.3 txresp| slash
*** s2 0.3 close
**** s2 0.3 Closed
*** s2 0.3 sema
**** s2 0.3 Sema(r1) wait 2 of 3
**** v1 0.3 vsl| 0 Backend_health - b1 Went sick 4--X-RH 1 3 4 0.000242 0.000242 HTTP/1.1 200 Ok
**** v1 0.3 vsl| 0 Backend_health - b2 Went sick 4--X-RH 1 2 3 0.000189 0.000189 HTTP/1.1 200 Ok
**** v1 0.3 vsl| 0 CLI - Wr 200 36 Loaded "./vcl.GRfqjZzm.so" as "vcl1"
**** v1 0.3 vsl| 0 CLI - Rd vcl.use "vcl1"
**** v1 0.3 vsl| 0 CLI - Wr 200 0
**** v1 0.3 vsl| 0 CLI - Rd start
**** v1 0.3 vsl| 0 Debug - Acceptor is epoll
**** v1 0.3 vsl| 0 CLI - Wr 200 0
*** v1 0.3 CLI RX 200
**** v1 0.3 CLI TX| debug.xid 1000
*** v1 0.3 debug| Child (21686) said Not running as root, no priv-sep\n
*** v1 0.3 debug| Child (21686) said Child starts\n
*** v1 0.3 debug| Child (21686) said SMF.s0 mmap'ed 10485760 bytes of 10485760\n
**** v1 0.3 vsl| 0 WorkThread - 0x2b70c6e0ccc0 start
**** v1 0.3 vsl| 0 WorkThread - 0x2b70c700dcc0 start
**** v1 0.3 vsl| 0 WorkThread - 0x2b70c720ecc0 start
**** v1 0.3 vsl| 0 WorkThread - 0x2b70c740fcc0 start
**** v1 0.3 vsl| 0 WorkThread - 0x2b70c7610cc0 start
**** v1 0.3 vsl| 0 WorkThread - 0x2b70c7811cc0 start
**** v1 0.3 vsl| 0 WorkThread - 0x2b70c7a12cc0 start
**** v1 0.3 vsl| 0 WorkThread - 0x2b70c7c13cc0 start
**** v1 0.3 vsl| 0 WorkThread - 0x2b70c7e14cc0 start
*** v1 0.3 CLI RX 200
**** v1 0.3 CLI RX| XID is 1000
**** v1 0.3 CLI TX| debug.listen_address
**** v1 0.3 vsl| 0 CLI - Rd debug.xid 1000
**** v1 0.3 vsl| 0 CLI - Wr 200 11 XID is 1000
*** v1 0.4 CLI RX 200
**** v1 0.4 CLI RX| 127.0.0.1 40829\n
** v1 0.4 Listen on 127.0.0.1 40829
**** v1 0.4 macro def v1_addr=127.0.0.1
**** v1 0.4 macro def v1_port=40829
**** v1 0.4 macro def v1_sock=127.0.0.1 40829
*** top 0.4 client
** c1 0.4 Starting client
*** c1 0.4 Connect to 127.0.0.1 40829
*** c1 0.4 connected fd 4 from 127.0.0.1 47694 to 127.0.0.1 40829
*** c1 0.4 txreq
**** c1 0.4 txreq| GET /foo HTTP/1.1\r\n
**** c1 0.4 txreq| \r\n
*** c1 0.4 rxresp
*** s3 0.4 accepted fd 8
*** s3 0.4 rxreq
**** s3 0.4 rxhdr| GET /foo HTTP/1.1\r\n
**** s3 0.4 rxhdr| X-Varnish: 1001\r\n
**** s3 0.4 rxhdr| Host: 127.0.0.1\r\n
**** s3 0.4 rxhdr| \r\n
**** s3 0.4 http[ 0] | GET
**** s3 0.4 http[ 1] | /foo
**** s3 0.4 http[ 2] | HTTP/1.1
**** s3 0.4 http[ 3] | X-Varnish: 1001
**** s3 0.4 http[ 4] | Host: 127.0.0.1
**** s3 0.4 bodylen = 0
*** s3 0.4 expect
**** s3 0.4 EXPECT req.url (/foo) == /foo (/foo) match
*** s3 0.4 txresp
**** s3 0.4 txresp| HTTP/1.1 200 Ok\r\n
**** s3 0.4 txresp| Foo: 3\r\n
**** s3 0.4 txresp| Content-Length: 6\r\n
**** s3 0.4 txresp| \r\n
**** s3 0.4 txresp| foobar
*** s3 0.4 shutting fd 8
** s3 0.4 Ending
**** c1 0.4 rxhdr| HTTP/1.1 200 Ok\r\n
**** c1 0.4 rxhdr| Foo: 3\r\n
**** c1 0.4 rxhdr| Content-Length: 6\r\n
**** c1 0.4 rxhdr| Accept-Ranges: bytes\r\n
**** c1 0.4 rxhdr| Date: Tue, 06 Dec 2011 11:52:40 GMT\r\n
**** c1 0.4 rxhdr| X-Varnish: 1001\r\n
**** c1 0.4 rxhdr| Age: 0\r\n
**** c1 0.4 rxhdr| Via: 1.1 varnish\r\n
**** c1 0.4 rxhdr| Connection: keep-alive\r\n
**** c1 0.4 rxhdr| \r\n
**** c1 0.4 http[ 0] | HTTP/1.1
**** c1 0.4 http[ 1] | 200
**** c1 0.4 http[ 2] | Ok
**** c1 0.4 http[ 3] | Foo: 3
**** c1 0.4 http[ 4] | Content-Length: 6
**** c1 0.4 http[ 5] | Accept-Ranges: bytes
**** c1 0.4 http[ 6] | Date: Tue, 06 Dec 2011 11:52:40 GMT
**** c1 0.4 http[ 7] | X-Varnish: 1001
**** c1 0.4 http[ 8] | Age: 0
**** c1 0.4 http[ 9] | Via: 1.1 varnish
**** c1 0.4 http[10] | Connection: keep-alive
**** c1 0.4 body| foobar
**** c1 0.4 bodylen = 6
*** c1 0.4 expect
**** c1 0.4 EXPECT resp.http.foo (3) == 3 (3) match
*** c1 0.4 sema
**** c1 0.4 Sema(r1) wake 3
*** c1 0.4 sema
**** c1 0.4 Sema(r2) wait 1 of 2
*** s1 0.4 accept
**** s1 0.4 Accepting
*** s2 0.4 accept
**** s2 0.4 Accepting
** c1 0.4 Waiting for client
**** v1 0.4 vsl| 0 CLI - Rd debug.listen_address
**** v1 0.4 vsl| 0 CLI - Wr 200 16 127.0.0.1 40829
**** v1 0.4 vsl| 13 SessionOpen c 127.0.0.1 47694 127.0.0.1:0
**** v1 0.4 vsl| 13 ReqStart c 127.0.0.1 47694 1001
**** v1 0.4 vsl| 13 RxRequest c GET
**** v1 0.4 vsl| 13 RxURL c /foo
**** v1 0.4 vsl| 13 RxProtocol c HTTP/1.1
**** v1 0.4 vsl| 13 VCL_call c recv
**** v1 0.4 vsl| 13 VCL_return c pass
**** v1 0.4 vsl| 13 VCL_call c hash
**** v1 0.4 vsl| 13 Hash c /foo
**** v1 0.4 vsl| 13 Hash c 127.0.0.1
**** v1 0.4 vsl| 13 VCL_return c hash
**** v1 0.4 vsl| 13 VCL_call c pass
**** v1 0.4 vsl| 13 VCL_return c pass
**** v1 0.4 vsl| 14 BackendOpen b b3 127.0.0.1 48742 127.0.0.1 44161
**** v1 0.4 vsl| 13 Backend c 14 f1 b3
**** v1 0.4 vsl| 14 TxRequest b GET
**** v1 0.4 vsl| 14 TxURL b /foo
**** v1 0.4 vsl| 14 TxProtocol b HTTP/1.1
**** v1 0.4 vsl| 14 TxHeader b X-Varnish: 1001
**** v1 0.4 vsl| 14 TxHeader b Host: 127.0.0.1
**** v1 0.4 vsl| 14 RxProtocol b HTTP/1.1
**** v1 0.4 vsl| 14 RxStatus b 200
**** v1 0.4 vsl| 14 RxResponse b Ok
**** v1 0.4 vsl| 14 RxHeader b Foo: 3
**** v1 0.4 vsl| 14 RxHeader b Content-Length: 6
**** v1 0.4 vsl| 13 TTL c 1001 RFC 120 -1 -1 1323172361 0 0 0 0
**** v1 0.4 vsl| 13 VCL_call c fetch
**** v1 0.4 vsl| 13 TTL c 1001 VCL 120 -1 -1 1323172361 -0
**** v1 0.4 vsl| 13 VCL_return c hit_for_pass
**** v1 0.4 vsl| 13 ObjProtocol c HTTP/1.1
**** v1 0.4 vsl| 13 ObjResponse c Ok
**** v1 0.4 vsl| 13 ObjHeader c Foo: 3
**** v1 0.4 vsl| 13 ObjHeader c Content-Length: 6
**** v1 0.4 vsl| 14 Fetch_Body b 4(length) cls 0 mklen 1
**** v1 0.4 vsl| 14 Length b 6
**** v1 0.4 vsl| 14 BackendReuse b b3
**** v1 0.4 vsl| 13 VCL_call c deliver
**** v1 0.4 vsl| 13 VCL_return c deliver
**** v1 0.4 vsl| 13 TxProtocol c HTTP/1.1
**** v1 0.4 vsl| 13 TxStatus c 200
**** v1 0.4 vsl| 13 TxResponse c Ok
**** v1 0.4 vsl| 13 TxHeader c Foo: 3
**** v1 0.4 vsl| 13 TxHeader c Content-Length: 6
**** v1 0.4 vsl| 13 TxHeader c Accept-Ranges: bytes
**** v1 0.4 vsl| 13 TxHeader c Date: Tue, 06 Dec 2011 11:52:40 GMT
**** v1 0.4 vsl| 13 TxHeader c X-Varnish: 1001
**** v1 0.4 vsl| 13 TxHeader c Age: 0
**** v1 0.4 vsl| 13 TxHeader c Via: 1.1 varnish
**** v1 0.4 vsl| 13 TxHeader c Connection: keep-alive
**** v1 0.4 vsl| 13 Length c 6
**** v1 0.4 vsl| 13 ReqEnd c 1001 1323172360.912379742 1323172360.912665844 0.000035763 0.000257969 0.000028133
**** v1 0.4 vsl| 13 Debug c herding
*** s1 1.3 Accepted socket fd is 6
*** s1 1.3 rxreq
**** s1 1.3 rxhdr| GET / HTTP/1.1\r\n
**** s1 1.3 rxhdr| Host: 127.0.0.1\r\n
**** s1 1.3 rxhdr| Connection: close\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] | Host: 127.0.0.1
**** s1 1.3 http[ 4] | Connection: close
**** s1 1.3 bodylen = 0
*** s1 1.3 expect
**** s1 1.3 EXPECT req.url (/) == / (/) match
*** s1 1.3 txresp
**** s1 1.3 txresp| HTTP/1.1 200 Ok\r\n
**** s1 1.3 txresp| Content-Length: 5\r\n
**** s1 1.3 txresp| \r\n
**** s1 1.3 txresp| slash
*** s1 1.3 close
**** s1 1.3 Closed
*** s1 1.3 accept
**** s1 1.3 Accepting
*** s2 1.3 Accepted socket fd is 8
*** s2 1.3 rxreq
**** s2 1.3 rxhdr| GET / HTTP/1.1\r\n
**** s2 1.3 rxhdr| Host: 127.0.0.1\r\n
**** s2 1.3 rxhdr| Connection: close\r\n
**** s2 1.3 rxhdr| \r\n
**** s2 1.3 http[ 0] | GET
**** s2 1.3 http[ 1] | /
**** s2 1.3 http[ 2] | HTTP/1.1
**** s2 1.3 http[ 3] | Host: 127.0.0.1
**** s2 1.3 http[ 4] | Connection: close
**** s2 1.3 bodylen = 0
*** s2 1.3 expect
**** s2 1.3 EXPECT req.url (/) == / (/) match
*** s2 1.3 txresp
**** s2 1.3 txresp| HTTP/1.1 200 Ok\r\n
**** s2 1.3 txresp| Content-Length: 5\r\n
**** s2 1.3 txresp| \r\n
**** s2 1.3 txresp| slash
*** s2 1.3 close
**** s2 1.3 Closed
*** s2 1.3 sema
**** s2 1.3 Sema(r2) wake 2
*** s2 1.3 accept
**** s2 1.3 Accepting
*** c1 1.3 txreq
**** c1 1.3 txreq| GET /foo HTTP/1.1\r\n
**** c1 1.3 txreq| \r\n
*** c1 1.3 rxresp
**** v1 1.3 vsl| 0 Backend_health - b1 Still sick 4--X-RH 2 3 4 0.000251 0.000247 HTTP/1.1 200 Ok
**** v1 1.3 vsl| 13 ReqStart c 127.0.0.1 47694 1002
**** v1 1.3 vsl| 13 RxRequest c GET
**** v1 1.3 vsl| 13 RxURL c /foo
**** v1 1.3 vsl| 13 RxProtocol c HTTP/1.1
**** v1 1.3 vsl| 13 VCL_call c recv
**** v1 1.3 vsl| 13 VCL_return c pass
**** v1 1.3 vsl| 13 VCL_call c hash
**** v1 1.3 vsl| 13 Hash c /foo
**** v1 1.3 vsl| 13 Hash c 127.0.0.1
**** v1 1.3 vsl| 13 VCL_return c hash
**** v1 1.3 vsl| 13 VCL_call c pass
**** v1 1.3 vsl| 13 VCL_return c pass
**** v1 1.3 vsl| 14 BackendClose b b3
**** v1 1.3 vsl| 14 BackendOpen b b3 127.0.0.1 48745 127.0.0.1 44161
**** v1 1.3 vsl| 13 Backend c 14 f1 b3
**** v1 1.3 vsl| 14 TxRequest b GET
**** v1 1.3 vsl| 14 TxURL b /foo
**** v1 1.3 vsl| 14 TxProtocol b HTTP/1.1
**** v1 1.3 vsl| 14 TxHeader b X-Varnish: 1002
**** v1 1.3 vsl| 14 TxHeader b Host: 127.0.0.1
**** v1 1.3 vsl| 0 Backend_health - b2 Back healthy 4--X-RH 2 2 3 0.000316 0.000252 HTTP/1.1 200 Ok
*** s1 2.3 Accepted socket fd is 6
*** s1 2.3 rxreq
**** s1 2.3 rxhdr| GET / HTTP/1.1\r\n
**** s1 2.3 rxhdr| Host: 127.0.0.1\r\n
**** s1 2.3 rxhdr| Connection: close\r\n
**** s1 2.3 rxhdr| \r\n
**** s1 2.3 http[ 0] | GET
**** s1 2.3 http[ 1] | /
**** s1 2.3 http[ 2] | HTTP/1.1
**** s1 2.3 http[ 3] | Host: 127.0.0.1
**** s1 2.3 http[ 4] | Connection: close
**** s1 2.3 bodylen = 0
*** s1 2.3 expect
**** s1 2.3 EXPECT req.url (/) == / (/) match
*** s1 2.3 txresp
**** s1 2.3 txresp| HTTP/1.1 200 Ok\r\n
**** s1 2.3 txresp| Content-Length: 5\r\n
**** s1 2.3 txresp| \r\n
**** s1 2.3 txresp| slash
*** s1 2.3 close
**** s1 2.3 Closed
*** s1 2.3 sema
**** s1 2.3 Sema(r3) wait 1 of 2
*** s2 2.3 Accepted socket fd is 8
*** s2 2.3 rxreq
**** s2 2.3 rxhdr| GET / HTTP/1.1\r\n
**** s2 2.3 rxhdr| Host: 127.0.0.1\r\n
**** s2 2.3 rxhdr| Connection: close\r\n
**** s2 2.3 rxhdr| \r\n
**** s2 2.3 http[ 0] | GET
**** s2 2.3 http[ 1] | /
**** s2 2.3 http[ 2] | HTTP/1.1
**** s2 2.3 http[ 3] | Host: 127.0.0.1
**** s2 2.3 http[ 4] | Connection: close
**** s2 2.3 bodylen = 0
*** s2 2.3 expect
---- s2 2.3 EXPECT req.url (/) == /foo (/foo) failed
**** v1 2.3 vsl| 0 Backend_health - b1 Back healthy 4--X-RH 3 3 4 0.000250 0.000248 HTTP/1.1 200 Ok
**** v1 3.3 vsl| 0 CLI - Rd ping
**** v1 3.3 vsl| 0 CLI - Wr 200 19 PONG 1323172363 1.0
**** v1 3.3 vsl| 0 Backend_health - b2 Still healthy 4--X--- 2 2 3 0.000000 0.000252
**** v1 4.3 vsl| 0 Backend_health - b1 Still healthy 4--X--- 3 3 4 0.000000 0.000248
**** v1 5.3 vsl| 0 Backend_health - b2 Went sick 4--X--- 1 2 3 0.000000 0.000252
**** v1 6.3 vsl| 0 CLI - Rd ping
**** v1 6.3 vsl| 0 CLI - Wr 200 19 PONG 1323172366 1.0
**** v1 6.3 vsl| 0 Backend_health - b1 Went sick 4--X--- 2 3 4 0.000000 0.000248
**** v1 7.3 vsl| 0 Backend_health - b2 Still sick 4--X--- 0 2 3 0.000000 0.000252
**** v1 8.3 vsl| 0 Backend_health - b1 Still sick 4--X--- 1 3 4 0.000000 0.000248
**** v1 9.3 vsl| 0 CLI - Rd ping
**** v1 9.3 vsl| 0 CLI - Wr 200 19 PONG 1323172369 1.0
**** v1 9.3 vsl| 0 Backend_health - b2 Still sick 4--X--- 0 2 3 0.000000 0.000252
**** v1 10.3 vsl| 0 Backend_health - b1 Still sick 4--X--- 0 3 4 0.000000 0.000248
**** v1 11.3 vsl| 0 Backend_health - b2 Still sick 4--X--- 0 2 3 0.000000 0.000252
**** v1 12.3 vsl| 0 CLI - Rd ping
**** v1 12.3 vsl| 0 CLI - Wr 200 19 PONG 1323172372 1.0
**** v1 12.3 vsl| 0 Backend_health - b1 Still sick 4--X--- 0 3 4 0.000000 0.000248
**** v1 13.3 vsl| 0 Backend_health - b2 Still sick 4--X--- 0 2 3 0.000000 0.000252
**** v1 14.3 vsl| 0 Backend_health - b1 Still sick 4--X--- 0 3 4 0.000000 0.000248
**** v1 15.3 vsl| 0 CLI - Rd ping
**** v1 15.3 vsl| 0 CLI - Wr 200 19 PONG 1323172375 1.0
**** v1 15.3 vsl| 0 Backend_health - b2 Still sick 4--X--- 0 2 3 0.000000 0.000252
---- c1 16.3 HTTP rx timeout (fd:4 15000 ms)
* top 16.3 RESETTING after ./tests/v00036.vtc
** s1 16.3 Waiting for server
**** s1 16.3 macro undef s1_addr
**** s1 16.3 macro undef s1_port
**** s1 16.3 macro undef s1_sock
** s2 16.3 Waiting for server
**** s2 16.3 macro undef s2_addr
**** s2 16.3 macro undef s2_port
**** s2 16.3 macro undef s2_sock
** s3 16.3 Waiting for server
**** s3 16.3 macro undef s3_addr
**** s3 16.3 macro undef s3_port
**** s3 16.3 macro undef s3_sock
**** v1 16.3 vsl| 0 Backend_health - b1 Still sick 4--X--- 0 3 4 0.000000 0.000248
**** v1 16.3 vsl| 13 FetchError c http first read error: -1 104 (No error recorded)
**** v1 16.3 vsl| 14 BackendClose b b3
**** v1 16.3 vsl| 13 VCL_call c error
**** v1 16.3 vsl| 13 VCL_return c deliver
**** v1 16.3 vsl| 13 VCL_call c deliver
**** v1 16.3 vsl| 13 VCL_return c deliver
**** v1 16.3 vsl| 13 TxProtocol c HTTP/1.1
**** v1 16.3 vsl| 13 TxStatus c 503
**** v1 16.3 vsl| 13 TxResponse c Service Unavailable
**** v1 16.3 vsl| 13 TxHeader c Server: Varnish
**** v1 16.3 vsl| 13 TxHeader c Content-Type: text/html; charset=utf-8
**** v1 16.3 vsl| 13 TxHeader c Retry-After: 5
**** v1 16.3 vsl| 13 TxHeader c Content-Length: 413
**** v1 16.3 vsl| 13 TxHeader c Accept-Ranges: bytes
**** v1 16.3 vsl| 13 TxHeader c Date: Tue, 06 Dec 2011 11:52:56 GMT
**** v1 16.3 vsl| 13 TxHeader c X-Varnish: 1002
**** v1 16.3 vsl| 13 TxHeader c Age: 15
**** v1 16.3 vsl| 13 TxHeader c Via: 1.1 varnish
**** v1 16.3 vsl| 13 TxHeader c Connection: close
**** v1 16.3 vsl| 13 Length c 413
**** v1 16.3 vsl| 13 ReqEnd c 1002 1323172361.833134651 1323172376.848122597 0.920468807 15.014959574 0.000028372
**** v1 16.3 vsl| 13 SessionClose c error
**** v1 16.3 vsl| 13 StatSess c 127.0.0.1 47694 16 1 2 0 2 1 424 419
**** v1 16.3 vsl| 0 Backend_health - b2 Still sick 4--Xr-- 0 2 3 0.000000 0.000252
** v1 17.3 Wait
** v1 17.3 R 21629 Status: 0000
# top TEST ./tests/v00036.vtc FAILED (60.044) signal=9 exit=0
make[2]: *** [check] Error 2
make[2]: Leaving directory `/usr/src/packages/BUILD/varnish-3.0.2/bin/varnishtest'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/usr/src/packages/BUILD/varnish-3.0.2/bin'
make: *** [check-recursive] Error 1
error: Bad exit status from /var/tmp/rpm-tmp.xcjTxv (%check)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment