[Varnish] #1440: e00019.vtc occasionally trips an assert
Varnish
varnish-bugs at varnish-cache.org
Thu Feb 27 13:14:25 CET 2014
#1440: e00019.vtc occasionally trips an assert
----------------------+----------------------------------------
Reporter: martin | Owner: Poul-Henning Kamp <phk@…>
Type: defect | Status: reopened
Priority: normal | Milestone:
Component: varnishd | Version: trunk
Severity: normal | Resolution:
Keywords: |
----------------------+----------------------------------------
Comment (by lkarsten):
Disregard the last entry, I didn't properly clean/rebuild my tree.
However, when verifying this, the test case failed of a different reason:
{{{
**** top 0.0 macro def varnishd=varnishd
**** top 0.0 macro def varnishadm=varnishadm
**** top 0.0 macro def varnishstat=varnishstat
**** top 0.0 macro def varnishhist=varnishhist
**** top 0.0 macro def varnishlog=varnishlog
**** top 0.0 macro def varnishncsa=varnishncsa
**** top 0.0 macro def vmod_std=std from "/home/lkarsten/work/varnish-
cache/lib/libvmod_std/.libs/libvmod_std.so"
**** top 0.0 macro def vmod_debug=debug from "/home/lkarsten/work
/varnish-cache/lib/libvmod_debug/.libs/libvmod_debug.so"
**** top 0.0 macro def vmod_directors=directors from
"/home/lkarsten/work/varnish-
cache/lib/libvmod_directors/.libs/libvmod_directors.so"
**** top 0.0 macro def pwd=/home/lkarsten/work/varnish-
cache/bin/varnishtest
**** top 0.0 macro def topbuild=/home/lkarsten/work/varnish-cache
**** top 0.0 macro def bad_ip=192.0.2.255
**** top 0.0 macro def tmpdir=/tmp/vtc.18031.7794acc1
* top 0.0 TEST tests/e00019.vtc starting
*** top 0.0 varnishtest
* top 0.0 TEST Push corners in new ESI parser
*** 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=36268
**** s1 0.0 macro def s1_sock=127.0.0.1 36268
* s1 0.0 Listen on 127.0.0.1 36268
*** top 0.0 varnish
** s1 0.0 Started on 127.0.0.1 36268
** v1 0.0 Launch
*** v1 0.0 CMD: cd ${pwd} && ${varnishd} -d -d -n
/tmp/vtc.18031.7794acc1/v1 -l 2m,1m,- -p auto_restart=off -p
syslog_cli_traffic=off -p sigsegv_handler=on -a '127.0.0.1:0' -M
'127.0.0.1 50381' -P /tmp/vtc.18031.7794acc1/v1/varnishd.pid
*** v1 0.0 CMD: cd /home/lkarsten/work/varnish-cache/bin/varnishtest
&& varnishd -d -d -n /tmp/vtc.18031.7794acc1/v1 -l 2m,1m,- -p
auto_restart=off -p syslog_cli_traffic=off -p sigsegv_handler=on -a
'127.0.0.1:0' -M '127.0.0.1 50381' -P
/tmp/vtc.18031.7794acc1/v1/varnishd.pid
*** v1 0.0 PID: 18072
*** v1 0.0 debug| Platform:
Linux,3.12-1-amd64,x86_64,-smalloc,-smalloc,-hcritbit\n
*** v1 0.0 debug| 200 275 \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,3.12-1-amd64,x86_64,-smalloc,-smalloc,-hcritbit\n
*** v1 0.0 debug| varnish-4.0.0-tp2 revision 0eb0c12\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 = 9
*** v1 0.1 CLI RX 107
**** v1 0.1 CLI RX| dlcmbiufkycctwfmanotkohkodidlgpo\n
**** v1 0.1 CLI RX| \n
**** v1 0.1 CLI RX| Authentication required.\n
**** v1 0.1 CLI TX| auth
418abac6fa0d5bc10cf71dd0696c2a46c3ebdd3f45b7f9c29477721e5b82c33e\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,3.12-1-amd64,x86_64,-smalloc,-smalloc,-hcritbit\n
**** v1 0.1 CLI RX| varnish-4.0.0-tp2 revision 0eb0c12\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| vcl 4.0;\n
**** v1 0.1 CLI TX| backend s1 { .host = "127.0.0.1"; .port = "36268";
}\n
**** v1 0.1 CLI TX| \n
**** v1 0.1 CLI TX| \n
**** v1 0.1 CLI TX| \tsub vcl_backend_response {\n
**** v1 0.1 CLI TX| \t\tif (bereq.url == "bar") {\n
**** v1 0.1 CLI TX| \t\t\tset beresp.do_esi = true;\n
**** v1 0.1 CLI TX| \t\t}\n
**** v1 0.1 CLI TX| \t}\n
**** v1 0.1 CLI TX| \n
**** v1 0.1 CLI TX| %XJEIFLH|)Xspa8P\n
*** v1 0.2 CLI RX 200
**** v1 0.2 CLI RX| Message from VCC-compiler:\n
**** v1 0.2 CLI RX| Not running as root, no priv-sep\n
**** v1 0.2 CLI RX| Message from C-compiler:\n
**** v1 0.2 CLI RX| Not running as root, no priv-sep\n
**** v1 0.2 CLI RX| Message from dlopen:\n
**** v1 0.2 CLI RX| Not running as root, no priv-sep\n
**** v1 0.2 CLI RX| \n
**** v1 0.2 CLI RX| VCL compiled.
**** v1 0.2 CLI TX| vcl.use vcl1
*** v1 0.2 CLI RX 200
**** v1 0.2 CLI RX| VCL 'vcl1' now active
** v1 0.2 Start
**** v1 0.2 CLI TX| start
*** v1 0.2 debug| child (18416) Started\n
*** v1 0.2 CLI RX 200
*** v1 0.2 wait-running
**** v1 0.2 CLI TX| status
*** v1 0.2 debug| Child (18416) said Not running as root, no priv-
sep\n
*** v1 0.2 debug| Child (18416) said Child starts\n
*** v1 0.3 CLI RX 200
**** v1 0.3 CLI RX| Child in state running
**** v1 0.3 CLI TX| debug.xid 999
*** v1 0.3 CLI RX 200
**** v1 0.3 CLI RX| XID is 999
**** v1 0.3 CLI TX| debug.listen_address
**** v1 0.3 vsl| 0 CLI - Rd debug.xid 999
**** v1 0.3 vsl| 0 CLI - Wr 200 10 XID is 999
*** v1 0.4 CLI RX 200
**** v1 0.4 CLI RX| 127.0.0.1 34864\n
** v1 0.4 Listen on 127.0.0.1 34864
**** v1 0.4 macro def v1_addr=127.0.0.1
**** v1 0.4 macro def v1_port=34864
**** v1 0.4 macro def v1_sock=127.0.0.1 34864
*** top 0.4 varnish
**** v1 0.4 CLI TX| param.set debug +esi_chop
**** v1 0.4 vsl| 0 CLI - Rd debug.listen_address
**** v1 0.4 vsl| 0 CLI - Wr 200 16 127.0.0.1 34864
*** v1 0.4 CLI RX 200
** v1 0.4 CLI 200 <param.set debug +esi_chop>
*** top 0.4 varnish
**** v1 0.4 CLI TX| param.set debug +syncvsl
*** v1 0.4 CLI RX 200
** v1 0.4 CLI 200 <param.set debug +syncvsl>
*** top 0.4 client
** c1 0.4 Starting client
** c1 0.4 Waiting for client
*** c1 0.4 Connect to 127.0.0.1 34864
*** c1 0.4 connected fd 10 from 127.0.0.1 45443 to 127.0.0.1 34864
*** c1 0.4 txreq
**** c1 0.4 txreq| GET bar HTTP/1.1\r\n
**** c1 0.4 txreq| \r\n
*** c1 0.4 rxresp
*** s1 0.4 accepted fd 4
*** s1 0.4 rxreq
**** s1 0.4 rxhdr| GET bar HTTP/1.1\r\n
**** s1 0.4 rxhdr| X-Forwarded-For: 127.0.0.1\r\n
**** s1 0.4 rxhdr| Accept-Encoding: gzip\r\n
**** s1 0.4 rxhdr| X-Varnish: 1002\r\n
**** s1 0.4 rxhdr| Host: 127.0.0.1\r\n
**** s1 0.4 rxhdr| \r\n
**** s1 0.4 http[ 0] | GET
**** s1 0.4 http[ 1] | bar
**** s1 0.4 http[ 2] | HTTP/1.1
**** s1 0.4 http[ 3] | X-Forwarded-For: 127.0.0.1
**** s1 0.4 http[ 4] | Accept-Encoding: gzip
**** s1 0.4 http[ 5] | X-Varnish: 1002
**** s1 0.4 http[ 6] | Host: 127.0.0.1
**** s1 0.4 bodylen = 0
*** s1 0.4 txresp
**** s1 0.4 txresp| HTTP/1.1 200 Ok\r\n
**** s1 0.4 txresp| Transfer-encoding: chunked\r\n
**** s1 0.4 txresp| \r\n
*** s1 0.4 chunked
**** s1 0.4 chunked| 18\r\n
**** s1 0.4 chunked| <1></esi:comment foo><1>\r\n
*** s1 0.4 chunked
**** s1 0.4 chunked| 27\r\n
**** s1 0.4 chunked| <2><esi:comment / ><esi:comment doo><2>\r\n
*** s1 0.4 chunked
**** s1 0.4 chunked| 29\r\n
**** s1 0.4 chunked| <3><esi:remove foo="bar"></esi:remove><3>\r\n
*** s1 0.4 chunked
**** s1 0.4 chunked| 27\r\n
**** s1 0.4 chunked| <4><esi:include src="foo"><esi:incl><4>\r\n
*** s1 0.4 chunked
**** s1 0.4 chunked| 10\r\n
**** s1 0.4 chunked| <H1><esi:remove>\r\n
*** s1 0.4 chunkedlen
**** s1 0.4 chunked| 100\r\n
**** s1 0.4 chunked|
0123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567\r\n
*** s1 0.4 chunked
**** s1 0.4 chunked| 12\r\n
**** s1 0.4 chunked| </esi:remove></H1>\r\n
*** s1 0.4 chunked
**** s1 0.4 chunked| 10\r\n
**** s1 0.4 chunked| <H2><esi:remove>\r\n
*** s1 0.4 chunkedlen
**** s1 0.4 chunked| 10000\r\n
**** s1 0.4 chunked|
01234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701...
*** s1 0.4 chunked
**** s1 0.4 chunked| 12\r\n
**** s1 0.4 chunked| </esi:remove></H2>\r\n
*** s1 0.4 chunked
**** s1 0.4 chunked| e\r\n
**** s1 0.4 chunked| <esi:comment/>\r\n
*** s1 0.4 chunkedlen
**** s1 0.4 chunked| 100\r\n
**** s1 0.4 chunked|
0123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567\r\n
*** s1 0.4 chunked
**** s1 0.4 chunked| e\r\n
**** s1 0.4 chunked| <esi:comment/>\r\n
*** s1 0.4 chunkedlen
**** v1 0.4 vsl| 1000 Begin c sess 0 HTTP/1
**** v1 0.4 vsl| 1000 SessOpen c 127.0.0.1 45443
127.0.0.1:0 127.0.0.1 34864 1393503049.402590 12
**** v1 0.4 vsl| 1001 Begin c req 1000 rxreq
**** v1 0.4 vsl| 1000 Link c req 1001 rxreq
**** v1 0.4 vsl| 1001 ReqStart c 127.0.0.1 45443
**** v1 0.4 vsl| 1001 ReqMethod c GET
**** v1 0.4 vsl| 1001 ReqURL c bar
**** v1 0.4 vsl| 1001 ReqProtocol c HTTP/1.1
**** v1 0.4 vsl| 1001 VCL_call c RECV
**** v1 0.4 vsl| 1001 ReqHeader c X-Forwarded-For:
127.0.0.1
**** v1 0.4 vsl| 1001 VCL_return c hash
**** v1 0.4 vsl| 1001 VCL_call c HASH
**** v1 0.4 vsl| 1001 VCL_return c lookup
**** v1 0.4 vsl| 1001 Debug c XXXX MISS
**** v1 0.4 vsl| 1001 VCL_call c MISS
**** v1 0.4 vsl| 1001 VCL_return c fetch
**** v1 0.4 vsl| 1002 Begin b bereq 1001 fetch
**** v1 0.4 vsl| 1001 Link c bereq 1002 fetch
**** v1 0.4 vsl| 1002 BereqMethod b GET
**** v1 0.4 vsl| 1002 BereqURL b bar
**** v1 0.4 vsl| 1002 BereqProtocol b HTTP/1.1
**** v1 0.4 vsl| 1002 BereqHeader b X-Forwarded-For:
127.0.0.1
**** v1 0.4 vsl| 1002 BereqHeader b Accept-Encoding: gzip
**** v1 0.4 vsl| 1002 VCL_call b BACKEND_FETCH
**** v1 0.4 vsl| 1002 VCL_return b fetch
**** v1 0.4 vsl| 1002 BereqHeader b X-Varnish: 1002
**** v1 0.4 vsl| 1002 BackendOpen b 15 s1(127.0.0.1,,36268)
127.0.0.1 41768
**** v1 0.4 vsl| 1002 Backend b 15 s1
s1(127.0.0.1,,36268)
**** v1 0.4 vsl| 1002 BereqHeader b Host: 127.0.0.1
**** v1 0.4 vsl| 1002 BerespProtocol b HTTP/1.1
**** v1 0.4 vsl| 1002 BerespStatus b 200
**** v1 0.4 vsl| 1002 BerespResponse b Ok
**** v1 0.4 vsl| 1002 BerespHeader b Transfer-encoding:
chunked
**** v1 0.4 vsl| 1002 TTL b RFC 20 -1 -1 1393503049
1393503049 0 0 0
**** v1 0.4 vsl| 1002 VCL_call b BACKEND_RESPONSE
**** v1 0.4 vsl| 1002 VCL_return b deliver
**** v1 0.4 vsl| 1002 Storage b malloc s0
**** v1 0.4 vsl| 1002 ObjProtocol b HTTP/1.1
**** v1 0.4 vsl| 1002 ObjStatus b 200
**** v1 0.4 vsl| 1002 ObjResponse b Ok
**** v1 0.4 vsl| 1002 ESI_xmlerror b ERR at 16 ESI 1.0
</esi:comment> illegal end-tag
**** v1 0.4 vsl| 1002 ESI_xmlerror b ERR at 38 XML 1.0 '>'
does not follow '/' in tag
**** v1 0.4 vsl| 1002 ESI_xmlerror b ERR at 60 ESI 1.0
<esi:comment> needs final '/'
**** v1 0.4 vsl| 1002 ESI_xmlerror b WARN at 130 ESI 1.0
<esi:include> lacks final '/'
**** v1 0.4 vsl| 1002 ESI_xmlerror b ERR at 139 ESI 1.0
<esi:bogus> element
**** s1 0.4 chunked| 10000\r\n
**** s1 0.4 chunked|
01234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701...
*** s1 0.4 chunked
**** s1 0.4 chunked| e\r\n
**** s1 0.4 chunked| <esi:comment/>\r\n
*** s1 0.4 chunkedlen
**** s1 0.4 chunked| 0\r\n
**** s1 0.4 chunked| \r\n
*** s1 0.4 rxreq
**** c1 0.6 rxhdr| HTTP/1.1 200 Ok\r\n
**** c1 0.6 rxhdr| Date: Thu, 27 Feb 2014 12:10:49 GMT\r\n
**** c1 0.6 rxhdr| X-Varnish: 1001\r\n
**** c1 0.6 rxhdr| Age: 0\r\n
**** c1 0.6 rxhdr| Via: 1.1 varnish\r\n
**** c1 0.6 rxhdr| Transfer-Encoding: chunked\r\n
**** c1 0.6 rxhdr| Connection: keep-alive\r\n
**** c1 0.6 rxhdr| \r\n
**** c1 0.6 http[ 0] | HTTP/1.1
**** c1 0.6 http[ 1] | 200
**** c1 0.6 http[ 2] | Ok
**** c1 0.6 http[ 3] | Date: Thu, 27 Feb 2014 12:10:49 GMT
**** c1 0.6 http[ 4] | X-Varnish: 1001
**** c1 0.6 http[ 5] | Age: 0
**** c1 0.6 http[ 6] | Via: 1.1 varnish
**** c1 0.6 http[ 7] | Transfer-Encoding: chunked
**** c1 0.6 http[ 8] | Connection: keep-alive
**** c1 0.6 len| 0015\r\n
**** c1 0.6 chunk| <1><1><2><2><3><3><4>
**** v1 0.6 vsl| 1002 Fetch_Body b 2(chunked)
**** v1 0.6 vsl| 1002 Length b 131837
**** v1 0.6 vsl| 0 ExpKill - EXP_Inbox
p=0x7fb918000950 e=0.000000000 f=0x1c10
**** v1 0.6 vsl| 1001 RespProtocol c HTTP/1.1
**** v1 0.6 vsl| 1001 RespStatus c 200
**** v1 0.6 vsl| 1001 RespResponse c Ok
**** v1 0.6 vsl| 0 ExpKill - EXP_When p=0x7fb918000950
e=1393503079.402649403 f=0x1c10
**** v1 0.6 vsl| 1001 RespHeader c Date: Thu, 27 Feb 2014
12:10:49 GMT
**** v1 0.6 vsl| 1001 RespHeader c X-Varnish: 1001
**** v1 0.6 vsl| 1001 RespHeader c Age: 0
**** v1 0.6 vsl| 1001 RespHeader c Via: 1.1 varnish
**** v1 0.6 vsl| 1001 VCL_call c DELIVER
**** v1 0.6 vsl| 1001 VCL_return c deliver
**** v1 0.6 vsl| 1001 Debug c RES_MODE 18
**** v1 0.6 vsl| 1001 RespHeader c Transfer-Encoding:
chunked
**** v1 0.6 vsl| 1001 RespHeader c Connection: keep-alive
**** v1 0.6 vsl| 1003 Begin c req 1000 rxreq
**** v1 0.6 vsl| 1000 Link c req 1003 rxreq
**** v1 0.6 vsl| 1003 Begin c req 1001 esi
**** v1 0.6 vsl| 1001 Link c req 1003 esi
**** v1 0.6 vsl| 1003 ReqStart c 127.0.0.1 45443
**** v1 0.6 vsl| 1003 ReqMethod c GET
**** v1 0.6 vsl| 1003 ReqURL c bar/foo
**** v1 0.6 vsl| 1003 ReqProtocol c HTTP/1.1
**** v1 0.6 vsl| 1003 VCL_call c RECV
**** v1 0.6 vsl| 1003 ReqHeader c X-Forwarded-For:
127.0.0.1
**** v1 0.6 vsl| 1003 VCL_return c hash
**** v1 0.6 vsl| 1003 VCL_call c HASH
**** v1 0.6 vsl| 1003 VCL_return c lookup
**** v1 0.6 vsl| 1003 Debug c XXXX MISS
**** v1 0.6 vsl| 1003 VCL_call c MISS
**** v1 0.6 vsl| 1003 VCL_return c fetch
**** v1 0.6 vsl| 1004 Begin b bereq 1003 fetch
**** v1 0.6 vsl| 1003 Link c bereq 1004 fetch
**** v1 0.6 vsl| 1004 BereqMethod b GET
**** v1 0.6 vsl| 1004 BereqURL b bar/foo
**** v1 0.6 vsl| 1004 BereqProtocol b HTTP/1.1
**** v1 0.6 vsl| 1004 BereqHeader b X-Forwarded-For:
127.0.0.1
**** v1 0.6 vsl| 1004 BereqHeader b Accept-Encoding: gzip
**** v1 0.6 vsl| 1004 VCL_call b BACKEND_FETCH
**** v1 0.6 vsl| 1004 VCL_return b fetch
**** v1 0.6 vsl| 1004 BereqHeader b X-Varnish: 1004
**** v1 0.6 vsl| 1004 BackendOpen b 16 s1(127.0.0.1,,36268)
127.0.0.1 41777
**** v1 0.6 vsl| 1004 Backend b 16 s1
s1(127.0.0.1,,36268)
**** v1 0.6 vsl| 1004 BereqHeader b Host: 127.0.0.1
**** v1 0.6 vsl| 1002 BackendReuse b 15 s1(127.0.0.1,,36268)
**** v1 0.6 vsl| 1002 BereqEnd b 1393503049.402762890
1393503049.554100037 0.000026806 0.000209815 0.150583778 0.150793593
**** v1 0.6 vsl| 1002 End b
**** v1 3.3 vsl| 0 CLI - Rd ping
**** v1 3.3 vsl| 0 CLI - Wr 200 19 PONG 1393503052
1.0
**** v1 6.2 vsl| 0 CLI - Rd ping
**** v1 6.2 vsl| 0 CLI - Wr 200 19 PONG 1393503055
1.0
**** v1 9.2 vsl| 0 CLI - Rd ping
**** v1 9.2 vsl| 0 CLI - Wr 200 19 PONG 1393503058
1.0
**** v1 12.3 vsl| 0 CLI - Rd ping
**** v1 12.3 vsl| 0 CLI - Wr 200 19 PONG 1393503061
1.0
**** v1 15.3 vsl| 0 CLI - Rd ping
**** v1 15.3 vsl| 0 CLI - Wr 200 19 PONG 1393503064
1.0
---- s1 15.5 HTTP rx timeout (fd:4 15000 ms)
---- c1 15.6 HTTP rx timeout (fd:10 15000 ms)
* top 15.6 RESETTING after tests/e00019.vtc
** s1 15.6 Waiting for server
**** s1 15.6 macro undef s1_addr
**** s1 15.6 macro undef s1_port
**** s1 15.6 macro undef s1_sock
**** v1 15.6 vsl| 1004 FetchError b http first read error:
EOF
**** v1 15.6 vsl| 1004 BackendClose b 16 s1(127.0.0.1,,36268)
**** v1 15.6 vsl| 1004 BerespProtocol b HTTP/1.1
**** v1 15.6 vsl| 1004 BerespStatus b 503
**** v1 15.6 vsl| 1004 BerespResponse b Backend fetch failed
**** v1 15.6 vsl| 1004 BerespHeader b Content-Length: 0
**** v1 15.6 vsl| 1004 BerespHeader b Connection: close
**** v1 15.6 vsl| 1004 VCL_call b BACKEND_ERROR
**** v1 15.6 vsl| 1004 VCL_return b deliver
**** v1 15.6 vsl| 1004 BerespHeader b Content-Length: 0
**** v1 15.6 vsl| 1004 BerespHeader b X-XXXPHK: yes
**** v1 15.6 vsl| 1004 Storage b malloc Transient
**** v1 15.6 vsl| 1004 ObjProtocol b HTTP/1.1
**** v1 15.6 vsl| 1004 ObjStatus b 503
**** v1 15.6 vsl| 1004 ObjResponse b Backend fetch failed
**** v1 15.6 vsl| 1004 ObjHeader b X-XXXPHK: yes
**** v1 15.6 vsl| 0 ExpKill - EXP_Inbox
p=0x7fb918000b60 e=0.000000000 f=0x1c10
**** v1 15.6 vsl| 1004 BereqEnd b 1393503049.553846598
1393503064.566039085 0.000018227 nan nan nan
**** v1 15.6 vsl| 0 ExpKill - EXP_When p=0x7fb918000b60
e=0.000000000 f=0x1c10
**** v1 15.6 vsl| 0 ExpKill - EXP_Expired x=1004
t=-1393503065
**** v1 15.6 vsl| 1004 End b
**** v1 15.6 vsl| 1003 RespProtocol c HTTP/1.1
**** v1 15.6 vsl| 1003 RespStatus c 503
**** v1 15.6 vsl| 1003 RespResponse c Backend fetch failed
**** v1 15.6 vsl| 1003 RespHeader c X-XXXPHK: yes
**** v1 15.6 vsl| 1003 RespHeader c Date: Thu, 27 Feb 2014
12:11:04 GMT
**** v1 15.6 vsl| 1003 RespHeader c X-Varnish: 1003
**** v1 15.6 vsl| 1003 RespHeader c Age: 1393503065
**** v1 15.6 vsl| 1003 RespHeader c Via: 1.1 varnish
**** v1 15.6 vsl| 1003 VCL_call c DELIVER
**** v1 15.6 vsl| 1003 VCL_return c deliver
**** v1 15.6 vsl| 1003 RespHeader c Content-Length: 0
**** v1 15.6 vsl| 1003 Debug c RES_MODE 28
**** v1 15.6 vsl| 1003 RespUnset c Content-Length: 0
**** v1 15.6 vsl| 1003 RespHeader c Transfer-Encoding:
chunked
**** v1 15.6 vsl| 1003 RespHeader c Connection: keep-alive
**** v1 15.6 vsl| 1003 Debug c XXX REF 1
**** v1 15.6 vsl| 1003 Length c 0
**** v1 15.6 vsl| 1003 ReqEnd c 1393503049.402649403
1393503049.402590036 -15.163525820 15.163466454 -15.163525820
**** v1 15.6 vsl| 1003 End c
**** v1 15.6 vsl| 0 End -
**** v1 15.6 vsl| 1001 Debug c XXX REF 2
**** v1 15.6 vsl| 1001 Length c 0
**** v1 15.6 vsl| 1001 ReqEnd c 1393503049.402649403
1393503049.402590036 -0.151128054 0.151068687 -0.151128054
**** v1 15.6 vsl| 1001 End c
** v1 16.6 Wait
**** v1 16.6 vsl| 0 CLI - EOF on CLI connection,
worker stops
** v1 17.6 R 18072 Status: 0000 (u 0.148000 s 0.160000)
* top 17.6 TEST tests/e00019.vtc FAILED
# top TEST tests/e00019.vtc FAILED (17.612) exit=1
lkarsten at immer:~/work/varnish-cache/bin/varnishtest$
}}}
--
Ticket URL: <https://www.varnish-cache.org/trac/ticket/1440#comment:3>
Varnish <https://varnish-cache.org/>
The Varnish HTTP Accelerator
More information about the varnish-bugs
mailing list