**** 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:39783 **** 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/../.. **** dT 0.001 **** 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.334794.0874f8db **** top macro def vtcid=vtc.334794.0874f8db **** top macro def n=${n} ** 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.004 ** v1 Launch *** v1 CMD: cd ${pwd} && exec vinyld -d -n /root/_vtest_tmp/vtc.334794.0874f8db/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 45995' -P /root/_vtest_tmp/vtc.334794.0874f8db/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.334794.0874f8db/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 45995' -P /root/_vtest_tmp/vtc.334794.0874f8db/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 **** dT 0.005 *** v1 PID: 334822 **** v1 macro def v1_pid=334822 **** v1 macro def v1_name=/root/_vtest_tmp/vtc.334794.0874f8db/v1 **** dT 0.014 *** v1 debug|Debug: Version: vinyl-cache-trunk revision 3a4b360508766b9441dbe065c3b5b3fcfa173bf8 *** v1 debug|Debug: Platform: Linux,6.12.105+deb13-cloud-amd64,x86_64,-jnone,-sdebug,-sdefault,-ssynth,-hcritbit *** v1 debug|200 335 *** v1 debug|----------------------------- *** v1 debug|Vinyl Cache CLI 1.0 *** v1 debug|----------------------------- *** v1 debug|Linux,6.12.105+deb13-cloud-amd64,x86_64,-jnone,-sdebug,-sdefault,-ssynth,-hcritbit *** v1 debug|vinyl-cache-trunk revision 3a4b360508766b9441dbe065c3b5b3fcfa173bf8 *** 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.112 **** v1 CLIPOLL 1 0x1 0x0 0x0 *** v1 CLI connection fd = 4 *** v1 CLI RX 107 **** v1 CLI RX|kgyvzpuiydumhwndlqnaauffzaleqmwf **** v1 CLI RX| **** v1 CLI RX|Authentication required. **** dT 0.113 **** v1 CLI TX|auth 18db860bad63abb654c56e4ad626aec5654340c3bcf42160f3c05aee80098e61 *** v1 CLI RX 200 **** v1 CLI RX|----------------------------- **** v1 CLI RX|Vinyl Cache CLI 1.0 **** v1 CLI RX|----------------------------- **** v1 CLI RX|Linux,6.12.105+deb13-cloud-amd64,x86_64,-jnone,-sdebug,-sdefault,-ssynth,-hcritbit **** v1 CLI RX|vinyl-cache-trunk revision 3a4b360508766b9441dbe065c3b5b3fcfa173bf8 **** 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.214 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.314 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.414 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.516 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.616 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.696 *** 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 \ **** dT 0.697 **** v1 CLI TX|start **** dT 0.717 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.746 *** v1 debug|Debug: Child (335088) Started **** dT 0.817 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.918 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.020 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.120 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.221 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.323 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.424 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.524 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.625 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.725 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.828 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.928 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.028 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.129 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.229 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.329 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.429 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.530 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.630 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.730 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.830 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.931 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.032 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.132 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.232 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.333 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.433 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.533 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.633 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.733 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.760 *** v1 debug|Error: Child failed on launch within startup_timeout=3.00s *** v1 debug|Error: Child (335088) said Child starts *** v1 debug|Error: Child (335088) said -sdebug init delay 5.000000s **** dT 3.834 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.934 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.034 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.135 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.235 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.335 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.436 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.536 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.636 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.736 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.837 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.937 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.037 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.137 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.238 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.338 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.439 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.539 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.639 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.740 *** v1 vsl|No VSL chunk found (child not started ?)