Created
November 9, 2021 10:22
-
-
Save nigoroll/cbb00e1ee679129338a04f05b86b143b to your computer and use it in GitHub Desktop.
#3732 on SunOS gcc 64bit
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
**** dT 0.000 | |
* top TEST ./tests/r02722.vtc starting | |
**** top extmacro def pwd=/tmp/dridi/varnish-cache/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]:61567 | |
**** 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/dridi/varnish-cache | |
**** top macro def testdir=/tmp/dridi/varnish-cache/bin/varnishtest/./tests | |
**** top macro def tmpdir=/tmp/vtc.820503.21b0a80b | |
** top === varnishtest "TCP vs UDS sockopt inheritance" | |
* top VTEST TCP vs UDS sockopt inheritance | |
** top === server s0 { | |
**** s0 macro def s0_addr=fc00:a462:8e9e:946a:5df3:31c6:d23:18dc | |
**** s0 macro def s0_port=46604 | |
**** s0 macro def s0_sock=[fc00:a462:8e9e:946a:5df3:31c6:d23:18dc]:46604 | |
** s0 Starting dispatch server | |
**** dT 0.001 | |
** top === varnish v1 -arg {-a :0 -a "${tmpdir}/v1.sock"} | |
** s0 Dispatch started on [fc00:a462:8e9e:946a:5df3:31c6:d23:18dc]:46604 | |
**** dT 0.011 | |
** top === varnish v1 -cliok "param.set debug +flush_head" | |
** v1 Launch | |
*** v1 CMD: cd ${pwd} && exec varnishd -d -n /tmp/vtc.820503.21b0a80b/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 -p h2_initial_window_size=1m -p h2_rx_window_low_water=64k -M 'fc00:a462:8e9e:946a:5df3:31c6:d23:18dc 53274' -P /tmp/vtc.820503.21b0a80b/v1/varnishd.pid -p vmod_path=/tmp/dridi/varnish-cache/vmod/.libs -a :0 -a "/tmp/vtc.820503.21b0a80b/v1.sock" | |
*** v1 CMD: cd /tmp/dridi/varnish-cache/bin/varnishtest && exec varnishd -d -n /tmp/vtc.820503.21b0a80b/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 -p h2_initial_window_size=1m -p h2_rx_window_low_water=64k -M 'fc00:a462:8e9e:946a:5df3:31c6:d23:18dc 53274' -P /tmp/vtc.820503.21b0a80b/v1/varnishd.pid -p vmod_path=/tmp/dridi/varnish-cache/vmod/.libs -a :0 -a "/tmp/vtc.820503.21b0a80b/v1.sock" | |
*** v1 PID: 820552 | |
**** v1 macro def v1_pid=820552 | |
**** v1 macro def v1_name=/tmp/vtc.820503.21b0a80b/v1 | |
**** dT 0.043 | |
*** v1 debug|Debug: Version: varnish-trunk revision 2e03d0b6652dd56dae7f7687f774525f2213a906 | |
*** 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 2e03d0b6652dd56dae7f7687f774525f2213a906 | |
*** 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.141 | |
**** v1 CLIPOLL 1 0x1 0x0 0x0 | |
*** v1 CLI connection fd = 6 | |
*** v1 CLI RX 107 | |
**** v1 CLI RX|holphvdfdjsgcfyremvgtdbnlxboahnq | |
**** v1 CLI RX| | |
**** v1 CLI RX|Authentication required. | |
**** dT 0.142 | |
**** v1 CLI TX|auth 2634376bd02dfc17694f72459a7da274a63e5612d0d69a05f96cb5c2bcc020f7 | |
*** 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 2e03d0b6652dd56dae7f7687f774525f2213a906 | |
**** 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|param.set debug +flush_head | |
*** v1 CLI RX 200 | |
** v1 CLI 200 <param.set debug +flush_head> | |
** top === varnish v1 -cliok "param.set timeout_idle 1" | |
**** v1 CLI TX|param.set timeout_idle 1 | |
*** v1 CLI RX 200 | |
** v1 CLI 200 <param.set timeout_idle 1> | |
** top === varnish v1 -vcl+backend { } -start | |
**** v1 CLI TX|vcl.inline vcl1 << %XJEIFLH|)Xspa8P | |
**** v1 CLI TX|vcl 4.1; | |
**** v1 CLI TX|backend s0 { .host = "fc00:a462:8e9e:946a:5df3:31c6:d23:18dc"; .port = "46604"; } | |
**** v1 CLI TX| | |
**** v1 CLI TX| | |
**** v1 CLI TX|%XJEIFLH|)Xspa8P | |
**** dT 0.242 | |
*** v1 vsl|No VSL chunk found (child not started ?) | |
**** dT 0.342 | |
*** v1 vsl|No VSL chunk found (child not started ?) | |
**** dT 0.442 | |
*** v1 vsl|No VSL chunk found (child not started ?) | |
**** dT 0.479 | |
*** 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 Start | |
**** v1 CLI TX|start | |
**** dT 0.488 | |
*** v1 debug|Debug: Child (820836) Started | |
**** dT 0.518 | |
*** v1 CLI RX 200 | |
*** v1 wait-running | |
**** v1 CLI TX|status | |
*** v1 debug|Info: Child (820836) said Security: Privilege proc_setid missing, will not change uid/gid | |
*** v1 debug|Info: Child (820836) said Child starts | |
*** 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 :: 59684 | |
**** v1 CLI RX|a0 0.0.0.0 38643 | |
**** v1 CLI RX|a1 /tmp/vtc.820503.21b0a80b/v1.sock - | |
**** v1 CLI TX|debug.xid 999 | |
*** v1 CLI RX 200 | |
**** v1 CLI RX|XID is 999 | |
**** v1 CLI TX|debug.listen_address | |
*** v1 CLI RX 200 | |
**** v1 CLI RX|a0 :: 59684 | |
**** v1 CLI RX|a0 0.0.0.0 38643 | |
**** v1 CLI RX|a1 /tmp/vtc.820503.21b0a80b/v1.sock - | |
** v1 Listen on :: 59684 | |
**** v1 macro def v1_addr=:: | |
**** v1 macro def v1_port=59684 | |
**** v1 macro def v1_sock=[::]:59684 | |
**** v1 macro def v1_a0_addr=:: | |
**** v1 macro def v1_a0_port=59684 | |
**** v1 macro def v1_a0_sock=[::]:59684 | |
**** v1 macro def v1_a1_addr=0.0.0.0 | |
**** v1 macro def v1_a1_port=0 | |
**** v1 macro def v1_a1_sock=/tmp/vtc.820503.21b0a80b/v1.sock | |
**** dT 0.542 | |
**** v1 vsl| 0 CLI - Rd vcl.load "vcl1" vcl_vcl1.1636453124.999599/vgc.so 1auto | |
**** dT 0.543 | |
**** v1 vsl| 0 CLI - Wr 200 52 Loaded "vcl_vcl1.1636453124.999599/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 CLI - Wr 200 0 | |
**** v1 vsl| 0 CLI - Rd debug.listen_address | |
**** v1 vsl| 0 CLI - Wr 200 67 a0 :: 59684 | |
a0 0.0.0.0 38643 | |
a1 /tmp/vtc.820503.21b0a80b/v1.sock - | |
**** v1 vsl| 0 CLI - Rd debug.xid 999 | |
**** v1 vsl| 0 CLI - Wr 200 10 XID is 999 | |
**** v1 vsl| 0 CLI - Rd debug.listen_address | |
**** v1 vsl| 0 CLI - Wr 200 67 a0 :: 59684 | |
a0 0.0.0.0 38643 | |
a1 /tmp/vtc.820503.21b0a80b/v1.sock - | |
**** dT 0.618 | |
** top === client c1 { | |
** top === client c1 -run | |
** c1 Starting client | |
** c1 Waiting for client | |
** c1 Started on [::]:59684 (1 iterations) | |
*** c1 Connect to [::]:59684 | |
**** dT 0.619 | |
*** c1 connected fd 16 from ::1 52324 to [::]:59684 | |
** c1 === txreq -req POST -hdr "Content-Length: 100" | |
**** c1 txreq|POST / HTTP/1.1\r | |
**** c1 txreq|Content-Length: 100\r | |
**** c1 txreq|Host: fc00:a462:8e9e:946a:5df3:31c6:d23:18dc\r | |
**** c1 txreq|\r | |
** c1 === send some | |
**** c1 send|some | |
** c1 === rxresp | |
*** s0 dispatch fd 4 -> s1 | |
*** s1 start with fd 4 | |
** s1 === rxreqhdrs | |
**** dT 0.643 | |
**** v1 vsl| 1000 Begin c sess 0 HTTP/1 | |
**** v1 vsl| 1000 SessOpen c ::1 52324 a0 ::1 59684 1636453125.475889 22 | |
**** v1 vsl| 1000 Link c req 1001 rxreq | |
**** dT 1.620 | |
**** s1 rxhdr|POST / HTTP/1.1\r | |
**** s1 rxhdr|Content-Length: 100\r | |
**** s1 rxhdr|Host: fc00:a462:8e9e:946a:5df3:31c6:d23:18dc\r | |
**** s1 rxhdr|X-Forwarded-For: ::1\r | |
**** s1 rxhdr|X-Varnish: 1002\r | |
**** s1 rxhdr|\r | |
**** s1 rxhdrlen = 125 | |
**** s1 http[ 0] |POST | |
**** s1 http[ 1] |/ | |
**** s1 http[ 2] |HTTP/1.1 | |
**** s1 http[ 3] |Content-Length: 100 | |
**** s1 http[ 4] |Host: fc00:a462:8e9e:946a:5df3:31c6:d23:18dc | |
**** s1 http[ 5] |X-Forwarded-For: ::1 | |
**** s1 http[ 6] |X-Varnish: 1002 | |
** s1 === non_fatal | |
** s1 === rxreqbody | |
**** s1 bodylen = <undef> | |
** s1 === txresp | |
**** s1 txresp|HTTP/1.1 200 OK\r | |
**** s1 txresp|Content-Length: 0\r | |
**** s1 txresp|\r | |
*** s1 shutting fd 4 | |
** s1 Ending | |
**** c1 rxhdr|HTTP/1.1 503 Backend fetch failed\r | |
**** c1 rxhdr|Date: Tue, 09 Nov 2021 10:18:46 GMT\r | |
**** c1 rxhdr|Server: Varnish\r | |
**** c1 rxhdr|Content-Type: text/html; charset=utf-8\r | |
**** c1 rxhdr|Retry-After: 5\r | |
**** c1 rxhdr|X-Varnish: 1001\r | |
**** c1 rxhdr|Age: 0\r | |
**** c1 rxhdr|Via: 1.1 varnish (Varnish/7.0)\r | |
**** c1 rxhdr|Content-Length: 281\r | |
**** c1 rxhdr|Connection: close\r | |
**** c1 rxhdr|\r | |
**** c1 rxhdrlen = 244 | |
**** c1 http[ 0] |HTTP/1.1 | |
**** c1 http[ 1] |503 | |
**** c1 http[ 2] |Backend fetch failed | |
**** c1 http[ 3] |Date: Tue, 09 Nov 2021 10:18:46 GMT | |
**** c1 http[ 4] |Server: Varnish | |
**** c1 http[ 5] |Content-Type: text/html; charset=utf-8 | |
**** c1 http[ 6] |Retry-After: 5 | |
**** c1 http[ 7] |X-Varnish: 1001 | |
**** c1 http[ 8] |Age: 0 | |
**** c1 http[ 9] |Via: 1.1 varnish (Varnish/7.0) | |
**** c1 http[10] |Content-Length: 281 | |
**** c1 http[11] |Connection: close | |
**** c1 c-l|<!DOCTYPE html> | |
**** c1 c-l|<html> | |
**** c1 c-l| <head> | |
**** c1 c-l| <title>503 Backend fetch failed</title> | |
**** c1 c-l| </head> | |
**** c1 c-l| <body> | |
**** c1 c-l| <h1>Error 503 Backend fetch failed</h1> | |
**** c1 c-l| <p>Backend fetch failed</p> | |
**** c1 c-l| <h3>Guru Meditation:</h3> | |
**** c1 c-l| <p>XID: 1002</p> | |
**** c1 c-l| <hr> | |
**** c1 c-l| <p>Varnish cache server</p> | |
**** c1 c-l| </body> | |
**** c1 c-l|</html> | |
**** c1 bodylen = 281 | |
** c1 === expect resp.status == 503 | |
**** c1 EXPECT resp.status (503) == "503" match | |
*** c1 closing fd 16 | |
** c1 Ending | |
** top === client c1 -run | |
** c1 Starting client | |
** c1 Waiting for client | |
** c1 Started on [::]:59684 (1 iterations) | |
*** c1 Connect to [::]:59684 | |
*** c1 connected fd 4 from ::1 39279 to [::]:59684 | |
** c1 === txreq -req POST -hdr "Content-Length: 100" | |
**** c1 txreq|POST / HTTP/1.1\r | |
**** c1 txreq|Content-Length: 100\r | |
**** c1 txreq|Host: fc00:a462:8e9e:946a:5df3:31c6:d23:18dc\r | |
**** c1 txreq|\r | |
** c1 === send some | |
**** c1 send|some | |
** c1 === rxresp | |
**** dT 1.621 | |
*** s0 dispatch fd 17 -> s2 | |
*** s2 start with fd 17 | |
** s2 === rxreqhdrs | |
**** dT 1.643 | |
**** v1 vsl| 1002 Begin b bereq 1001 pass | |
**** v1 vsl| 1002 VCL_use b vcl1 | |
**** v1 vsl| 1002 Timestamp b Start: 1636453125.476393 0.000000 0.000000 | |
**** v1 vsl| 1002 BereqMethod b POST | |
**** v1 vsl| 1002 BereqURL b / | |
**** v1 vsl| 1002 BereqProtocol b HTTP/1.1 | |
**** v1 vsl| 1002 BereqHeader b Content-Length: 100 | |
**** v1 vsl| 1002 BereqHeader b Host: fc00:a462:8e9e:946a:5df3:31c6:d23:18dc | |
**** v1 vsl| 1002 BereqHeader b X-Forwarded-For: ::1 | |
**** 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: 1636453125.476430 0.000037 0.000037 | |
**** v1 vsl| 1002 Timestamp b Connected: 1636453125.476534 0.000141 0.000104 | |
**** v1 vsl| 1002 BackendOpen b 27 s0 fc00:a462:8e9e:946a:5df3:31c6:d23:18dc 46604 fc00:a462:8e9e:946a:5df3:31c6:d23:18dc 39255 connect | |
**** v1 vsl| 1002 FetchError b req.body read error: 11 (Resource temporarily unavailable) | |
**** v1 vsl| 1002 FetchError b backend write error: 11 (Resource temporarily unavailable) | |
**** v1 vsl| 1002 Timestamp b Bereq: 1636453126.476719 1.000326 1.000184 | |
**** v1 vsl| 1002 BackendClose b 27 s0 close | |
**** v1 vsl| 1002 Timestamp b Beresp: 1636453126.476745 1.000352 0.000025 | |
**** v1 vsl| 1002 Timestamp b Error: 1636453126.476752 1.000359 0.000006 | |
**** v1 vsl| 1002 BerespProtocol b HTTP/1.1 | |
**** v1 vsl| 1002 BerespStatus b 503 | |
**** v1 vsl| 1002 BerespReason b Backend fetch failed | |
**** v1 vsl| 1002 BerespHeader b Date: Tue, 09 Nov 2021 10:18:46 GMT | |
**** v1 vsl| 1002 BerespHeader b Server: Varnish | |
**** v1 vsl| 1002 VCL_call b BACKEND_ERROR | |
**** v1 vsl| 1002 BerespHeader b Content-Type: text/html; charset=utf-8 | |
**** v1 vsl| 1002 BerespHeader b Retry-After: 5 | |
**** v1 vsl| 1002 VCL_return b deliver | |
**** v1 vsl| 1002 Storage b umem Transient | |
**** v1 vsl| 1002 Length b 281 | |
**** v1 vsl| 1002 BereqAcct b 125 0 125 0 0 0 | |
**** v1 vsl| 1002 End b | |
**** v1 vsl| 1001 Begin c req 1000 rxreq | |
**** v1 vsl| 1001 Timestamp c Start: 1636453125.476124 0.000000 0.000000 | |
**** v1 vsl| 1001 Timestamp c Req: 1636453125.476124 0.000000 0.000000 | |
**** v1 vsl| 1001 VCL_use c vcl1 | |
**** v1 vsl| 1001 ReqStart c ::1 52324 a0 | |
**** v1 vsl| 1001 ReqMethod c POST | |
**** v1 vsl| 1001 ReqURL c / | |
**** v1 vsl| 1001 ReqProtocol c HTTP/1.1 | |
**** v1 vsl| 1001 ReqHeader c Content-Length: 100 | |
**** v1 vsl| 1001 ReqHeader c Host: fc00:a462:8e9e:946a:5df3:31c6:d23:18dc | |
**** v1 vsl| 1001 ReqHeader c X-Forwarded-For: ::1 | |
**** v1 vsl| 1001 VCL_call c RECV | |
**** v1 vsl| 1001 VCL_return c pass | |
**** v1 vsl| 1001 VCL_call c HASH | |
**** v1 vsl| 1001 VCL_return c lookup | |
**** v1 vsl| 1001 VCL_call c PASS | |
**** v1 vsl| 1001 VCL_return c fetch | |
**** v1 vsl| 1001 Link c bereq 1002 pass | |
**** v1 vsl| 1001 Storage c umem Transient | |
**** v1 vsl| 1001 FetchError c Resource temporarily unavailable | |
**** v1 vsl| 1001 FetchError c straight insufficient bytes | |
**** v1 vsl| 1001 Timestamp c ReqBody: 1636453126.476651 1.000527 1.000527 | |
**** v1 vsl| 1001 Timestamp c Fetch: 1636453126.476845 1.000720 0.000193 | |
**** v1 vsl| 1001 RespProtocol c HTTP/1.1 | |
**** v1 vsl| 1001 RespStatus c 503 | |
**** v1 vsl| 1001 RespReason c Backend fetch failed | |
**** v1 vsl| 1001 RespHeader c Date: Tue, 09 Nov 2021 10:18:46 GMT | |
**** v1 vsl| 1001 RespHeader c Server: Varnish | |
**** v1 vsl| 1001 RespHeader c Content-Type: text/html; charset=utf-8 | |
**** v1 vsl| 1001 RespHeader c Retry-After: 5 | |
**** v1 vsl| 1001 RespHeader c X-Varnish: 1001 | |
**** v1 vsl| 1001 RespHeader c Age: 0 | |
**** v1 vsl| 1001 RespHeader c Via: 1.1 varnish (Varnish/7.0) | |
**** v1 vsl| 1001 VCL_call c DELIVER | |
**** v1 vsl| 1001 VCL_return c deliver | |
**** v1 vsl| 1001 Timestamp c Process: 1636453126.476881 1.000757 0.000036 | |
**** v1 vsl| 1001 Filters c | |
**** v1 vsl| 1001 RespHeader c Content-Length: 281 | |
**** v1 vsl| 1001 RespHeader c Connection: close | |
**** v1 vsl| 1001 Timestamp c Resp: 1636453126.476935 1.000811 0.000053 | |
**** v1 vsl| 1001 ReqAcct c 86 0 86 244 281 525 | |
**** v1 vsl| 1001 End c | |
**** v1 vsl| 1000 SessClose c RX_BODY 1.001 | |
**** v1 vsl| 1000 End c | |
**** v1 vsl| 1003 Begin c sess 0 HTTP/1 | |
**** v1 vsl| 1003 SessOpen c ::1 39279 a0 ::1 59684 1636453126.477656 24 | |
**** v1 vsl| 1003 Link c req 1004 rxreq | |
**** dT 2.621 | |
**** s2 rxhdr|POST / HTTP/1.1\r | |
**** s2 rxhdr|Content-Length: 100\r | |
**** s2 rxhdr|Host: fc00:a462:8e9e:946a:5df3:31c6:d23:18dc\r | |
**** s2 rxhdr|X-Forwarded-For: ::1\r | |
**** s2 rxhdr|X-Varnish: 1005\r | |
**** s2 rxhdr|\r | |
**** s2 rxhdrlen = 125 | |
**** s2 http[ 0] |POST | |
**** s2 http[ 1] |/ | |
**** s2 http[ 2] |HTTP/1.1 | |
**** s2 http[ 3] |Content-Length: 100 | |
**** s2 http[ 4] |Host: fc00:a462:8e9e:946a:5df3:31c6:d23:18dc | |
**** s2 http[ 5] |X-Forwarded-For: ::1 | |
**** s2 http[ 6] |X-Varnish: 1005 | |
** s2 === non_fatal | |
** s2 === rxreqbody | |
**** s2 bodylen = <undef> | |
** s2 === txresp | |
**** s2 txresp|HTTP/1.1 200 OK\r | |
**** s2 txresp|Content-Length: 0\r | |
**** s2 txresp|\r | |
*** s2 shutting fd 17 | |
** s2 Ending | |
**** c1 rxhdr|HTTP/1.1 503 Backend fetch failed\r | |
**** c1 rxhdr|Date: Tue, 09 Nov 2021 10:18:47 GMT\r | |
**** c1 rxhdr|Server: Varnish\r | |
**** c1 rxhdr|Content-Type: text/html; charset=utf-8\r | |
**** c1 rxhdr|Retry-After: 5\r | |
**** c1 rxhdr|X-Varnish: 1004\r | |
**** c1 rxhdr|Age: 0\r | |
**** c1 rxhdr|Via: 1.1 varnish (Varnish/7.0)\r | |
**** c1 rxhdr|Content-Length: 281\r | |
**** c1 rxhdr|Connection: close\r | |
**** c1 rxhdr|\r | |
**** c1 rxhdrlen = 244 | |
**** c1 http[ 0] |HTTP/1.1 | |
**** c1 http[ 1] |503 | |
**** c1 http[ 2] |Backend fetch failed | |
**** c1 http[ 3] |Date: Tue, 09 Nov 2021 10:18:47 GMT | |
**** c1 http[ 4] |Server: Varnish | |
**** c1 http[ 5] |Content-Type: text/html; charset=utf-8 | |
**** c1 http[ 6] |Retry-After: 5 | |
**** c1 http[ 7] |X-Varnish: 1004 | |
**** c1 http[ 8] |Age: 0 | |
**** c1 http[ 9] |Via: 1.1 varnish (Varnish/7.0) | |
**** c1 http[10] |Content-Length: 281 | |
**** c1 http[11] |Connection: close | |
**** c1 c-l|<!DOCTYPE html> | |
**** c1 c-l|<html> | |
**** c1 c-l| <head> | |
**** c1 c-l| <title>503 Backend fetch failed</title> | |
**** c1 c-l| </head> | |
**** c1 c-l| <body> | |
**** c1 c-l| <h1>Error 503 Backend fetch failed</h1> | |
**** c1 c-l| <p>Backend fetch failed</p> | |
**** c1 c-l| <h3>Guru Meditation:</h3> | |
**** c1 c-l| <p>XID: 1005</p> | |
**** c1 c-l| <hr> | |
**** c1 c-l| <p>Varnish cache server</p> | |
**** c1 c-l| </body> | |
**** c1 c-l|</html> | |
**** c1 bodylen = 281 | |
** c1 === expect resp.status == 503 | |
**** c1 EXPECT resp.status (503) == "503" match | |
*** c1 closing fd 4 | |
** c1 Ending | |
** top === varnish v1 -vsl_catchup | |
**** dT 2.644 | |
**** v1 vsl| 1005 Begin b bereq 1004 pass | |
**** v1 vsl| 1005 VCL_use b vcl1 | |
**** v1 vsl| 1005 Timestamp b Start: 1636453126.477774 0.000000 0.000000 | |
**** v1 vsl| 1005 BereqMethod b POST | |
**** v1 vsl| 1005 BereqURL b / | |
**** v1 vsl| 1005 BereqProtocol b HTTP/1.1 | |
**** v1 vsl| 1005 BereqHeader b Content-Length: 100 | |
**** v1 vsl| 1005 BereqHeader b Host: fc00:a462:8e9e:946a:5df3:31c6:d23:18dc | |
**** v1 vsl| 1005 BereqHeader b X-Forwarded-For: ::1 | |
**** v1 vsl| 1005 BereqHeader b X-Varnish: 1005 | |
**** v1 vsl| 1005 VCL_call b BACKEND_FETCH | |
**** v1 vsl| 1005 VCL_return b fetch | |
**** v1 vsl| 1005 Timestamp b Fetch: 1636453126.477799 0.000025 0.000025 | |
**** v1 vsl| 1005 Timestamp b Connected: 1636453126.477855 0.000080 0.000055 | |
**** v1 vsl| 1005 BackendOpen b 27 s0 fc00:a462:8e9e:946a:5df3:31c6:d23:18dc 46604 fc00:a462:8e9e:946a:5df3:31c6:d23:18dc 40478 connect | |
**** v1 vsl| 1005 FetchError b req.body read error: 11 (Resource temporarily unavailable) | |
**** v1 vsl| 1005 FetchError b backend write error: 11 (Resource temporarily unavailable) | |
**** v1 vsl| 1005 Timestamp b Bereq: 1636453127.477654 0.999879 0.999799 | |
**** v1 vsl| 1005 BackendClose b 27 s0 close | |
**** v1 vsl| 1005 Timestamp b Beresp: 1636453127.477687 0.999913 0.000033 | |
**** v1 vsl| 1005 Timestamp b Error: 1636453127.477690 0.999915 0.000002 | |
**** v1 vsl| 1005 BerespProtocol b HTTP/1.1 | |
**** v1 vsl| 1005 BerespStatus b 503 | |
**** v1 vsl| 1005 BerespReason b Backend fetch failed | |
**** v1 vsl| 1005 BerespHeader b Date: Tue, 09 Nov 2021 10:18:47 GMT | |
**** v1 vsl| 1005 BerespHeader b Server: Varnish | |
**** v1 vsl| 1005 VCL_call b BACKEND_ERROR | |
**** v1 vsl| 1005 BerespHeader b Content-Type: text/html; charset=utf-8 | |
**** v1 vsl| 1005 BerespHeader b Retry-After: 5 | |
**** v1 vsl| 1005 VCL_return b deliver | |
**** v1 vsl| 1005 Storage b umem Transient | |
**** v1 vsl| 1005 Length b 281 | |
**** v1 vsl| 1005 BereqAcct b 125 0 125 0 0 0 | |
**** v1 vsl| 1005 End b | |
**** v1 vsl| 1004 Begin c req 1003 rxreq | |
**** v1 vsl| 1004 Timestamp c Start: 1636453126.477706 0.000000 0.000000 | |
**** v1 vsl| 1004 Timestamp c Req: 1636453126.477706 0.000000 0.000000 | |
**** v1 vsl| 1004 VCL_use c vcl1 | |
**** v1 vsl| 1004 ReqStart c ::1 39279 a0 | |
**** v1 vsl| 1004 ReqMethod c POST | |
**** v1 vsl| 1004 ReqURL c / | |
**** v1 vsl| 1004 ReqProtocol c HTTP/1.1 | |
**** v1 vsl| 1004 ReqHeader c Content-Length: 100 | |
**** v1 vsl| 1004 ReqHeader c Host: fc00:a462:8e9e:946a:5df3:31c6:d23:18dc | |
**** v1 vsl| 1004 ReqHeader c X-Forwarded-For: ::1 | |
**** v1 vsl| 1004 VCL_call c RECV | |
**** v1 vsl| 1004 VCL_return c pass | |
**** v1 vsl| 1004 VCL_call c HASH | |
**** v1 vsl| 1004 VCL_return c lookup | |
**** v1 vsl| 1004 VCL_call c PASS | |
**** v1 vsl| 1004 VCL_return c fetch | |
**** v1 vsl| 1004 Link c bereq 1005 pass | |
**** v1 vsl| 1004 Storage c umem Transient | |
**** v1 vsl| 1004 FetchError c Resource temporarily unavailable | |
**** v1 vsl| 1004 FetchError c straight insufficient bytes | |
**** v1 vsl| 1004 Timestamp c ReqBody: 1636453127.477616 0.999910 0.999910 | |
**** v1 vsl| 1004 Timestamp c Fetch: 1636453127.477748 1.000041 0.000131 | |
**** v1 vsl| 1004 RespProtocol c HTTP/1.1 | |
**** v1 vsl| 1004 RespStatus c 503 | |
**** v1 vsl| 1004 RespReason c Backend fetch failed | |
**** v1 vsl| 1004 RespHeader c Date: Tue, 09 Nov 2021 10:18:47 GMT | |
**** v1 vsl| 1004 RespHeader c Server: Varnish | |
**** v1 vsl| 1004 RespHeader c Content-Type: text/html; charset=utf-8 | |
**** v1 vsl| 1004 RespHeader c Retry-After: 5 | |
**** v1 vsl| 1004 RespHeader c X-Varnish: 1004 | |
**** v1 vsl| 1004 RespHeader c Age: 0 | |
**** v1 vsl| 1004 RespHeader c Via: 1.1 varnish (Varnish/7.0) | |
**** v1 vsl| 1004 VCL_call c DELIVER | |
**** v1 vsl| 1004 VCL_return c deliver | |
**** v1 vsl| 1004 Timestamp c Process: 1636453127.477771 1.000064 0.000022 | |
**** v1 vsl| 1004 Filters c | |
**** v1 vsl| 1004 RespHeader c Content-Length: 281 | |
**** v1 vsl| 1004 RespHeader c Connection: close | |
**** v1 vsl| 1004 Timestamp c Resp: 1636453127.477806 1.000100 0.000035 | |
**** v1 vsl| 1004 ReqAcct c 86 0 86 244 281 525 | |
**** v1 vsl| 1004 End c | |
**** v1 vsl| 1003 SessClose c RX_BODY 1.000 | |
**** v1 vsl| 1003 End c | |
**** dT 2.721 | |
** top === client c1 -connect "${tmpdir}/v1.sock" | |
** top === client c1 -run | |
** c1 Starting client | |
** c1 Waiting for client | |
** c1 Started on /tmp/vtc.820503.21b0a80b/v1.sock (1 iterations) | |
*** c1 Connect to /tmp/vtc.820503.21b0a80b/v1.sock | |
*** c1 connected fd 4 to /tmp/vtc.820503.21b0a80b/v1.sock | |
** c1 === txreq -req POST -hdr "Content-Length: 100" | |
**** c1 txreq|POST / HTTP/1.1\r | |
**** c1 txreq|Content-Length: 100\r | |
**** c1 txreq|Host: fc00:a462:8e9e:946a:5df3:31c6:d23:18dc\r | |
**** c1 txreq|\r | |
** c1 === send some | |
**** c1 send|some | |
** c1 === rxresp | |
**** dT 2.722 | |
*** s0 dispatch fd 16 -> s3 | |
*** s3 start with fd 16 | |
** s3 === rxreqhdrs | |
**** dT 2.744 | |
**** v1 vsl| 1006 Begin c sess 0 HTTP/1 | |
**** v1 vsl| 1006 SessOpen c 0.0.0.0 0 a1 0.0.0.0 0 1636453127.578616 19 | |
**** v1 vsl| 1006 Link c req 1007 rxreq | |
**** dT 3.544 | |
**** v1 vsl| 0 CLI - Rd ping | |
**** v1 vsl| 0 CLI - Wr 200 19 PONG 1636453128 1.0 | |
**** dT 6.545 | |
**** v1 vsl| 0 CLI - Rd ping | |
**** v1 vsl| 0 CLI - Wr 200 19 PONG 1636453131 1.0 | |
**** dT 9.547 | |
**** v1 vsl| 0 CLI - Rd ping | |
**** v1 vsl| 0 CLI - Wr 200 19 PONG 1636453134 1.0 | |
**** dT 12.548 | |
**** v1 vsl| 0 CLI - Rd ping | |
**** v1 vsl| 0 CLI - Wr 200 19 PONG 1636453137 1.0 | |
**** dT 15.549 | |
**** v1 vsl| 0 CLI - Rd ping | |
**** v1 vsl| 0 CLI - Wr 200 19 PONG 1636453140 1.0 | |
**** dT 18.550 | |
**** v1 vsl| 0 CLI - Rd ping | |
**** v1 vsl| 0 CLI - Wr 200 19 PONG 1636453143 1.0 | |
**** dT 21.551 | |
**** v1 vsl| 0 CLI - Rd ping | |
**** v1 vsl| 0 CLI - Wr 200 19 PONG 1636453146 1.0 | |
**** dT 24.551 | |
**** v1 vsl| 0 CLI - Rd ping | |
**** v1 vsl| 0 CLI - Wr 200 19 PONG 1636453149 1.0 | |
**** dT 27.552 | |
**** v1 vsl| 0 CLI - Rd ping | |
**** v1 vsl| 0 CLI - Wr 200 19 PONG 1636453152 1.0 | |
**** dT 30.552 | |
**** v1 vsl| 0 CLI - Rd ping | |
**** v1 vsl| 0 CLI - Wr 200 19 PONG 1636453155 1.0 | |
**** dT 32.721 | |
---- c1 HTTP rx timeout (fd:4 30000 ms) | |
* top RESETTING after ./tests/r02722.vtc | |
** s0 Waiting for server (3/-1) | |
** s1 Waiting for server (-1/-1) | |
** s2 Waiting for server (-1/-1) | |
** s3 Waiting for server (-1/16) | |
**** dT 32.722 | |
** v1 Wait | |
**** v1 CLI TX|panic.clear | |
*** v1 CLI RX 300 | |
**** v1 CLI RX|No panic to clear | |
*** v1 debug|Info: manager stopping child | |
*** v1 debug|Debug: | |
*** v1 debug| Stopping Child | |
**** dT 32.753 | |
**** v1 vsl| 0 CLI - EOF on CLI connection, worker stops | |
**** dT 32.822 | |
*** v1 debug|Info: Child (820836) ended | |
*** v1 debug|Info: Child (820836) said Child dies | |
*** v1 debug| | |
*** v1 debug|Debug: Child cleanup complete | |
*** v1 debug| | |
*** v1 debug|Info: manager dies | |
*** v1 debug| | |
**** v1 STDOUT EOF | |
**** dT 32.853 | |
** v1 WAIT4 pid=820552 status=0x0000 (user 0.292000 sys 0.094000) | |
* top TEST ./tests/r02722.vtc FAILED | |
# top TEST ./tests/r02722.vtc FAILED (32.855) exit=2 |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment