**** dT 0.001 * top TEST ../../../../bin/varnishtest/tests/r02990.vtc starting **** top extmacro def pkg_version=trunk **** top extmacro def pkg_branch=trunk **** top extmacro def pwd=/root/VT/varnish-cache/varnish-trunk/_build/sub/bin/varnishtest **** top extmacro def date(...) **** top extmacro def string(...) **** top extmacro def localhost=127.0.0.1 **** top extmacro def bad_backend=127.0.0.1:13950 **** top extmacro def listen_addr=127.0.0.1:0 **** top extmacro def bad_ip=192.0.2.255 **** top extmacro def topbuild=/root/VT/varnish-cache/varnish-trunk/_build/sub **** top extmacro def topsrc=/root/VT/varnish-cache/varnish-trunk/_build/sub/../.. **** dT 0.002 **** top macro def testdir=/root/VT/varnish-cache/varnish-trunk/_build/sub/bin/varnishtest/../../../../bin/varnishtest/tests **** top macro def tmpdir=/root/VT/_vtest_tmp/vtc.45001.0514a749 **** top macro def vtcid=vtc.45001.0514a749 **** dT 0.004 ** top === varnishtest "Initial varnishstat verbosity" * top VTEST Initial varnishstat verbosity ** top === varnish v1 -vcl {backend be none;} -start **** dT 0.077 ** v1 Launch *** v1 CMD: cd ${pwd} && exec varnishd -d -n /root/VT/_vtest_tmp/vtc.45001.0514a749/v1 -i v1 -l 2m -p auto_restart=off -p syslog_cli_traffic=off -p thread_pool_min=10 -p debug=+vtc_mode -p vsl_mask=+Debug,+H2RxHdr,+H2RxBody -p h2_initial_window_size=1m -p h2_rx_window_low_water=64k -a '127.0.0.1:0' -M '127.0.0.1 16375' -P /root/VT/_vtest_tmp/vtc.45001.0514a749/v1/varnishd.pid -p vmod_path=/root/VT/varnish-cache/varnish-trunk/_build/sub/vmod/.libs *** v1 CMD: cd /root/VT/varnish-cache/varnish-trunk/_build/sub/bin/varnishtest && exec varnishd -d -n /root/VT/_vtest_tmp/vtc.45001.0514a749/v1 -i v1 -l 2m -p auto_restart=off -p syslog_cli_traffic=off -p thread_pool_min=10 -p debug=+vtc_mode -p vsl_mask=+Debug,+H2RxHdr,+H2RxBody -p h2_initial_window_size=1m -p h2_rx_window_low_water=64k -a '127.0.0.1:0' -M '127.0.0.1 16375' -P /root/VT/_vtest_tmp/vtc.45001.0514a749/v1/varnishd.pid -p vmod_path=/root/VT/varnish-cache/varnish-trunk/_build/sub/vmod/.libs **** dT 0.080 *** v1 PID: 45017 **** v1 macro def v1_pid=45017 **** v1 macro def v1_name=/root/VT/_vtest_tmp/vtc.45001.0514a749/v1 **** dT 0.465 *** v1 debug|Debug: Version: varnish-trunk revision 8934271509381d58f014bcce96bc1d8a7941e1e9 *** v1 debug|Debug: Platform: FreeBSD,13.4-RC3,arm,-jnone,-sdefault,-sdefault,-hcritbit *** v1 debug|200 308 *** v1 debug|----------------------------- *** v1 debug|Varnish Cache CLI 1.0 *** v1 debug|----------------------------- *** v1 debug|FreeBSD,13.4-RC3,arm,-jnone,-sdefault,-sdefault,-hcritbit *** v1 debug|varnish-trunk revision 8934271509381d58f014bcce96bc1d8a7941e1e9 *** v1 debug| *** v1 debug|Type 'help' for command list. *** v1 debug|Type 'quit' to close CLI session. *** v1 debug|Type 'start' to launch worker process. *** v1 debug| **** dT 0.540 **** v1 CLIPOLL 1 0x1 0x0 0x0 *** v1 CLI connection fd = 4 **** dT 0.542 *** v1 CLI RX 107 **** v1 CLI RX|sodbprmqclcuiajyrnmaczvyzggtqgil **** v1 CLI RX| **** v1 CLI RX|Authentication required. **** dT 0.545 **** v1 CLI TX|auth 14dc79dcf8f1983e524b9ac1fc428bb03b6b220b48cebce86246f7681c1e61df **** dT 0.549 *** v1 CLI RX 200 **** v1 CLI RX|----------------------------- **** v1 CLI RX|Varnish Cache CLI 1.0 **** v1 CLI RX|----------------------------- **** v1 CLI RX|FreeBSD,13.4-RC3,arm,-jnone,-sdefault,-sdefault,-hcritbit **** v1 CLI RX|varnish-trunk revision 8934271509381d58f014bcce96bc1d8a7941e1e9 **** v1 CLI RX| **** v1 CLI RX|Type 'help' for command list. **** v1 CLI RX|Type 'quit' to close CLI session. **** v1 CLI RX|Type 'start' to launch worker process. **** dT 0.551 **** v1 CLI TX|vcl.inline vcl1 << %XJEIFLH|)Xspa8P **** v1 CLI TX|vcl 4.1; **** v1 CLI TX|backend be none; **** v1 CLI TX|%XJEIFLH|)Xspa8P **** dT 0.669 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.772 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.876 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.980 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.081 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.186 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.288 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.391 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.495 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.599 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.700 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.803 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.906 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.009 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.112 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.215 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.318 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.421 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.524 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.629 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.730 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.835 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.936 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.038 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.140 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.243 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.344 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.447 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.549 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.650 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.753 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.856 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.959 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.061 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.162 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.265 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.365 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.467 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.569 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.672 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.773 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.878 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.979 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.080 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.184 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.285 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.386 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.488 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.590 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.692 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.794 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.896 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.997 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 6.099 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 6.201 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 6.303 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 6.404 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 6.506 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 6.608 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 6.710 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 6.812 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 6.914 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 7.017 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 7.119 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 7.222 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 7.324 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 7.426 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 7.529 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 7.633 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 7.739 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 7.843 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 7.943 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 8.047 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 8.151 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 8.255 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 8.359 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 8.460 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 8.564 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 8.665 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 8.766 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 8.774 *** v1 CLI RX 200 **** v1 CLI RX|VCL compiled. **** v1 CLI TX|vcl.use vcl1 **** dT 8.815 *** v1 CLI RX 200 **** v1 CLI RX|VCL 'vcl1' now active ** v1 Start **** v1 CLI TX|start **** dT 8.868 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 8.930 *** v1 debug|Debug: Child (45026) Started **** dT 8.971 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 9.075 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 9.583 *** v1 debug|Child launched OK **** dT 9.614 *** v1 CLI RX 200 *** v1 wait-running **** v1 CLI TX|status **** dT 9.615 *** v1 debug|Info: Child (45026) said Child starts **** dT 9.656 *** v1 CLI RX 200 **** v1 CLI RX|Child in state running **** v1 CLI TX|debug.listen_address **** dT 9.687 **** v1 vsl| 0 CLI - Rd vcl.load "vcl1" vcl_vcl1.1732849423.232460/vgc.so 1auto **** v1 vsl| 0 CLI - Wr 200 52 Loaded "vcl_vcl1.1732849423.232460/vgc.so" as "vcl1" **** v1 vsl| 0 CLI - Rd vcl.use "vcl1" **** v1 vsl| 0 CLI - Wr 200 0 **** v1 vsl| 0 CLI - Rd start **** v1 vsl| 0 Debug - sockopt: Setting SO_LINGER for a0=127.0.0.1:18578 **** v1 vsl| 0 Debug - sockopt: Setting SO_KEEPALIVE for a0=127.0.0.1:18578 **** v1 vsl| 0 Debug - sockopt: Setting SO_SNDTIMEO for a0=127.0.0.1:18578 **** v1 vsl| 0 Debug - sockopt: Setting SO_RCVTIMEO for a0=127.0.0.1:18578 **** v1 vsl| 0 Debug - sockopt: Setting TCP_NODELAY for a0=127.0.0.1:18578 **** v1 vsl| 0 Debug - sockopt: Setting TCP_KEEPIDLE for a0=127.0.0.1:18578 **** v1 vsl| 0 Debug - sockopt: Setting TCP_KEEPCNT for a0=127.0.0.1:18578 **** v1 vsl| 0 Debug - sockopt: Setting TCP_KEEPINTVL for a0=127.0.0.1:18578 **** v1 vsl| 0 Error - Kernel filtering: sock=3, errno=2 No such file or directory **** v1 vsl| 0 CLI - Wr 200 0 **** dT 9.700 *** v1 CLI RX 200 **** v1 CLI RX|a0 127.0.0.1 18578 **** v1 CLI TX|debug.xid 1000 **** dT 9.743 *** v1 CLI RX 200 **** v1 CLI RX|XID is 1000 chunk 1 **** v1 CLI TX|debug.listen_address **** dT 9.789 *** v1 CLI RX 200 **** v1 CLI RX|a0 127.0.0.1 18578 ** v1 Listen on 127.0.0.1 18578 **** v1 macro def v1_addr=127.0.0.1 **** v1 macro def v1_port=18578 **** v1 macro def v1_sock=127.0.0.1:18578 **** v1 macro def v1_a0_addr=127.0.0.1 **** v1 macro def v1_a0_port=18578 **** v1 macro def v1_a0_sock=127.0.0.1:18578 ** top === process p1 -dump {varnishstat -n ${v1_name}} -start **** dT 9.810 **** v1 vsl| 0 CLI - Rd debug.listen_address **** v1 vsl| 0 CLI - Wr 200 19 a0 127.0.0.1 18578 **** v1 vsl| 0 CLI - Rd debug.xid 1000 **** dT 9.811 **** v1 vsl| 0 CLI - Wr 200 19 XID is 1000 chunk 1 **** v1 vsl| 0 CLI - Rd debug.listen_address **** v1 vsl| 0 CLI - Wr 200 19 a0 127.0.0.1 18578 **** dT 9.840 **** p1 CMD: varnishstat -n /root/VT/_vtest_tmp/vtc.45001.0514a749/v1 **** dT 9.846 *** p1 PID: 45030 **** dT 9.849 **** p1 macro def p1_pid=45030 **** p1 macro def p1_dir=/root/VT/_vtest_tmp/vtc.45001.0514a749/p1 **** p1 macro def p1_out=/root/VT/_vtest_tmp/vtc.45001.0514a749/p1/term **** p1 macro def p1_err=/root/VT/_vtest_tmp/vtc.45001.0514a749/p1/stderr ** top === process p2 -dump {varnishstat -n ${v1_name} -f MGT.child_sta... **** dT 9.930 **** p2 CMD: varnishstat -n /root/VT/_vtest_tmp/vtc.45001.0514a749/v1 -f MGT.child_start **** dT 9.936 *** p2 PID: 45037 **** dT 9.943 **** p2 macro def p2_pid=45037 **** p2 macro def p2_dir=/root/VT/_vtest_tmp/vtc.45001.0514a749/p2 **** p2 macro def p2_out=/root/VT/_vtest_tmp/vtc.45001.0514a749/p2/term **** p2 macro def p2_err=/root/VT/_vtest_tmp/vtc.45001.0514a749/p2/stderr ** top === process p1 -expect-text 0 0 INFO **** dT 10.452 **** p1 stdout|\x1b[1;24r\x1b[m\x1b[4l\x1b[?25l **** dT 10.454 **** p2 stdout|\x1b[1;24r\x1b[m\x1b[4l\x1b[?25l **** dT 10.456 **** p1 stdout|\x1b[?1h\x1b= **** dT 10.458 **** p2 stdout|\x1b[?1h\x1b= **** dT 10.466 **** p1 stdout|\x1b[H\x1b[2J\x1b[3B **** dT 10.471 **** p2 stdout|\x1b[H\x1b[2J\x1b[3B **** dT 10.474 **** p1 stdout|\x1b[7m \x1b[21;1H **** dT 10.477 **** p2 stdout|\x1b[7m \x1b[21;1H **** dT 10.480 **** p1 stdout| \x1b[22;1H **** dT 10.482 **** p2 stdout| \x1b[22;1H **** dT 10.484 **** p1 stdout|\x1b[m **** dT 10.486 **** p2 stdout|\x1b[m **** dT 10.506 **** p1 stdout|\x1b[H **** dT 10.523 **** p2 stdout|\x1b[H **** dT 10.525 **** p1 stdout|Uptime mgt:\x1b[6C **** dT 10.527 **** p2 stdout|Uptime mgt:\x1b[6C **** dT 10.529 **** p1 stdout|0+00:00:01\x1b[1;44H **** p1 stdout|Hitrate n:\x1b[1;62H **** dT 10.531 **** p2 stdout|0+00:00:01\x1b[1;44H **** dT 10.534 **** p1 stdout|1\x1b[1;71H **** p1 stdout|1\x1b[8C **** dT 10.536 **** p2 stdout|Hitrate n:\x1b[1;62H **** dT 10.538 **** p1 stdout|1\x1b[2;1H **** dT 10.539 **** p1 stdout|Uptime child: 0+00:00:00\x1b[2;47H **** dT 10.541 **** p2 stdout|1\x1b[1;71H **** dT 10.543 **** p1 stdout|avg(n): 0.0000 0.0000 0.0000\x1b[3;1H **** dT 10.547 **** p2 stdout|1\x1b[8C **** dT 10.549 **** p1 stdout|Press to toggle help screen\r\x1b[1B **** dT 10.551 **** p2 stdout|1\x1b[2;1H **** dT 10.554 **** p1 stdout|\x1b[7m NAME CURRENT CHANGE AVERAGE AVG_10 \x1b[21;1H **** dT 10.556 **** p2 stdout|Uptime child: 0+00:00:00\x1b[2;47H **** dT 10.558 **** p1 stdout| INFO 1-0/0\x1b[22;1H **** dT 10.559 **** p2 stdout|avg(n): 0.0000 0.0000 0.0000\x1b[3;1H **** dT 10.561 **** p1 stdout|\x1b[m **** dT 10.563 **** p2 stdout|Press to toggle help screen\r\x1b[1B **** dT 10.567 **** p2 stdout|\x1b[7m NAME CURRENT CHANGE AVERAGE AVG_10 \x1b[21;1H **** dT 10.569 **** p2 stdout| DIAG 1-0/0\x1b[22;1H **** dT 10.571 **** p2 stdout|\x1b[m **** dT 10.588 **** p1 found expected text at 21,70: 'INFO' ** top === process p1 -screen_dump *** p1 screen|Uptime mgt: 0+00:00:01 Hitrate n: 1 1 1 *** p1 screen|Uptime child: 0+00:00:00 avg(n): 0.0000 0.0000 0.0000 *** p1 screen|Press to toggle help screen *** p1 screen| NAME CURRENT CHANGE AVERAGE AVG_10 *** p1 screen| *** p1 screen| *** p1 screen| *** p1 screen| *** p1 screen| *** p1 screen| *** p1 screen| *** p1 screen| *** p1 screen| *** p1 screen| *** p1 screen| *** p1 screen| *** p1 screen| *** p1 screen| *** p1 screen| *** p1 screen| *** p1 screen| INFO 1-0/0 **** dT 10.589 *** p1 screen| *** p1 screen| *** p1 screen| *** p1 Cursor at line 22 column 1 ** top === process p2 -expect-text 0 0 MGT.child_start **** dT 10.625 **** v1 vsl| 0 Debug - sockopt: Not setting unmodified SO_LINGER for a0=127.0.0.1:18578 **** v1 vsl| 0 Debug - sockopt: Not setting unmodified SO_KEEPALIVE for a0=127.0.0.1:18578 **** v1 vsl| 0 Debug - sockopt: Setting SO_SNDTIMEO for a0=127.0.0.1:18578 **** v1 vsl| 0 Debug - sockopt: Setting SO_RCVTIMEO for a0=127.0.0.1:18578 **** v1 vsl| 0 Debug - sockopt: Not setting unmodified TCP_NODELAY for a0=127.0.0.1:18578 **** v1 vsl| 0 Debug - sockopt: Not setting unmodified TCP_KEEPIDLE for a0=127.0.0.1:18578 **** v1 vsl| 0 Debug - sockopt: Not setting unmodified TCP_KEEPCNT for a0=127.0.0.1:18578 **** v1 vsl| 0 Debug - sockopt: Not setting unmodified TCP_KEEPINTVL for a0=127.0.0.1:18578 **** dT 11.691 **** p1 stdout|\x1b[1;27H **** p2 stdout|\x1b[1;27H **** dT 11.721 **** p1 stdout|2\x1b[1;62H **** dT 11.724 **** p1 stdout|2\x1b[1;71H **** dT 11.728 **** p1 stdout|2\x1b[8C **** dT 11.732 **** p2 stdout|2\x1b[1;62H **** dT 11.734 **** p2 stdout|2\x1b[1;71H **** dT 11.738 **** p2 stdout|2\x1b[8C **** dT 11.741 **** p2 stdout|2\x1b[2;27H **** dT 11.745 **** p2 stdout|1\r\x1b[3B **** dT 11.748 **** p2 stdout|\x1b[1mMGT.uptime\x1b[5;25H **** dT 11.752 **** p2 stdout| 0+00:00:02\r\x1b[1B **** dT 11.769 **** p1 stdout|2\x1b[2;27H **** dT 11.770 **** p2 stdout|\x1b[mMGT.child_start\x1b[6;37H **** dT 11.797 **** p1 stdout|1\r\x1b[3B **** dT 11.798 **** p2 stdout|1\x1b[6;48H **** dT 11.860 **** p1 stdout|\x1b[1mMGT.uptime\x1b[5;25H **** p1 stdout| 0+00:00:02\r\x1b[1B **** dT 11.865 **** p2 stdout|0.00\x1b[6;62H **** dT 11.870 **** p2 found expected text at 6,1: 'MGT.child_start' **** dT 11.871 ** top === process p2 -expect-text 0 0 DIAG **** p2 found expected text at 21,70: 'DIAG' **** dT 11.872 ** top === process p2 -screen_dump *** p2 screen|Uptime mgt: 0+00:00:02 Hitrate n: 2 2 2 *** p2 screen|Uptime child: 0+00:00:01 avg(n): 0.0000 0.0000 0.0000 **** dT 11.873 *** p2 screen|Press to toggle help screen *** p2 screen| NAME CURRENT CHANGE AVERAGE AVG_10 *** p2 screen|MGT.uptime 0+00:00:02 *** p2 screen|MGT.child_start 1 0.00 **** dT 11.874 *** p2 screen| *** p2 screen| *** p2 screen| *** p2 screen| **** dT 11.875 *** p2 screen| *** p2 screen| *** p2 screen| *** p2 screen| **** dT 11.876 *** p2 screen| *** p2 screen| *** p2 screen| *** p2 screen| **** dT 11.877 *** p2 screen| *** p2 screen| *** p2 screen| DIAG 1-0/0 *** p2 screen| **** dT 11.878 *** p2 screen| *** p2 screen| *** p2 Cursor at line 6 column 62 * top RESETTING after ../../../../bin/varnishtest/tests/r02990.vtc **** dT 11.880 **** p1 Sent signal 15 **** p2 stdout|1.00\x1b[10C **** dT 11.897 **** p1 stdout|\x1b[mMAIN.pools\x1b[6;37H **** dT 11.901 **** p1 stdout|2\x1b[6;48H **** dT 11.904 **** p1 stdout|0.00\x1b[6;63H **** dT 11.907 **** p1 stdout|.\x1b[12C **** dT 11.921 **** p2 stdout|0.00\x1b[21;5H **** dT 11.926 **** p2 stdout|\x1b[7mMGT.uptime\x1b[63C **** p2 stdout|2/2\x1b[22;1H **** dT 11.955 **** p1 stdout|2.00\r\x1b[1B **** dT 11.959 **** p1 stdout|MAIN.threads\x1b[7;36H **** dT 11.962 **** p1 stdout|20\x1b[7;48H **** dT 11.964 **** p1 stdout|0.00\x1b[7;63H **** dT 11.966 **** p1 stdout|.\x1b[11C **** dT 11.982 **** p2 stdout|\x1b[mManagement process uptime:\x1b[23;9H **** dT 11.990 **** p2 stdout|Uptime in seconds of the management process **** dT 12.100 **** p1 stdout|20.00\r\x1b[1B **** dT 12.114 **** p1 stdout|MAIN.threads_created\x1b[8;36H **** dT 12.118 **** p1 stdout|20\x1b[8;48H **** dT 12.120 **** p1 stdout|0.00\x1b[8;61H **** dT 12.201 **** p1 stdout|20.00\x1b[10C **** dT 12.328 **** p1 stdout|0.00\r\x1b[1B **** dT 12.399 **** p1 stdout|MAIN.n_vcl\x1b[9;37H **** dT 12.454 **** p1 stdout|1\x1b[9;48H **** dT 12.456 **** p1 stdout|0.00\x1b[9;63H **** dT 12.458 **** p1 stdout|.\x1b[12C **** dT 12.460 **** p1 stdout|1.00\r\x1b[1B **** dT 12.485 **** p1 stdout|MAIN.bans\x1b[10;37H **** dT 12.490 **** p1 stdout|1\x1b[10;48H **** dT 12.492 **** p1 stdout|0.00\x1b[10;63H **** dT 12.505 **** p1 stdout|.\x1b[12C **** dT 12.556 **** p1 stdout|1.00\r\x1b[1B **** dT 12.560 **** p1 stdout|SMA.s0.g_space\x1b[11;32H **** dT 12.562 **** p1 stdout|100.00M\x1b[11;48H **** dT 12.575 **** p1 stdout|0.00\x1b[11;63H **** dT 12.580 **** p1 stdout|.\x1b[10C **** dT 12.584 **** p1 stdout|100.00M\x1b[21;5H **** dT 12.588 **** p1 stdout|\x1b[7mMGT.uptime\x1b[63C **** dT 12.614 **** v1 vsl| 0 CLI - Rd ping **** v1 vsl| 0 CLI - Wr 200 19 PONG 1732849435 1.0 **** dT 12.688 **** p1 stdout|7/7\x1b[22;1H **** dT 12.765 **** p1 stdout|\x1b[mManagement process uptime:\x1b[23;9H **** dT 12.819 **** p1 stdout|Uptime in seconds of the management process **** dT 12.882 **** p1 Sent signal 9 **** dT 12.893 **** p1 stdout read 0 **** dT 12.897 **** p1 stderr read 0 **** dT 12.902 ** p1 WAIT4 pid=45030 status=0x0009 (user 0.099388 sys 0.102232) * p1 Expected exit: 0x0 signal: 15 core: 0 ---- p1 Bad exit status: 0x0009 exit 0x0 signal 9 core 0 **** p1 stdout 1119 bytes, stderr 0 bytes **** dT 12.918 **** p2 Sent signal 15 **** dT 12.934 **** p2 stdout|\x1b[24;1H\x1b[?12l\x1b[?25h **** dT 12.937 **** p2 stdout|\r\x1b[?1l\x1b> **** dT 12.963 **** p2 stdout read 0 **** dT 12.965 **** p2 stderr read 0 **** dT 12.980 ** p2 WAIT4 pid=45037 status=0x0000 (user 0.090875 sys 0.090875) **** dT 13.986 **** p2 stdout 862 bytes, stderr 0 bytes **** dT 13.987 ** v1 Wait **** v1 CLI TX|panic.show **** dT 14.084 *** v1 CLI RX 300 **** v1 CLI RX|Child has not panicked or panic has been cleared **** dT 14.085 *** v1 debug|Info: manager stopping child *** v1 debug|Debug: Stopping Child **** dT 14.163 **** v1 vsl| 0 CLI - EOF on CLI connection, worker stops **** dT 14.189 *** v1 debug|Info: Child (45026) said Child dies **** dT 14.216 *** v1 debug|Info: Child (45026) ended **** dT 14.228 *** v1 debug|Debug: Child cleanup complete **** dT 14.419 *** v1 debug|Info: manager dies **** dT 14.441 **** v1 STDOUT EOF **** dT 14.443 ** v1 WAIT4 pid=45017 status=0x0000 (user 4.787103 sys 0.811512) **** dT 14.444 * top TEST ../../../../bin/varnishtest/tests/r02990.vtc FAILED # top TEST ../../../../bin/varnishtest/tests/r02990.vtc FAILED (14.467) exit=2 FAIL tests/r02990.vtc (exit status: 2)