Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

e29.vtc fails on SunOS with regex added #4033

Open
nigoroll opened this issue Dec 21, 2023 · 0 comments
Open

e29.vtc fails on SunOS with regex added #4033

nigoroll opened this issue Dec 21, 2023 · 0 comments

Comments

@nigoroll
Copy link
Member

Expected Behavior

Test passes

Current Behavior

Test fails

Possible Solution

No response

Steps to Reproduce (for bugs)

No response

Context

TODO: Revisit 2cae359.

http://varnish-cache.org/vtest/attachment_2cae35978727b706a02b77fce0c82e2863649687_SunOS_i86pc_5.11_1.05_gcc4.7.3%3CBR%3E-m32%3CBR%3EIPv6%3CBR%3Euffix_uplex_e00029.txt

**** dT    0.000
*    top   TEST ../../../bin/varnishtest/tests/e00029.vtc starting
**** top   extmacro def pkg_version=trunk
**** top   extmacro def pkg_branch=trunk
**** top   extmacro def pwd=/tmp/vtest.gcc4.7.3_m32_IPv6_uffix/varnish-cache/varnish-trunk/_build/bin/varnishtest
**** top   extmacro def date(...)
**** top   extmacro def string(...)
**** top   extmacro def localhost=fc00:a462:8e9e:946a:5df3:31c6:d23:18dc
**** top   extmacro def bad_backend=[fc00:a462:8e9e:946a:5df3:31c6:d23:18dc]:34049
**** top   extmacro def listen_addr=[fc00:a462:8e9e:946a:5df3:31c6:d23:18dc]:0
**** top   extmacro def bad_ip=192.0.2.255
**** top   extmacro def topbuild=/tmp/vtest.gcc4.7.3_m32_IPv6_uffix/varnish-cache/varnish-trunk/_build
**** top   extmacro def topsrc=/tmp/vtest.gcc4.7.3_m32_IPv6_uffix/varnish-cache/varnish-trunk/_build/..
**** top   macro def testdir=/tmp/vtest.gcc4.7.3_m32_IPv6_uffix/varnish-cache/varnish-trunk/_build/bin/varnishtest/../../../bin/varnishtest/tests
**** top   macro def tmpdir=/tmp/vtest.gcc4.7.3_m32_IPv6_uffix/_vtest_tmp/vtc.107053.18cca96c
**** top   macro def vtcid=vtc.107053.18cca96c
**   top   === varnishtest "ESI max_esi_depth"
*    top   VTEST ESI max_esi_depth
**   top   === server s1 {
**   s1    Starting server
**** s1    macro def s1_addr=fc00:a462:8e9e:946a:5df3:31c6:d23:18dc
**** s1    macro def s1_port=46343
**** s1    macro def s1_sock=[fc00:a462:8e9e:946a:5df3:31c6:d23:18dc]:46343
*    s1    Listen on [fc00:a462:8e9e:946a:5df3:31c6:d23:18dc]:46343
**** dT    0.001
**   top   === varnish v1 -arg "-p feature=+esi_include_onerror" -vcl+backe...
**   s1    Started on [fc00:a462:8e9e:946a:5df3:31c6:d23:18dc]:46343 (1 iterations)
**** dT    0.013
**   v1    Launch
***  v1    CMD: cd ${pwd} && exec varnishd  -d -n /tmp/vtest.gcc4.7.3_m32_IPv6_uffix/_vtest_tmp/vtc.107053.18cca96c/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 '[fc00:a462:8e9e:946a:5df3:31c6:d23:18dc]:0' -M 'fc00:a462:8e9e:946a:5df3:31c6:d23:18dc 49262' -P /tmp/vtest.gcc4.7.3_m32_IPv6_uffix/_vtest_tmp/vtc.107053.18cca96c/v1/varnishd.pid -p vmod_path=/tmp/vtest.gcc4.7.3_m32_IPv6_uffix/varnish-cache/varnish-trunk/_build/vmod/.libs  -p feature=+esi_include_onerror
***  v1    CMD: cd /tmp/vtest.gcc4.7.3_m32_IPv6_uffix/varnish-cache/varnish-trunk/_build/bin/varnishtest && exec varnishd  -d -n /tmp/vtest.gcc4.7.3_m32_IPv6_uffix/_vtest_tmp/vtc.107053.18cca96c/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 '[fc00:a462:8e9e:946a:5df3:31c6:d23:18dc]:0' -M 'fc00:a462:8e9e:946a:5df3:31c6:d23:18dc 49262' -P /tmp/vtest.gcc4.7.3_m32_IPv6_uffix/_vtest_tmp/vtc.107053.18cca96c/v1/varnishd.pid -p vmod_path=/tmp/vtest.gcc4.7.3_m32_IPv6_uffix/varnish-cache/varnish-trunk/_build/vmod/.libs  -p feature=+esi_include_onerror
**** dT    0.014
***  v1    PID: 107102
**** v1    macro def v1_pid=107102
**** v1    macro def v1_name=/tmp/vtest.gcc4.7.3_m32_IPv6_uffix/_vtest_tmp/vtc.107053.18cca96c/v1
**** dT    0.057
***  v1    debug|Debug: Version: varnish-trunk revision 2cae35978727b706a02b77fce0c82e2863649687
***  v1    debug|Debug: Platform: -jsolaris,-sdefault,-sdefault,-hcritbit
***  v1    debug|200 290     
***  v1    debug|-----------------------------
***  v1    debug|Varnish Cache CLI 1.0
***  v1    debug|-----------------------------
***  v1    debug|-jsolaris,-sdefault,-sdefault,-hcritbit
***  v1    debug|varnish-trunk revision 2cae35978727b706a02b77fce0c82e2863649687
***  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.155
**** v1    CLIPOLL 1 0x1 0x0 0x0
***  v1    CLI connection fd = 6
***  v1    CLI RX  107
**** v1    CLI RX|avhsfmziryvjogtfpzmbxrclyqxeujup
**** v1    CLI RX|
**** v1    CLI RX|Authentication required.
**** dT    0.156
**** v1    CLI TX|auth dee25dc4ee9cb2c07e71e769ede870c6d49fcb3066c3cb2f61a6ca790885f05e
***  v1    CLI RX  200
**** v1    CLI RX|-----------------------------
**** v1    CLI RX|Varnish Cache CLI 1.0
**** v1    CLI RX|-----------------------------
**** v1    CLI RX|-jsolaris,-sdefault,-sdefault,-hcritbit
**** v1    CLI RX|varnish-trunk revision 2cae35978727b706a02b77fce0c82e2863649687
**** 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 s1 { .host = "fc00:a462:8e9e:946a:5df3:31c6:d23:18dc"; .port = "46343"; }
**** v1    CLI TX|
**** v1    CLI TX|
**** v1    CLI TX|\tsub vcl_deliver {
**** v1    CLI TX|\t\t# ref r01576.vtc
**** v1    CLI TX|\t\tset resp.http.torture =
**** v1    CLI TX|\t\t   req.url + "ABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABABAB" ~ "^/(A{1,2}B)+$";
**** v1    CLI TX|\t}
**** v1    CLI TX|\tsub vcl_backend_response {
**** v1    CLI TX|\t\tset beresp.do_esi = true;
**** v1    CLI TX|\t\tset beresp.do_gzip = true;
**** v1    CLI TX|\t}
**** v1    CLI TX|
**** v1    CLI TX|%XJEIFLH|)Xspa8P
**** dT    0.257
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    0.357
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    0.457
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    0.557
***  v1    vsl|No VSL chunk found (child not started ?)
**** dT    0.629
***  v1    CLI RX  200
**** v1    CLI RX|Message from VCC-compiler:
**** v1    CLI RX|Security: Privilege proc_setid missing, will not change uid/gid
**** v1    CLI RX|Message from C-compiler:
**** v1    CLI RX|Security: Privilege proc_setid missing, will not change uid/gid
**** v1    CLI RX|Message from dlopen:
**** v1    CLI RX|Security: Privilege proc_setid missing, will not change uid/gid
**** v1    CLI RX|VCL compiled.
**** v1    CLI TX|vcl.use vcl1
***  v1    CLI RX  200
**** v1    CLI RX|VCL 'vcl1' now active
**   v1    Start
**** v1    CLI TX|start
**** dT    0.639
***  v1    debug|Debug: Child (107644) Started
**** dT    0.671
***  v1    debug|Child launched OK
**** dT    0.673
***  v1    CLI RX  200
***  v1    wait-running
**** v1    CLI TX|status
***  v1    debug|Info: Child (107644) said Child starts
***  v1    debug|Info: Child (107644) said Security: Privilege proc_setid missing, will not change uid/gid
***  v1    CLI RX  200
**** v1    CLI RX|Child in state running
**** v1    CLI TX|debug.listen_address
***  v1    CLI RX  200
**** v1    CLI RX|a0 fc00:a462:8e9e:946a:5df3:31c6:d23:18dc 37765
**** v1    CLI TX|debug.xid 1000
***  v1    CLI RX  200
**** v1    CLI RX|XID is 1000 chunk 1
**** v1    CLI TX|debug.listen_address
***  v1    CLI RX  200
**** v1    CLI RX|a0 fc00:a462:8e9e:946a:5df3:31c6:d23:18dc 37765
**   v1    Listen on fc00:a462:8e9e:946a:5df3:31c6:d23:18dc 37765
**** v1    macro def v1_addr=fc00:a462:8e9e:946a:5df3:31c6:d23:18dc
**** v1    macro def v1_port=37765
**** v1    macro def v1_sock=[fc00:a462:8e9e:946a:5df3:31c6:d23:18dc]:37765
**** v1    macro def v1_a0_addr=fc00:a462:8e9e:946a:5df3:31c6:d23:18dc
**** v1    macro def v1_a0_port=37765
**** v1    macro def v1_a0_sock=[fc00:a462:8e9e:946a:5df3:31c6:d23:18dc]:37765
**** dT    0.757
**** v1    vsl|          0 CLI             - Rd vcl.load "vcl1" vcl_vcl1.1703174937.194608/vgc.so 1auto
**** v1    vsl|          0 CLI             - Wr 200 52 Loaded "vcl_vcl1.1703174937.194608/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=[fc00:a462:8e9e:946a:5df3:31c6:d23:18dc]:37765
**** v1    vsl|          0 Debug           - sockopt: Setting SO_KEEPALIVE for a0=[fc00:a462:8e9e:946a:5df3:31c6:d23:18dc]:37765
**** v1    vsl|          0 Debug           - sockopt: Setting SO_SNDTIMEO for a0=[fc00:a462:8e9e:946a:5df3:31c6:d23:18dc]:37765
**** v1    vsl|          0 Debug           - sockopt: Setting SO_RCVTIMEO for a0=[fc00:a462:8e9e:946a:5df3:31c6:d23:18dc]:37765
**** v1    vsl|          0 Debug           - sockopt: Setting TCP_NODELAY for a0=[fc00:a462:8e9e:946a:5df3:31c6:d23:18dc]:37765
**** v1    vsl|          0 Debug           - sockopt: Setting TCP_KEEPIDLE for a0=[fc00:a462:8e9e:946a:5df3:31c6:d23:18dc]:37765
**** v1    vsl|          0 Debug           - sockopt: Setting TCP_KEEPCNT for a0=[fc00:a462:8e9e:946a:5df3:31c6:d23:18dc]:37765
**** v1    vsl|          0 Debug           - sockopt: Setting TCP_KEEPINTVL for a0=[fc00:a462:8e9e:946a:5df3:31c6:d23:18dc]:37765
**** v1    vsl|          0 CLI             - Wr 200 0 
**** v1    vsl|          0 CLI             - Rd debug.listen_address 
**** v1    vsl|          0 CLI             - Wr 200 48 a0 fc00:a462:8e9e:946a:5df3:31c6:d23:18dc 37765

