**** 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:40909 **** 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.1194341.5f70141a **** top macro def vtcid=vtc.1194341.5f70141a **** 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.1194341.5f70141a/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 38617' -P /root/_vtest_tmp/vtc.1194341.5f70141a/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.1194341.5f70141a/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 38617' -P /root/_vtest_tmp/vtc.1194341.5f70141a/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: 1194369 **** v1 macro def v1_pid=1194369 **** v1 macro def v1_name=/root/_vtest_tmp/vtc.1194341.5f70141a/v1 **** dT 0.017 *** v1 debug|Debug: Version: vinyl-cache-trunk revision 85334e8bfa977d278fd394a036ce1017d97a3d98 *** v1 debug|Debug: Platform: Linux,6.12.113+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.113+deb13-cloud-amd64,x86_64,-jnone,-sdebug,-sdefault,-ssynth,-hcritbit *** v1 debug|vinyl-cache-trunk revision 85334e8bfa977d278fd394a036ce1017d97a3d98 *** 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|ctyqmtonioqohrxrpyglkdmdyflnzpql **** v1 CLI RX| **** v1 CLI RX|Authentication required. **** dT 0.116 **** v1 CLI TX|auth 4fbbbf9b67511cfce99b8309f451ccaa1060d08ded2aa051ee15b5e4cccd544f *** v1 CLI RX 200 **** v1 CLI RX|----------------------------- **** v1 CLI RX|Vinyl Cache CLI 1.0 **** v1 CLI RX|----------------------------- **** v1 CLI RX|Linux,6.12.113+deb13-cloud-amd64,x86_64,-jnone,-sdebug,-sdefault,-ssynth,-hcritbit **** v1 CLI RX|vinyl-cache-trunk revision 85334e8bfa977d278fd394a036ce1017d97a3d98 **** 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.217 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.317 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.417 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.517 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.620 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.630 *** 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.631 **** v1 CLI TX|start **** dT 0.676 *** v1 debug|Debug: Child (1194484) Started **** dT 0.720 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.821 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 0.921 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.021 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.121 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.221 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.322 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.422 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.522 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.623 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.723 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.823 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 1.923 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.024 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.124 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.225 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.325 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.429 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.529 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.629 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.729 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.830 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 2.930 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.033 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.133 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.233 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.333 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.434 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.534 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.635 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.689 *** v1 debug|Error: Child failed on launch within startup_timeout=3.00s *** v1 debug|Error: Child (1194484) said Child starts *** v1 debug|Error: Child (1194484) said -sdebug init delay 5.000000s **** dT 3.735 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.835 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 3.936 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.039 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.142 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.243 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.343 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.443 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.544 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.644 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.745 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.845 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 4.945 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.045 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.145 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.246 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.346 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.446 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.546 *** v1 vsl|No VSL chunk found (child not started ?) **** dT 5.646 *** v1 vsl|No VSL chunk found (child not started ?)