On Wed, Jul 8, 2015 at 12:55 AM, Poul-Henning Kamp <[email protected]> wrote:
>> A VRT_CTX may not be available in all situations for backends deletion.
>
> They will have to be. If need be, the caller must construct one.
I didn't think it was OK to make my own context, thanks.
>>Subject: [PATCH 2/5] Keep track of backends references and connections
>
> I've done this entirely differently.
>
> Fixes #1755
Please revisit this one, my patch also fixes two panics I just got while
rebasing against the current trunk. See attached test logs.
>> [PATCH 3/5] Add a debug.sleep(DURATION) synchronization helper
> This should use VTIM_sleep().
>
> Commit it when fixed & tested.
Ack
>> Subject: [PATCH 4/5] Add a test suite for dynamic backends
>
> I've run out of steam, will look at this tomorrow.
Thanks
>> Subject: [PATCH 5/5] Add more information to a backend panic message
>
> This doesn't work with the way I did #2/5 above.
Do I send a patch or simply commit?
**** 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/dridi/varnish/src/varnish-cache/lib/libvmod_std/.libs/libvmod_std.so"
**** top 0.0 macro def vmod_debug=debug from "/home/dridi/varnish/src/varnish-cache/lib/libvmod_debug/.libs/libvmod_debug.so"
**** top 0.0 macro def vmod_directors=directors from "/home/dridi/varnish/src/varnish-cache/lib/libvmod_directors/.libs/libvmod_directors.so"
**** top 0.0 macro def pwd=/home/dridi/varnish/src/varnish-cache/bin/varnishtest
**** top 0.0 macro def topbuild=/home/dridi/varnish/src/varnish-cache
**** top 0.0 macro def bad_ip=192.0.2.255
**** top 0.0 macro def tmpdir=/tmp/vtc.21900.33cfdd06
* top 0.0 TEST ./tests/d00008.vtc starting
** top 0.0 === varnishtest "Test dynamic backends hot swap"
* top 0.0 TEST Test dynamic backends hot swap
** top 0.0 === server s1 {
** s1 0.0 Starting server
**** s1 0.0 macro def s1_addr=127.0.0.1
**** s1 0.0 macro def s1_port=43926
**** s1 0.0 macro def s1_sock=127.0.0.1 43926
* s1 0.0 Listen on 127.0.0.1 43926
** top 0.0 === server s2 {
** s2 0.0 Starting server
** s1 0.0 Started on 127.0.0.1 43926
**** s2 0.0 macro def s2_addr=127.0.0.1
**** s2 0.0 macro def s2_port=49265
**** s2 0.0 macro def s2_sock=127.0.0.1 49265
* s2 0.0 Listen on 127.0.0.1 49265
** top 0.0 === varnish v1 -vcl {
** s2 0.0 Started on 127.0.0.1 49265
** v1 0.0 Launch
*** v1 0.0 CMD: cd ${pwd} && exec ${varnishd} -d -n /tmp/vtc.21900.33cfdd06/v1 -l 2m,1m,- -p auto_restart=off -p syslog_cli_traffic=off -p sigsegv_handler=on -p thread_pool_min=10 -p debug=+vtc_mode -a '127.0.0.1:0' -M '127.0.0.1 50883' -P /tmp/vtc.21900.33cfdd06/v1/varnishd.pid
*** v1 0.0 CMD: cd /home/dridi/varnish/src/varnish-cache/bin/varnishtest && exec varnishd -d -n /tmp/vtc.21900.33cfdd06/v1 -l 2m,1m,- -p auto_restart=off -p syslog_cli_traffic=off -p sigsegv_handler=on -p thread_pool_min=10 -p debug=+vtc_mode -a '127.0.0.1:0' -M '127.0.0.1 50883' -P /tmp/vtc.21900.33cfdd06/v1/varnishd.pid
*** v1 0.0 PID: 21920
**** v1 0.0 macro def v1_pid=21920
**** v1 0.0 macro def v1_name=/tmp/vtc.21900.33cfdd06/v1
*** v1 0.0 debug| Platform: Linux,4.0.6-200.fc21.x86_64,x86_64,-jnone,-smalloc,-smalloc,-hcritbit\n
*** v1 0.0 debug| 200 287 \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,4.0.6-200.fc21.x86_64,x86_64,-jnone,-smalloc,-smalloc,-hcritbit\n
*** v1 0.0 debug| varnish-trunk revision 8922d14\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 = 11
*** v1 0.1 CLI RX 107
**** v1 0.1 CLI RX| jboqizvmgcusvtrmgulfhbuuiwcxildt\n
**** v1 0.1 CLI RX| \n
**** v1 0.1 CLI RX| Authentication required.\n
**** v1 0.1 CLI TX| auth 9459ff1cde77a68339dc07fd4f11e4184e0a632695dd6d57528cfa7af42ed0d4\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,4.0.6-200.fc21.x86_64,x86_64,-jnone,-smalloc,-smalloc,-hcritbit\n
**** v1 0.1 CLI RX| varnish-trunk revision 8922d14\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| \n
**** v1 0.1 CLI TX| \timport debug from "/home/dridi/varnish/src/varnish-cache/lib/libvmod_debug/.libs/libvmod_debug.so";\n
**** v1 0.1 CLI TX| \n
**** v1 0.1 CLI TX| \tbackend dummy { .host = "192.0.2.255"; }\n
**** v1 0.1 CLI TX| \n
**** v1 0.1 CLI TX| \tsub vcl_init {\n
**** v1 0.1 CLI TX| \t\tnew s1 = debug.dyn("127.0.0.1", "43926");\n
**** v1 0.1 CLI TX| \t}\n
**** v1 0.1 CLI TX| \n
**** v1 0.1 CLI TX| \tsub vcl_recv {\n
**** v1 0.1 CLI TX| \t\tif (req.method == "SWAP") {\n
**** v1 0.1 CLI TX| \t\t\ts1.hot_swap(req.http.X-Addr ,req.http.X-Port);\n
**** v1 0.1 CLI TX| \t\t\treturn (synth(200));\n
**** v1 0.1 CLI TX| \t\t}\n
**** v1 0.1 CLI TX| \t\tset req.backend_hint = s1.backend();\n
**** v1 0.1 CLI TX| \t}\n
**** v1 0.1 CLI TX| \n
**** v1 0.1 CLI TX| %XJEIFLH|)Xspa8P\n
*** v1 0.3 CLI RX 200
**** v1 0.3 CLI RX| VCL compiled.\n
**** v1 0.3 CLI TX| vcl.use vcl1
*** v1 0.3 CLI RX 200
** v1 0.3 Start
**** v1 0.3 CLI TX| start
*** v1 0.3 debug| child (21950) Started\n
*** v1 0.3 CLI RX 200
*** v1 0.3 wait-running
**** v1 0.3 CLI TX| status
*** v1 0.3 debug| Child (21950) said Child starts\n
*** v1 0.4 CLI RX 200
**** v1 0.4 CLI RX| Child in state running
**** v1 0.4 CLI TX| debug.xid 999
**** v1 0.4 vsl| 0 CLI - Rd vcl.load "vcl1" vcl_vcl1/vgc.so 1auto
**** v1 0.4 vsl| 0 CLI - Wr 200 34 Loaded "vcl_vcl1/vgc.so" as "vcl1"
**** v1 0.4 vsl| 0 CLI - Rd vcl.use "vcl1"
**** v1 0.4 vsl| 0 CLI - Wr 200 0
**** v1 0.4 vsl| 0 CLI - Rd start
**** v1 0.4 vsl| 0 CLI - Wr 200 0
*** v1 0.4 CLI RX 200
**** v1 0.4 CLI RX| XID is 999
**** v1 0.4 CLI TX| debug.listen_address
**** v1 0.4 vsl| 0 CLI - Rd debug.xid 999
**** v1 0.4 vsl| 0 CLI - Wr 200 10 XID is 999
*** v1 0.5 CLI RX 200
**** v1 0.5 CLI RX| 127.0.0.1 55916\n
** v1 0.5 Listen on 127.0.0.1 55916
**** v1 0.5 macro def v1_addr=127.0.0.1
**** v1 0.5 macro def v1_port=55916
**** v1 0.5 macro def v1_sock=127.0.0.1 55916
** top 0.5 === varnish v1 -expect MAIN.n_backend == 2
** v1 0.5 as expected: MAIN.n_backend (2) == 2
** top 0.5 === client c1 {
** c1 0.5 Starting client
** c1 0.5 Waiting for client
*** c1 0.5 Connect to 127.0.0.1 55916
*** c1 0.5 connected fd 12 from 127.0.0.1 34098 to 127.0.0.1 55916
** c1 0.5 === txreq -url "/foo"
**** c1 0.5 txreq| GET /foo HTTP/1.1\r\n
**** c1 0.5 txreq| \r\n
** c1 0.5 === rxresp
*** s1 0.5 accepted fd 5
** s1 0.5 === rxreq
**** s1 0.5 rxhdr| GET /foo HTTP/1.1\r\n
**** s1 0.5 rxhdr| X-Forwarded-For: 127.0.0.1\r\n
**** s1 0.5 rxhdr| Accept-Encoding: gzip\r\n
**** s1 0.5 rxhdr| X-Varnish: 1002\r\n
**** s1 0.5 rxhdr| Host: 127.0.0.1\r\n
**** s1 0.5 rxhdr| \r\n
**** s1 0.5 rxhdrlen = 106
**** s1 0.5 http[ 0] | GET
**** s1 0.5 http[ 1] | /foo
**** s1 0.5 http[ 2] | HTTP/1.1
**** s1 0.5 http[ 3] | X-Forwarded-For: 127.0.0.1
**** s1 0.5 http[ 4] | Accept-Encoding: gzip
**** s1 0.5 http[ 5] | X-Varnish: 1002
**** s1 0.5 http[ 6] | Host: 127.0.0.1
**** s1 0.5 bodylen = 0
** s1 0.5 === expect req.url == "/foo"
**** s1 0.5 EXPECT req.url (/foo) == "/foo" match
** s1 0.5 === txresp
**** s1 0.5 txresp| HTTP/1.1 200 OK\r\n
**** s1 0.5 txresp| Content-Length: 0\r\n
**** s1 0.5 txresp| \r\n
*** s1 0.5 shutting fd 5
** s1 0.5 Ending
**** v1 0.5 vsl| 0 CLI - Rd debug.listen_address
**** v1 0.5 vsl| 0 CLI - Wr 200 16 127.0.0.1 55916
**** v1 0.5 vsl| 1000 Begin c sess 0 HTTP/1
**** v1 0.5 vsl| 1000 SessOpen c 127.0.0.1 34098 127.0.0.1:55916 127.0.0.1 55916 1436347471.218572 7
**** v1 0.5 vsl| 1000 Link c req 1001 rxreq
**** v1 0.5 vsl| 0 ExpKill - EXP_Inbox p=0x7f87f742a0c0 e=0.000000000 f=0x0
**** v1 0.5 vsl| 0 ExpKill - EXP_When p=0x7f87f742a0c0 e=1436347601.220134974 f=0x1c10
**** c1 0.5 rxhdr| HTTP/1.1 200 OK\r\n
**** c1 0.5 rxhdr| Date: Wed, 08 Jul 2015 09:24:31 GMT\r\n
**** c1 0.5 rxhdr| X-Varnish: 1001\r\n
**** c1 0.5 rxhdr| Age: 0\r\n
**** c1 0.5 rxhdr| Via: 1.1 varnish-v4\r\n
**** c1 0.5 rxhdr| Accept-Ranges: bytes\r\n
**** c1 0.5 rxhdr| Content-Length: 0\r\n
**** c1 0.5 rxhdr| Connection: keep-alive\r\n
**** c1 0.5 rxhdr| \r\n
**** c1 0.5 rxhdrlen = 167
**** c1 0.5 http[ 0] | HTTP/1.1
**** c1 0.5 http[ 1] | 200
**** c1 0.5 http[ 2] | OK
**** c1 0.5 http[ 3] | Date: Wed, 08 Jul 2015 09:24:31 GMT
**** c1 0.5 http[ 4] | X-Varnish: 1001
**** c1 0.5 http[ 5] | Age: 0
**** c1 0.5 http[ 6] | Via: 1.1 varnish-v4
**** c1 0.5 http[ 7] | Accept-Ranges: bytes
**** c1 0.5 http[ 8] | Content-Length: 0
**** c1 0.5 http[ 9] | Connection: keep-alive
**** c1 0.5 bodylen = 0
** c1 0.5 === expect resp.status == 200
**** c1 0.5 EXPECT resp.status (200) == "200" match
** c1 0.5 === txreq -req "SWAP" -hdr "X-Addr: 127.0.0.1" -hdr "X-Port: 492...
**** c1 0.5 txreq| SWAP / HTTP/1.1\r\n
**** c1 0.5 txreq| X-Addr: 127.0.0.1\r\n
**** c1 0.5 txreq| X-Port: 49265\r\n
**** c1 0.5 txreq| \r\n
** c1 0.5 === rxresp
**** v1 0.5 vsl| 1002 Begin b bereq 1001 fetch
**** v1 0.5 vsl| 1002 Timestamp b Start: 1436347471.218967 0.000000 0.000000
**** v1 0.5 vsl| 1002 BereqMethod b GET
**** v1 0.5 vsl| 1002 BereqURL b /foo
**** v1 0.5 vsl| 1002 BereqProtocol b HTTP/1.1
**** v1 0.5 vsl| 1002 BereqHeader b X-Forwarded-For: 127.0.0.1
**** v1 0.5 vsl| 1002 BereqHeader b Accept-Encoding: gzip
**** v1 0.5 vsl| 1002 BereqHeader b X-Varnish: 1002
**** v1 0.5 vsl| 1002 VCL_call b BACKEND_FETCH
**** v1 0.5 vsl| 1002 VCL_return b fetch
**** v1 0.5 vsl| 1002 BereqHeader b Host: 127.0.0.1
**** v1 0.5 vsl| 1002 BackendOpen b 15 vcl1.s1 127.0.0.1 43926 127.0.0.1 41149
**** v1 0.5 vsl| 1002 Timestamp b Bereq: 1436347471.219353 0.000386 0.000386
**** v1 0.5 vsl| 1002 Timestamp b Beresp: 1436347471.220135 0.001168 0.000782
**** v1 0.5 vsl| 1002 BerespProtocol b HTTP/1.1
**** v1 0.5 vsl| 1002 BerespStatus b 200
**** v1 0.5 vsl| 1002 BerespReason b OK
**** v1 0.5 vsl| 1002 BerespHeader b Content-Length: 0
**** v1 0.5 vsl| 1002 BerespHeader b Date: Wed, 08 Jul 2015 09:24:31 GMT
**** v1 0.5 vsl| 1002 TTL b RFC 120 10 -1 1436347471 1436347471 1436347471 0 0
**** v1 0.5 vsl| 1002 VCL_call b BACKEND_RESPONSE
**** v1 0.5 vsl| 1002 VCL_return b deliver
**** v1 0.5 vsl| 1002 Storage b malloc s0
**** v1 0.5 vsl| 1002 ObjProtocol b HTTP/1.1
**** v1 0.5 vsl| 1002 ObjStatus b 200
**** v1 0.5 vsl| 1002 ObjReason b OK
**** v1 0.5 vsl| 1002 ObjHeader b Content-Length: 0
**** v1 0.5 vsl| 1002 ObjHeader b Date: Wed, 08 Jul 2015 09:24:31 GMT
**** v1 0.5 vsl| 1002 Fetch_Body b 0 none -
**** v1 0.5 vsl| 1002 BackendReuse b 15 vcl1.s1
**** v1 0.5 vsl| 1002 Timestamp b BerespBody: 1436347471.230449 0.011482 0.010314
**** v1 0.5 vsl| 1002 Length b 0
**** v1 0.5 vsl| 1002 BereqAcct b 106 0 106 38 0 38
**** v1 0.5 vsl| 1002 End b
**** v1 0.5 vsl| 1001 Begin c req 1000 rxreq
**** v1 0.5 vsl| 1001 Timestamp c Start: 1436347471.218719 0.000000 0.000000
**** v1 0.5 vsl| 1001 Timestamp c Req: 1436347471.218719 0.000000 0.000000
**** v1 0.5 vsl| 1001 ReqStart c 127.0.0.1 34098
**** v1 0.5 vsl| 1001 ReqMethod c GET
**** v1 0.5 vsl| 1001 ReqURL c /foo
**** v1 0.5 vsl| 1001 ReqProtocol c HTTP/1.1
**** v1 0.5 vsl| 1001 ReqHeader c X-Forwarded-For: 127.0.0.1
**** v1 0.5 vsl| 1001 VCL_call c RECV
**** v1 0.5 vsl| 1001 VCL_return c hash
**** v1 0.5 vsl| 1001 VCL_call c HASH
**** v1 0.5 vsl| 1001 VCL_return c lookup
**** v1 0.5 vsl| 1001 VCL_call c MISS
**** v1 0.5 vsl| 1001 VCL_return c fetch
**** v1 0.5 vsl| 1001 Link c bereq 1002 fetch
**** v1 0.5 vsl| 1001 Timestamp c Fetch: 1436347471.230500 0.011781 0.011781
**** v1 0.5 vsl| 1001 RespProtocol c HTTP/1.1
**** v1 0.5 vsl| 1001 RespStatus c 200
**** v1 0.5 vsl| 1001 RespReason c OK
**** v1 0.5 vsl| 1001 RespHeader c Content-Length: 0
**** v1 0.5 vsl| 1001 RespHeader c Date: Wed, 08 Jul 2015 09:24:31 GMT
**** v1 0.5 vsl| 1001 RespHeader c X-Varnish: 1001
**** v1 0.5 vsl| 1001 RespHeader c Age: 0
**** v1 0.5 vsl| 1001 RespHeader c Via: 1.1 varnish-v4
**** v1 0.5 vsl| 1001 VCL_call c DELIVER
**** v1 0.5 vsl| 1001 VCL_return c deliver
**** v1 0.5 vsl| 1001 Timestamp c Process: 1436347471.230664 0.011946 0.000164
**** v1 0.5 vsl| 1001 RespHeader c Accept-Ranges: bytes
**** v1 0.5 vsl| 1001 RespUnset c Content-Length: 0
**** v1 0.5 vsl| 1001 RespHeader c Content-Length: 0
**** v1 0.5 vsl| 1001 Debug c RES_MODE 2
**** v1 0.5 vsl| 1001 RespHeader c Connection: keep-alive
**** v1 0.5 vsl| 1001 Timestamp c Resp: 1436347471.230927 0.012208 0.000262
**** v1 0.5 vsl| 1001 ReqAcct c 21 0 21 167 0 167
**** v1 0.5 vsl| 1001 End c
**** v1 0.5 vsl| 1000 Link c req 1003 rxreq
**** v1 0.5 vsl| 1003 Begin c req 1000 rxreq
**** v1 0.5 vsl| 1003 Timestamp c Start: 1436347471.231574 0.000000 0.000000
**** v1 0.5 vsl| 1003 Timestamp c Req: 1436347471.231574 0.000000 0.000000
**** v1 0.5 vsl| 1003 ReqStart c 127.0.0.1 34098
**** v1 0.5 vsl| 1003 ReqMethod c SWAP
**** v1 0.5 vsl| 1003 ReqURL c /
**** v1 0.5 vsl| 1003 ReqProtocol c HTTP/1.1
**** v1 0.5 vsl| 1003 ReqHeader c X-Addr: 127.0.0.1
**** v1 0.5 vsl| 1003 ReqHeader c X-Port: 49265
**** v1 0.5 vsl| 1003 ReqHeader c X-Forwarded-For: 127.0.0.1
**** v1 0.5 vsl| 1003 VCL_call c RECV
---- c1 0.5 HTTP rx EOF (fd:12 read: Success)
* top 0.5 RESETTING after ./tests/d00008.vtc
** s1 0.5 Waiting for server (3/-1)
**** s1 0.5 macro undef s1_addr
**** s1 0.5 macro undef s1_port
**** s1 0.5 macro undef s1_sock
** s2 0.5 Waiting for server (4/-1)
**** s2 0.5 macro undef s2_addr
**** s2 0.5 macro undef s2_port
**** s2 0.5 macro undef s2_sock
*** v1 1.5 debug| Child (21950) died signal=6 (core dumped)\n
**** v1 1.5 CLI TX| backend.list
*** v1 1.5 debug| Child (21950) Panic message:\n
*** v1 1.5 debug| Assert error in VBE_Delete(), cache/cache_backend_cfg.c line 185:\n
*** v1 1.5 debug| Condition((be->vsc) == 0) not true.\n
*** v1 1.5 debug| thread = (cache-worker)\n
*** v1 1.5 debug| version = varnish-trunk revision 8922d14\n
*** v1 1.5 debug| ident = Linux,4.0.6-200.fc21.x86_64,x86_64,-jnone,-smalloc,-smalloc,-hcritbit,epoll\n
*** v1 1.5 debug| Backtrace:\n
*** v1 1.5 debug| 0x43220f: pan_ic+0x12f\n
*** v1 1.5 debug| 0x4134ec: VBE_Delete+0x12c\n
*** v1 1.5 debug| 0x7f87ff1fafa3: libvmod_debug.so(+0x2fa3) [0x7f87ff1fafa3]\n
*** v1 1.5 debug| 0x7f880008b277: vgc.so(VGC_function_vcl_recv+0x1e7) [0x7f880008b277]\n
*** v1 1.5 debug| 0x43d519: vcl_call_method+0x1e9\n
*** v1 1.5 debug| 0x43f0ba: VCL_recv_method+0x5a\n
*** v1 1.5 debug| 0x43531a: CNT_Request+0x6aa\n
*** v1 1.5 debug| 0x44c513: HTTP1_Session+0x113\n
*** v1 1.5 debug| 0x438541: SES_Proto_Req+0x61\n
*** v1 1.5 debug| 0x446f52: WRK_Thread+0x472\n
*** v1 1.5 debug| req = 0x7f87f741a020 {\n
*** v1 1.5 debug| sp = 0x7f87f740e220, vxid = 1003, step = R_STP_RECV,\n
*** v1 1.5 debug| req_body = R_BODY_NONE,\n
*** v1 1.5 debug| restarts = 0, esi_level = 0,\n
*** v1 1.5 debug| sp = 0x7f87f740e220 {\n
*** v1 1.5 debug| fd = 7, vxid = 1000,\n
*** v1 1.5 debug| client = 127.0.0.1 34098,\n
*** v1 1.5 debug| step = S_STP_H1PROC,\n
*** v1 1.5 debug| },\n
*** v1 1.5 debug| worker = 0x7f8803034c80 {\n
*** v1 1.5 debug| stack = {0x7f8803035000 -> 0x7f8803029000}\n
*** v1 1.5 debug| ws = 0x7f8803034e80 {\n
*** v1 1.5 debug| id = "wrk",\n
*** v1 1.5 debug| {s,f,r,e} = {0x7f8803034420,0x7f8803034420,(nil),+2040},\n
*** v1 1.5 debug| },\n
*** v1 1.5 debug| VCL::method = *RECV,\n
*** v1 1.5 debug| VCL::return = abandon,\n
*** v1 1.5 debug| VCL::methods = {RECV, HASH, MISS, DELIVER},\n
*** v1 1.5 debug| },\n
*** v1 1.5 debug| ws = 0x7f87f741a220 {\n
*** v1 1.5 debug| id = "req",\n
*** v1 1.5 debug| {s,f,r,e} = {0x7f87f741c028,+88,(nil),+57296},\n
*** v1 1.5 debug| },\n
*** v1 1.5 debug| http[req] = {\n
*** v1 1.5 debug| ws = 0x7f87f741a220[req]\n
*** v1 1.5 debug| "SWAP",\n
*** v1 1.5 debug| "/",\n
*** v1 1.5 debug| "HTTP/1.1",\n
*** v1 1.5 debug| "X-Addr: 127.0.0.1",\n
*** v1 1.5 debug| "X-Port: 49265",\n
*** v1 1.5 debug| "X-Forwarded-For: 127.0.0.1",\n
*** v1 1.5 debug| },\n
*** v1 1.5 debug| vcl = {\n
*** v1 1.5 debug| srcname = {\n
*** v1 1.5 debug| "input",\n
*** v1 1.5 debug| "Builtin",\n
*** v1 1.5 debug| },\n
*** v1 1.5 debug| },\n
*** v1 1.5 debug| flags = {\n
*** v1 1.5 debug| wantbody,\n
*** v1 1.5 debug| }\n
*** v1 1.5 debug| },\n
*** v1 1.5 debug| \n
*** v1 1.5 debug| \n
*** v1 1.5 debug| Child cleanup complete\n
*** v1 1.5 CLI RX 101
**** v1 1.5 CLI RX| Unknown request in manager process (child not running).\n
**** v1 1.5 CLI RX| Type 'help' for more info.
** v1 1.5 Wait
**** v1 1.5 STDOUT poll 0x10
** v1 1.5 R 21920 Status: 0000 (u 0.143568 s 0.050994)
* top 1.6 TEST ./tests/d00008.vtc FAILED
# top TEST ./tests/d00008.vtc FAILED (1.608) exit=1
**** 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/dridi/varnish/src/varnish-cache/lib/libvmod_std/.libs/libvmod_std.so"
**** top 0.0 macro def vmod_debug=debug from "/home/dridi/varnish/src/varnish-cache/lib/libvmod_debug/.libs/libvmod_debug.so"
**** top 0.0 macro def vmod_directors=directors from "/home/dridi/varnish/src/varnish-cache/lib/libvmod_directors/.libs/libvmod_directors.so"
**** top 0.0 macro def pwd=/home/dridi/varnish/src/varnish-cache/bin/varnishtest
**** top 0.0 macro def topbuild=/home/dridi/varnish/src/varnish-cache
**** top 0.0 macro def bad_ip=192.0.2.255
**** top 0.0 macro def tmpdir=/tmp/vtc.21996.3187715b
* top 0.0 TEST ./tests/d00009.vtc starting
** top 0.0 === varnishtest "Test dynamic backends hot swap while being used...
* top 0.0 TEST Test dynamic backends hot swap while being used
** top 0.0 === server s1 {
** s1 0.0 Starting server
**** s1 0.0 macro def s1_addr=127.0.0.1
**** s1 0.0 macro def s1_port=43720
**** s1 0.0 macro def s1_sock=127.0.0.1 43720
* s1 0.0 Listen on 127.0.0.1 43720
** top 0.0 === server s2 {
** s2 0.0 Starting server
**** s2 0.0 macro def s2_addr=127.0.0.1
**** s2 0.0 macro def s2_port=35589
**** s2 0.0 macro def s2_sock=127.0.0.1 35589
* s2 0.0 Listen on 127.0.0.1 35589
** top 0.0 === varnish v1 -vcl {
** s1 0.0 Started on 127.0.0.1 43720
** s2 0.0 Started on 127.0.0.1 35589
** v1 0.0 Launch
*** v1 0.0 CMD: cd ${pwd} && exec ${varnishd} -d -n /tmp/vtc.21996.3187715b/v1 -l 2m,1m,- -p auto_restart=off -p syslog_cli_traffic=off -p sigsegv_handler=on -p thread_pool_min=10 -p debug=+vtc_mode -a '127.0.0.1:0' -M '127.0.0.1 40931' -P /tmp/vtc.21996.3187715b/v1/varnishd.pid
*** v1 0.0 CMD: cd /home/dridi/varnish/src/varnish-cache/bin/varnishtest && exec varnishd -d -n /tmp/vtc.21996.3187715b/v1 -l 2m,1m,- -p auto_restart=off -p syslog_cli_traffic=off -p sigsegv_handler=on -p thread_pool_min=10 -p debug=+vtc_mode -a '127.0.0.1:0' -M '127.0.0.1 40931' -P /tmp/vtc.21996.3187715b/v1/varnishd.pid
*** v1 0.0 PID: 22016
**** v1 0.0 macro def v1_pid=22016
**** v1 0.0 macro def v1_name=/tmp/vtc.21996.3187715b/v1
*** v1 0.0 debug| Platform: Linux,4.0.6-200.fc21.x86_64,x86_64,-jnone,-smalloc,-smalloc,-hcritbit\n
*** v1 0.0 debug| 200 287 \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,4.0.6-200.fc21.x86_64,x86_64,-jnone,-smalloc,-smalloc,-hcritbit\n
*** v1 0.0 debug| varnish-trunk revision 8922d14\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 = 11
*** v1 0.1 CLI RX 107
**** v1 0.1 CLI RX| kohrplxdvznuwmbomozdfvjyeydjxrxj\n
**** v1 0.1 CLI RX| \n
**** v1 0.1 CLI RX| Authentication required.\n
**** v1 0.1 CLI TX| auth 058ff8d1e03247a8d1f4258cb2bb94dfabfc0c6b681e98636f293bf866156224\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,4.0.6-200.fc21.x86_64,x86_64,-jnone,-smalloc,-smalloc,-hcritbit\n
**** v1 0.1 CLI RX| varnish-trunk revision 8922d14\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| \n
**** v1 0.1 CLI TX| \timport debug from "/home/dridi/varnish/src/varnish-cache/lib/libvmod_debug/.libs/libvmod_debug.so";\n
**** v1 0.1 CLI TX| \n
**** v1 0.1 CLI TX| \tbackend dummy { .host = "192.0.2.255"; }\n
**** v1 0.1 CLI TX| \n
**** v1 0.1 CLI TX| \tsub vcl_init {\n
**** v1 0.1 CLI TX| \t\tnew s1 = debug.dyn("127.0.0.1", "43720");\n
**** v1 0.1 CLI TX| \t}\n
**** v1 0.1 CLI TX| \n
**** v1 0.1 CLI TX| \tsub vcl_recv {\n
**** v1 0.1 CLI TX| \t\tif (req.method == "SWAP") {\n
**** v1 0.1 CLI TX| \t\t\ts1.hot_swap(req.http.X-Addr ,req.http.X-Port);\n
**** v1 0.1 CLI TX| \t\t\treturn (synth(200));\n
**** v1 0.1 CLI TX| \t\t}\n
**** v1 0.1 CLI TX| \t\tset req.backend_hint = s1.backend();\n
**** v1 0.1 CLI TX| \t}\n
**** v1 0.1 CLI TX| \n
**** v1 0.1 CLI TX| %XJEIFLH|)Xspa8P\n
*** v1 0.3 CLI RX 200
**** v1 0.3 CLI RX| VCL compiled.\n
**** v1 0.3 CLI TX| vcl.use vcl1
*** v1 0.3 CLI RX 200
** v1 0.3 Start
**** v1 0.3 CLI TX| start
*** v1 0.3 debug| child (22193) Started\n
*** v1 0.3 debug| Child (22193) said Child starts\n
*** v1 0.3 CLI RX 200
*** v1 0.3 wait-running
**** v1 0.3 CLI TX| status
*** v1 0.4 CLI RX 200
**** v1 0.4 CLI RX| Child in state running
**** v1 0.4 CLI TX| debug.xid 999
**** v1 0.4 vsl| 0 CLI - Rd vcl.load "vcl1" vcl_vcl1/vgc.so 1auto
**** v1 0.4 vsl| 0 CLI - Wr 200 34 Loaded "vcl_vcl1/vgc.so" as "vcl1"
**** v1 0.4 vsl| 0 CLI - Rd vcl.use "vcl1"
**** v1 0.4 vsl| 0 CLI - Wr 200 0
**** v1 0.4 vsl| 0 CLI - Rd start
**** v1 0.4 vsl| 0 CLI - Wr 200 0
*** v1 0.4 CLI RX 200
**** v1 0.4 CLI RX| XID is 999
**** v1 0.4 CLI TX| debug.listen_address
**** v1 0.4 vsl| 0 CLI - Rd debug.xid 999
**** v1 0.4 vsl| 0 CLI - Wr 200 10 XID is 999
*** v1 0.5 CLI RX 200
**** v1 0.5 CLI RX| 127.0.0.1 44976\n
** v1 0.5 Listen on 127.0.0.1 44976
**** v1 0.5 macro def v1_addr=127.0.0.1
**** v1 0.5 macro def v1_port=44976
**** v1 0.5 macro def v1_sock=127.0.0.1 44976
** top 0.5 === varnish v1 -expect MAIN.n_backend == 2
** v1 0.5 as expected: MAIN.n_backend (2) == 2
** top 0.5 === client c1 {
** c1 0.5 Starting client
** top 0.5 === client c2 {
** c2 0.5 Starting client
*** c1 0.5 Connect to 127.0.0.1 44976
** c2 0.5 Waiting for client
*** c1 0.5 connected fd 12 from 127.0.0.1 52501 to 127.0.0.1 44976
** c1 0.5 === txreq -url "/foo"
**** c1 0.5 txreq| GET /foo HTTP/1.1\r\n
**** c1 0.5 txreq| \r\n
** c1 0.5 === rxresp
*** s1 0.5 accepted fd 5
** s1 0.5 === rxreq
**** s1 0.5 rxhdr| GET /foo HTTP/1.1\r\n
**** s1 0.5 rxhdr| X-Forwarded-For: 127.0.0.1\r\n
**** s1 0.5 rxhdr| Accept-Encoding: gzip\r\n
**** s1 0.5 rxhdr| X-Varnish: 1002\r\n
**** s1 0.5 rxhdr| Host: 127.0.0.1\r\n
**** s1 0.5 rxhdr| \r\n
**** s1 0.5 rxhdrlen = 106
**** s1 0.5 http[ 0] | GET
**** s1 0.5 http[ 1] | /foo
**** s1 0.5 http[ 2] | HTTP/1.1
**** s1 0.5 http[ 3] | X-Forwarded-For: 127.0.0.1
**** s1 0.5 http[ 4] | Accept-Encoding: gzip
**** s1 0.5 http[ 5] | X-Varnish: 1002
**** s1 0.5 http[ 6] | Host: 127.0.0.1
**** s1 0.5 bodylen = 0
** s1 0.5 === expect req.url == "/foo"
**** s1 0.5 EXPECT req.url (/foo) == "/foo" match
** s1 0.5 === sema r1 sync 2
**** s1 0.5 Sema(r1) wait 1 of 2
**** v1 0.5 vsl| 0 CLI - Rd debug.listen_address
**** v1 0.5 vsl| 0 CLI - Wr 200 16 127.0.0.1 44976
**** v1 0.5 vsl| 1000 Begin c sess 0 HTTP/1
**** v1 0.5 vsl| 1000 SessOpen c 127.0.0.1 52501 127.0.0.1:44976 127.0.0.1 44976 1436347471.605350 12
**** v1 0.5 vsl| 1000 Link c req 1001 rxreq
*** c2 0.5 Connect to 127.0.0.1 44976
*** c2 0.5 connected fd 13 from 127.0.0.1 52504 to 127.0.0.1 44976
** c2 0.5 === sema r1 sync 2
**** c2 0.5 Sema(r1) wake 2
** s1 0.5 === sema r2 sync 2
**** s1 0.5 Sema(r2) wait 1 of 2
** c2 0.5 === txreq -req "SWAP" -hdr "X-Addr: 127.0.0.1" -hdr "X-Port: 355...
**** c2 0.5 txreq| SWAP / HTTP/1.1\r\n
**** c2 0.5 txreq| X-Addr: 127.0.0.1\r\n
**** c2 0.5 txreq| X-Port: 35589\r\n
**** c2 0.5 txreq| \r\n
** c2 0.5 === rxresp
**** v1 0.5 vsl| 1003 Begin c sess 0 HTTP/1
**** v1 0.5 vsl| 1003 SessOpen c 127.0.0.1 52504 127.0.0.1:44976 127.0.0.1 44976 1436347471.612039 13
**** v1 0.5 vsl| 1003 Link c req 1004 rxreq
**** v1 0.5 vsl| 1004 Begin c req 1003 rxreq
**** v1 0.5 vsl| 1004 Timestamp c Start: 1436347471.612086 0.000000 0.000000
**** v1 0.5 vsl| 1004 Timestamp c Req: 1436347471.612086 0.000000 0.000000
**** v1 0.5 vsl| 1004 ReqStart c 127.0.0.1 52504
**** v1 0.5 vsl| 1004 ReqMethod c SWAP
**** v1 0.5 vsl| 1004 ReqURL c /
**** v1 0.5 vsl| 1004 ReqProtocol c HTTP/1.1
**** v1 0.5 vsl| 1004 ReqHeader c X-Addr: 127.0.0.1
**** v1 0.5 vsl| 1004 ReqHeader c X-Port: 35589
**** v1 0.5 vsl| 1004 ReqHeader c X-Forwarded-For: 127.0.0.1
**** v1 0.5 vsl| 1004 VCL_call c RECV
---- c2 0.5 HTTP rx EOF (fd:13 read: Success)
* top 0.5 RESETTING after ./tests/d00009.vtc
*** v1 0.5 debug| Child (22193) died signal=6 (core dumped)\n
** s1 0.5 Waiting for server (3/-1)
**** s1 0.5 macro undef s1_addr
**** s1 0.5 macro undef s1_port
**** s1 0.5 macro undef s1_sock
** s2 0.5 Waiting for server (4/-1)
**** s2 0.5 macro undef s2_addr
**** s2 0.5 macro undef s2_port
**** s2 0.5 macro undef s2_sock
** c1 0.5 Waiting for client
*** v1 0.5 debug| Child (22193) Panic message:\n
*** v1 0.5 debug| Assert error in VBT_Rel(), cache/cache_backend_tcp.c line 188:\n
*** v1 0.5 debug| Condition((tp->n_used) == 0) not true.\n
*** v1 0.5 debug| thread = (cache-worker)\n
*** v1 0.5 debug| version = varnish-trunk revision 8922d14\n
*** v1 0.5 debug| ident = Linux,4.0.6-200.fc21.x86_64,x86_64,-jnone,-smalloc,-smalloc,-hcritbit,epoll\n
*** v1 0.5 debug| Backtrace:\n
*** v1 0.5 debug| 0x43220f: pan_ic+0x12f\n
*** v1 0.5 debug| 0x415360: VBT_Rel+0x220\n
*** v1 0.5 debug| 0x413438: VBE_Delete+0x78\n
*** v1 0.5 debug| 0x7f175b5f7fa3: libvmod_debug.so(+0x2fa3) [0x7f175b5f7fa3]\n
*** v1 0.5 debug| 0x7f175ddfb277: vgc.so(VGC_function_vcl_recv+0x1e7) [0x7f175ddfb277]\n
*** v1 0.5 debug| 0x43d519: vcl_call_method+0x1e9\n
*** v1 0.5 debug| 0x43f0ba: VCL_recv_method+0x5a\n
*** v1 0.5 debug| 0x43531a: CNT_Request+0x6aa\n
*** v1 0.5 debug| 0x44c513: HTTP1_Session+0x113\n
*** v1 0.5 debug| 0x438541: SES_Proto_Req+0x61\n
*** v1 0.5 debug| req = 0x7f1755418020 {\n
*** v1 0.5 debug| sp = 0x7f175540e220, vxid = 1004, step = R_STP_RECV,\n
*** v1 0.5 debug| req_body = R_BODY_NONE,\n
*** v1 0.5 debug| restarts = 0, esi_level = 0,\n
*** v1 0.5 debug| sp = 0x7f175540e220 {\n
*** v1 0.5 debug| fd = 13, vxid = 1003,\n
*** v1 0.5 debug| client = 127.0.0.1 52504,\n
*** v1 0.5 debug| step = S_STP_H1PROC,\n
*** v1 0.5 debug| },\n
*** v1 0.5 debug| worker = 0x7f17618d3c80 {\n
*** v1 0.5 debug| stack = {0x7f17618d4000 -> 0x7f17618c8000}\n
*** v1 0.5 debug| ws = 0x7f17618d3e80 {\n
*** v1 0.5 debug| id = "wrk",\n
*** v1 0.5 debug| {s,f,r,e} = {0x7f17618d3420,0x7f17618d3420,(nil),+2040},\n
*** v1 0.5 debug| },\n
*** v1 0.5 debug| VCL::method = *RECV,\n
*** v1 0.5 debug| VCL::return = abandon,\n
*** v1 0.5 debug| VCL::methods = {RECV},\n
*** v1 0.5 debug| },\n
*** v1 0.5 debug| ws = 0x7f1755418220 {\n
*** v1 0.5 debug| id = "req",\n
*** v1 0.5 debug| {s,f,r,e} = {0x7f175541a028,+88,(nil),+57296},\n
*** v1 0.5 debug| },\n
*** v1 0.5 debug| http[req] = {\n
*** v1 0.5 debug| ws = 0x7f1755418220[req]\n
*** v1 0.5 debug| "SWAP",\n
*** v1 0.5 debug| "/",\n
*** v1 0.5 debug| "HTTP/1.1",\n
*** v1 0.5 debug| "X-Addr: 127.0.0.1",\n
*** v1 0.5 debug| "X-Port: 35589",\n
*** v1 0.5 debug| "X-Forwarded-For: 127.0.0.1",\n
*** v1 0.5 debug| },\n
*** v1 0.5 debug| vcl = {\n
*** v1 0.5 debug| srcname = {\n
*** v1 0.5 debug| "input",\n
*** v1 0.5 debug| "Builtin",\n
*** v1 0.5 debug| },\n
*** v1 0.5 debug| },\n
*** v1 0.5 debug| flags = {\n
*** v1 0.5 debug| }\n
*** v1 0.5 debug| },\n
*** v1 0.5 debug| \n
*** v1 0.5 debug| \n
*** v1 0.5 debug| Child cleanup complete\n
**** v1 1.5 CLI TX| backend.list
*** v1 1.5 CLI RX 101
**** v1 1.5 CLI RX| Unknown request in manager process (child not running).\n
**** v1 1.5 CLI RX| Type 'help' for more info.
** v1 1.5 Wait
**** v1 1.5 STDOUT poll 0x10
** v1 1.5 R 22016 Status: 0000 (u 0.149770 s 0.045677)
# top TEST ./tests/d00009.vtc FAILED (60.046) signal=9 exit=0
_______________________________________________
varnish-dev mailing list
[email protected]
https://www.varnish-cache.org/lists/mailman/listinfo/varnish-dev