**** v1    vsl|          0 CLI             - Rd debug.xid 1000 
**** 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 48 a0 fc00:a462:8e9e:946a:5df3:31c6:d23:18dc 37765

**** dT    0.773
**   top   === logexpect l1 -v v1 -g raw {
**** dT    0.774
**   l1    === fail add * VCL_Error {Regexp matching failed}
**   l1    === expect * * VCL_Error {^ESI depth limit reached}
**   l1    === expect 0 = VCL_Error {^ESI depth limit reached}
**   l1    === expect * * VCL_Error {^ESI depth limit reached}
**   l1    === expect 0 = VCL_Error {^ESI depth limit reached}
**   l1    === expect * * VCL_Error {^ESI depth limit reached}
**   l1    === expect 0 = VCL_Error {^ESI depth limit reached}
**   l1    === fail clear
**   top   === client c1 {
**   c1    Starting client
**** l1    begin|
***  l1    cond | fail add * VCL_Error Regexp matching failed
***  l1    test | expect * * VCL_Error ^ESI depth limit reached
**   c1    Waiting for client
**   c1    Started on [fc00:a462:8e9e:946a:5df3:31c6:d23:18dc]:37765 (1 iterations)
***  c1    Connect to [fc00:a462:8e9e:946a:5df3:31c6:d23:18dc]:37765
**** dT    0.775
***  c1    connected fd 21 from fc00:a462:8e9e:946a:5df3:31c6:d23:18dc 45482 to [fc00:a462:8e9e:946a:5df3:31c6:d23:18dc]:37765
**   c1    === txreq -hdr "Host: foo" -hdr "Accept-Encoding: gzip"
**** c1    txreq|GET / HTTP/1.1\r
**** c1    txreq|Host: foo\r
**** c1    txreq|Accept-Encoding: gzip\r
**** c1    txreq|User-Agent: c1\r
**** c1    txreq|\r
**   c1    === rxresp
***  s1    accepted fd 4 fc00:a462:8e9e:946a:5df3:31c6:d23:18dc 60403
**** dT    0.776
**   s1    === rxreq
**** s1    rxhdr|GET / HTTP/1.1\r
**** s1    rxhdr|Host: foo\r
**** s1    rxhdr|Accept-Encoding: gzip\r
**** s1    rxhdr|User-Agent: c1\r
**** s1    rxhdr|X-Forwarded-For: fc00:a462:8e9e:946a:5df3:31c6:d23:18dc\r
**** s1    rxhdr|Via: 1.1 v1 (Varnish/trunk)\r
**** s1    rxhdr|X-Varnish: 1002\r
**** s1    rxhdr|\r
**** s1    rxhdrlen = 171
**** s1    http[ 0] |GET
**** s1    http[ 1] |/
**** s1    http[ 2] |HTTP/1.1
**** s1    http[ 3] |Host: foo
**** s1    http[ 4] |Accept-Encoding: gzip
**** s1    http[ 5] |User-Agent: c1
**** s1    http[ 6] |X-Forwarded-For: fc00:a462:8e9e:946a:5df3:31c6:d23:18dc
**** s1    http[ 7] |Via: 1.1 v1 (Varnish/trunk)
**** s1    http[ 8] |X-Varnish: 1002
**** s1    bodylen = 0
**   s1    === txresp -nolen -hdr "Transfer-Encoding: chunked"
**** s1    txresp|HTTP/1.1 200 OK\r
**** s1    txresp|Transfer-Encoding: chunked\r
**** s1    txresp|Date: Thu, 21 Dec 2023 16:08:57 GMT\r
**** s1    txresp|Server: s1\r
**** s1    txresp|\r
**   s1    === chunked {<html>}
**** s1    chunked|6\r
**** s1    chunked|<html>\r
**   s1    === chunkedlen 1024
**** s1    chunked|400\r
**** s1    chunked|0123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567\r
**   s1    === chunked {<esi:include src="/" onerror="continue"/>}
**** s1    chunked|29\r
**** s1    chunked|<esi:include src="/" onerror="continue"/>\r
**   s1    === chunkedlen 1024
**** s1    chunked|400\r
**** s1    chunked|0123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567\r
**   s1    === chunked {<esi:include src="/" onerror="continue"/>}
**** s1    chunked|29\r
**** s1    chunked|<esi:include src="/" onerror="continue"/>\r
**   s1    === chunkedlen 1024
**** s1    chunked|400\r
**** s1    chunked|0123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567012345670123456701234567\r
**   s1    === chunked {</html>}
**** s1    chunked|7\r
**** s1    chunked|</html>\r
**   s1    === chunkedlen 0
**** s1    chunked|0\r
**** s1    chunked|\r
***  s1    shutting fd 4
**** dT    0.777
**   s1    Ending
**** dT    0.788
**** c1    rxhdr|HTTP/1.1 503 VCL failed\r
**** c1    rxhdr|Date: Thu, 21 Dec 2023 16:08:57 GMT\r
**** c1    rxhdr|Server: Varnish\r
**** c1    rxhdr|X-Varnish: 1001\r
**** c1    rxhdr|Content-Type: text/html; charset=utf-8\r
**** c1    rxhdr|Retry-After: 5\r
**** c1    rxhdr|Content-Length: 251\r
**** c1    rxhdr|Connection: close\r
**** c1    rxhdr|\r
**** c1    rxhdrlen = 194
**** c1    http[ 0] |HTTP/1.1
**** c1    http[ 1] |503
**** c1    http[ 2] |VCL failed
**** c1    http[ 3] |Date: Thu, 21 Dec 2023 16:08:57 GMT
**** c1    http[ 4] |Server: Varnish
**** c1    http[ 5] |X-Varnish: 1001
**** c1    http[ 6] |Content-Type: text/html; charset=utf-8
**** c1    http[ 7] |Retry-After: 5
**** c1    http[ 8] |Content-Length: 251
**** c1    http[ 9] |Connection: close
**** c1    c-l|<!DOCTYPE html>
**** c1    c-l|<html>
**** c1    c-l|  <head>
**** c1    c-l|    <title>503 VCL failed</title>
**** c1    c-l|  </head>
**** c1    c-l|  <body>
**** c1    c-l|    <h1>Error 503 VCL failed</h1>
**** c1    c-l|    <p>VCL failed</p>
**** c1    c-l|    <h3>Guru Meditation:</h3>
**** c1    c-l|    <p>XID: 1001</p>
**** c1    c-l|    <hr>
**** c1    c-l|    <p>Varnish cache server</p>
**** c1    c-l|  </body>
**** c1    c-l|</html>
**** c1    bodylen = 251
**   c1    === expect resp.status == 200
---- c1    EXPECT resp.status (503) == "200" failed
*    top   RESETTING after ../../../bin/varnishtest/tests/e00029.vtc
**   l1    Waiting for logexp
**   s1    Waiting for server (3/-1)
**   v1    Wait
**** v1    CLI TX|panic.show
***  v1    CLI RX  300
**** v1    CLI RX|Child has not panicked or panic has been cleared
***  v1    debug|Info: manager stopping child
***  v1    debug|Debug:
***  v1    debug| Stopping Child
**** dT    0.857
**** v1    vsl|       1000 Begin           c sess 0 HTTP/1
**** v1    vsl|       1000 SessOpen        c fc00:a462:8e9e:946a:5df3:31c6:d23:18dc 45482 a0 fc00:a462:8e9e:946a:5df3:31c6:d23:18dc 37765 1703174937.812893 18
**** v1    vsl|       1000 Debug           c sockopt: Test confirmed SO_KEEPALIVE non heredity for a0=[fc00:a462:8e9e:946a:5df3:31c6:d23:18dc]:37765
**** v1    vsl|       1000 Debug           c sockopt: SO_LINGER may be inherited for a0=[fc00:a462:8e9e:946a:5df3:31c6:d23:18dc]:37765
**** v1    vsl|       1000 Debug           c sockopt: Setting SO_KEEPALIVE for a0=[fc00:a462:8e9e:946a:5df3:31c6:d23:18dc]:37765
**** v1    vsl|       1000 Debug           c sockopt: SO_SNDTIMEO may be inherited for a0=[fc00:a462:8e9e:946a:5df3:31c6:d23:18dc]:37765
**** v1    vsl|       1000 Debug           c sockopt: SO_RCVTIMEO may be inherited for a0=[fc00:a462:8e9e:946a:5df3:31c6:d23:18dc]:37765
**** v1    vsl|       1000 Debug           c sockopt: TCP_NODELAY may be inherited for a0=[fc00:a462:8e9e:946a:5df3:31c6:d23:18dc]:37765
**** v1    vsl|       1000 Debug           c sockopt: TCP_KEEPIDLE may be inherited for a0=[fc00:a462:8e9e:946a:5df3:31c6:d23:18dc]:37765
**** v1    vsl|       1000 Debug           c sockopt: TCP_KEEPCNT may be inherited for a0=[fc00:a462:8e9e:946a:5df3:31c6:d23:18dc]:37765
**** v1    vsl|       1000 Debug           c sockopt: TCP_KEEPINTVL may be inherited for a0=[fc00:a462:8e9e:946a:5df3:31c6:d23:18dc]:37765
**** v1    vsl|       1000 Link            c req 1001 rxreq
**** v1    vsl|       1002 Begin           b bereq 1001 fetch
**** v1    vsl|       1002 VCL_use         b vcl1
**** v1    vsl|       1002 Timestamp       b Start: 1703174937.813394 0.000000 0.000000
**** v1    vsl|       1002 BereqMethod     b GET
**** v1    vsl|       1002 BereqURL        b /
**** v1    vsl|       1002 BereqProtocol   b HTTP/1.1
**** v1    vsl|       1002 BereqHeader     b Host: foo
**** v1    vsl|       1002 BereqHeader     b Accept-Encoding: gzip
**** v1    vsl|       1002 BereqHeader     b User-Agent: c1
**** v1    vsl|       1002 BereqHeader     b X-Forwarded-For: fc00:a462:8e9e:946a:5df3:31c6:d23:18dc
**** v1    vsl|       1002 BereqHeader     b Via: 1.1 v1 (Varnish/trunk)
**** v1    vsl|       1002 BereqHeader     b X-Varnish: 1002
**** v1    vsl|       1002 VCL_call        b BACKEND_FETCH
**** v1    vsl|       1002 VCL_return      b fetch
**** v1    vsl|       1002 Timestamp       b Fetch: 1703174937.813447 0.000053 0.000053
**** v1    vsl|       1002 Timestamp       b Connected: 1703174937.813563 0.000169 0.000116
**** v1    vsl|       1002 BackendOpen     b 21 s1 fc00:a462:8e9e:946a:5df3:31c6:d23:18dc 46343 fc00:a462:8e9e:946a:5df3:31c6:d23:18dc 60403 connect
**** v1    vsl|       1002 Timestamp       b Bereq: 1703174937.813599 0.000205 0.000035
**** v1    vsl|       1002 BerespProtocol  b HTTP/1.1
**** v1    vsl|       1002 BerespStatus    b 200
**** v1    vsl|       1002 BerespReason    b OK
**** v1    vsl|       1002 BerespHeader    b Transfer-Encoding: chunked
**** v1    vsl|       1002 BerespHeader    b Date: Thu, 21 Dec 2023 16:08:57 GMT
**** v1    vsl|       1002 BerespHeader    b Server: s1
**** v1    vsl|       1002 Timestamp       b Beresp: 1703174937.814149 0.000755 0.000550
**** v1    vsl|       1002 TTL             b RFC 120 10 0 1703174938 1703174938 1703174937 0 0 cacheable
**** v1    vsl|       1002 VCL_call        b BACKEND_RESPONSE
**** v1    vsl|       1002 VCL_return      b deliver
**** v1    vsl|       1002 Timestamp       b Process: 1703174937.814224 0.000830 0.000075
**** v1    vsl|       1002 Filters         b  esi_gzip
**** v1    vsl|       1002 BerespHeader    b Content-Encoding: gzip
**** v1    vsl|       1002 BerespHeader    b Vary: Accept-Encoding
**** v1    vsl|       1002 Storage         b umem s0
**** v1    vsl|       1002 Fetch_Body      b 2 chunked -
**** v1    vsl|       1002 Gzip            b G F E 3167 200 80 1520 1530
**** v1    vsl|       1002 BackendClose    b 21 s1 recycle
**** v1    vsl|       1002 Timestamp       b BerespBody: 1703174937.825064 0.011670 0.010839
**** v1    vsl|       1002 Length          b 200
**** v1    vsl|       1002 BereqAcct       b 171 0 171 96 3167 3263
**** v1    vsl|       1002 End             b 
**** v1    vsl|       1001 Begin           c req 1000 rxreq
**** v1    vsl|       1001 Timestamp       c Start: 1703174937.813172 0.000000 0.000000
**** v1    vsl|       1001 Timestamp       c Req: 1703174937.813172 0.000000 0.000000
**** v1    vsl|       1001 VCL_use         c vcl1
**** v1    vsl|       1001 ReqStart        c fc00:a462:8e9e:946a:5df3:31c6:d23:18dc 45482 a0
**** v1    vsl|       1001 ReqMethod       c GET
**** v1    vsl|       1001 ReqURL          c /
**** v1    vsl|       1001 ReqProtocol     c HTTP/1.1
**** v1    vsl|       1001 ReqHeader       c Host: foo
**** v1    vsl|       1001 ReqHeader       c Accept-Encoding: gzip
**** v1    vsl|       1001 ReqHeader       c User-Agent: c1
**** v1    vsl|       1001 ReqHeader       c X-Forwarded-For: fc00:a462:8e9e:946a:5df3:31c6:d23:18dc
**** v1    vsl|       1001 ReqHeader       c Via: 1.1 v1 (Varnish/trunk)
**** v1    vsl|       1001 VCL_call        c RECV
**** v1    vsl|       1001 VCL_return      c hash
**** v1    vsl|       1001 VCL_call        c HASH
**** v1    vsl|       1001 VCL_return      c lookup
**** v1    vsl|       1001 VCL_call        c MISS
**** v1    vsl|       1001 VCL_return      c fetch
**** v1    vsl|       1001 Link            c bereq 1002 fetch
**** v1    vsl|       1001 Timestamp       c Fetch: 1703174937.825069 0.011897 0.011897
**** v1    vsl|       1001 RespProtocol    c HTTP/1.1
**** v1    vsl|       1001 RespStatus      c 200
**** v1    vsl|       1001 RespReason      c OK
**** v1    vsl|       1001 RespHeader      c Date: Thu, 21 Dec 2023 16:08:57 GMT
**** v1    vsl|       1001 RespHeader      c Server: s1
**** v1    vsl|       1001 RespHeader      c Content-Encoding: gzip
**** v1    vsl|       1001 RespHeader      c Vary: Accept-Encoding
**** v1    vsl|       1001 RespHeader      c X-Varnish: 1001
**** v1    vsl|       1001 RespHeader      c Age: 0
**** v1    vsl|       1001 RespHeader      c Via: 1.1 v1 (Varnish/trunk)
**** v1    vsl|       1001 RespHeader      c Accept-Ranges: bytes
**** v1    vsl|       1001 VCL_call        c DELIVER
**** v1    vsl|       1001 VCL_Error       c Regexp matching failed: matching depth limit exceeded
**** v1    vsl|       1001 RespHeader      c torture: false
**** v1    vsl|       1001 VCL_return      c fail
**** v1    vsl|       1001 Timestamp       c Process: 1703174937.825227 0.012055 0.000157
**** v1    vsl|       1001 RespProtocol    c HTTP/1.1
**** v1    vsl|       1001 RespStatus      c 503
**** v1    vsl|       1001 RespReason      c VCL failed
**** v1    vsl|       1001 RespHeader      c Date: Thu, 21 Dec 2023 16:08:57 GMT
**** v1    vsl|       1001 RespHeader      c Server: Varnish
**** v1    vsl|       1001 RespHeader      c X-Varnish: 1001
**** v1    vsl|       1001 VCL_call        c SYNTH
**** v1    vsl|       1001 RespHeader      c Content-Type: text/html; charset=utf-8
**** v1    vsl|       1001 RespHeader      c Retry-After: 5
**** v1    vsl|       1001 VCL_return      c deliver
**** v1    vsl|       1001 Timestamp       c Process: 1703174937.825273 0.012101 0.000046
**** v1    vsl|       1001 RespHeader      c Content-Length: 251
**** v1    vsl|       1001 Storage         c umem Transient
**** v1    vsl|       1001 Filters         c 
**** v1    vsl|       1001 RespHeader      c Connection: close
**** v1    vsl|       1001 Timestamp       c Resp: 1703174937.825380 0.012207 0.000106
**** v1    vsl|       1001 ReqAcct         c 68 0 68 194 251 445
**** v1    vsl|       1001 End             c 
**** v1    vsl|       1000 SessClose       c VCL_FAILURE 0.013
**** v1    vsl|       1000 End             c 
**** v1    vsl|          0 CLI             - EOF on CLI connection, worker stops
**** dT    0.888
***  v1    debug|Info: Child (107644) said Child dies
***  v1    debug|Info: Child (107644) ended
***  v1    debug|Debug: Child cleanup complete
***  v1    debug|
***  v1    debug|Info: 
***  v1    debug|manager dies
**** dT    0.889
**** v1    STDOUT EOF
**** dT    0.957
**   v1    WAIT4 pid=107102 status=0x0000 (user 0.416000 sys 0.107000)
**** dT    0.958
*    top   TEST ../../../bin/varnishtest/tests/e00029.vtc FAILED
#    top  TEST ../../../bin/varnishtest/tests/e00029.vtc FAILED (0.960) exit=2

Varnish Cache version

No response

Operating system

No response

Source of binary packages used (if any)

No response

nigoroll added a commit that referenced this issue Dec 21, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

1 participant