**** dT 0.000 * top TEST ../../../../bin/vinyltest/tests/r03940.vtc starting **** top extmacro def pkg_version=trunk **** top extmacro def pkg_branch=trunk **** top extmacro def pwd=/root/vinyl-cache/vinyl-cache-trunk/_build/sub/bin/vinyltest **** 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:39463 **** top extmacro def listen_addr=127.0.0.1:0 **** top extmacro def bad_ip=192.0.2.255 **** top extmacro def topbuild=/root/vinyl-cache/vinyl-cache-trunk/_build/sub **** top extmacro def topsrc=/root/vinyl-cache/vinyl-cache-trunk/_build/sub/../.. **** top macro def testdir=/root/vinyl-cache/vinyl-cache-trunk/_build/sub/bin/vinyltest/../../../../bin/vinyltest/tests **** top macro def tmpdir=/root/_vtest_tmp/vtc.842838.7575a24a **** top macro def vtcid=vtc.842838.7575a24a ** top === vtest "test startup_timeout vs. stevedore init / open" * top VTEST test startup_timeout vs. stevedore init / open ** top === vinyl v1 -arg "-sdebug=debug,dinit=5s -pstartup_timeout=3s -... **** dT 0.005 ** v1 Launch *** v1 CMD: cd ${pwd} && exec vinyld -d -n /root/_vtest_tmp/vtc.842838.7575a24a/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 45301' -P /root/_vtest_tmp/vtc.842838.7575a24a/v1/vinyld.pid -p vmod_path=/root/vinyl-cache/vinyl-cache-trunk/_build/sub/vmod/.libs: -sdebug=debug,dinit=5s -pstartup_timeout=3s -pcli_timeout=2s -p feature=+no_coredump *** v1 CMD: cd /root/vinyl-cache/vinyl-cache-trunk/_build/sub/bin/vinyltest && exec vinyld -d -n /root/_vtest_tmp/vtc.842838.7575a24a/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 45301' -P /root/_vtest_tmp/vtc.842838.7575a24a/v1/vinyld.pid -p vmod_path=/root/vinyl-cache/vinyl-cache-trunk/_build/sub/vmod/.libs: -sdebug=debug,dinit=5s -pstartup_timeout=3s -pcli_timeout=2s -p feature=+no_coredump *** v1 PID: 842867 **** v1 macro def v1_pid=842867 **** v1 macro def v1_name=/root/_vtest_tmp/vtc.842838.7575a24a/v1 **** dT 0.019 *** v1 debug|Debug: Version: vinyl-cache-trunk revision 655c988a2f079ee458bc64f55f4548862946fe3d *** v1 debug|Debug: Platform: Linux,6.12.96+deb13-cloud-amd64,x86_64,-jnone,-sdebug,-sdefault,-ssynth,-hcritbit *** v1 debug|200 334 *** v1 debug|----------------------------- *** v1 debug|Vinyl Cache CLI 1.0 *** v1 debug|----------------------------- *** v1 debug|Linux,6.12.96+deb13-cloud-amd64,x86_64,-jnone,-sdebug,-sdefault,-ssynth,-hcritbit *** v1 debug|vinyl-cache-trunk revision 655c988a2f079ee458bc64f55f4548862946fe3d *** 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.115 **** v1 CLIPOLL 1 0x1 0x0 0x0 *** v1 CLI connection fd = 4 *** v1 CLI RX 107 **** v1 CLI RX|ouecbrgmvzwofnrqepnbocmdejohyqal **** v1 CLI RX| **** v1 CLI RX|Authentication required. **** v1 CLI TX|auth 615d800f6c19227355a28f306b5e4bd512a53ee3b271acdf7e15ca0286b05fa0 **** dT 0.116 *** v1 CLI RX 200 **** v1 CLI RX|----------------------------- **** v1 CLI RX|Vinyl Cache CLI 1.0 **** v1 CLI RX|----------------------------- **** v1 CLI RX|Linux,6.12.96+deb13-cloud-amd64,x86_64,-jnone,-sdebug,-sdefault,-ssynth,-hcritbit **** v1 CLI RX|vinyl-cache-trunk revision 655c988a2f079ee458bc64f55f4548862946fe3d **** 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. **** v1 CLI TX|vcl.inline vcl1 << %XJEIFLH|)Xspa8P **** v1 CLI TX|vcl 4.1; **** v1 CLI TX|backend none none; **** v1 CLI TX|%XJEIFLH|)Xspa8P **** dT 0.216 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.319 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.419 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.520 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.593 *** v1 CLI RX 200 **** v1 CLI RX|VCL compiled. **** v1 CLI TX|vcl.use vcl1 *** v1 CLI RX 200 **** v1 CLI RX|VCL 'vcl1' now active ** top === vinyl v1 -cliexpect \ **** v1 CLI TX|start **** dT 0.620 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.643 *** v1 debug|Debug: Child (843050) Started **** dT 0.722 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.822 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.927 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.027 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.128 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.228 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.328 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.428 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.528 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.631 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.731 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.832 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.932 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.032 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.132 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.233 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.333 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.433 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.534 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.634 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.734 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.835 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.935 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.035 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.135 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.236 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.336 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.436 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.536 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.637 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.655 *** v1 debug|Error: Child failed on launch within startup_timeout=3.00s *** v1 debug|Error: Child (843050) said Child starts *** v1 debug|Error: Child (843050) said -sdebug init delay 5.000000s *** v1 debug|Error: Child (843050) said -sdebug open delay in init 0.000000s **** dT 3.737 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.837 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.938 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.039 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.139 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.239 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.339 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.440 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.541 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.641 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.741 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.841 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.941 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.042 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.142 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.243 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.343 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.446 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.547 *** v1 vsl|No VSL chunk found (child not started ?)