Hi Pieter,
On Sat, Dec 15, 2018 at 04:52:10PM +0100, PiBa-NL wrote:
> Hi List, Willy,
>
> Trying to run some existing regtests with added option: option http-use-htx
>
> Using: HA-Proxy version 1.9-dev10-c11ec4a 2018/12/15
>
> I get the below issues sofar:
>
> #### based on /reg-tests/connection/b00000.vtc
> Takes 8 seconds to pass, in a slightly modified manor 1.1 > 2.0 expectation
> for syslog. This surely needs a closer look?
> # top TEST ./htx-test/connection-b00000.vtc passed (8.490)
It looks exactly like another issue we've found when a content-length
is missing but the close is not seen, which is the same in your case
with the first proxy returning the 503 error page by default. Christopher
told me he understands what's happening in this situation (at least for
the one we've met), I'm CCing him in case this report fuels this thoughts.
> #### based on /reg-tests/stick-table/b00001.vtc
> Difference here is the use=1 vs use=0 , maybe that is better, but then the
> 'old' expectation seems wrong, and the bug is the case without htx?
>
> **** h1 0.0 CLI recv|0x8026612c0: key=127.0.0.1 use=1 exp=0 gpt0=0 gpc0=0
> gpc0_rate(10000)=0 conn_rate(10000)=1 http_req_cnt=1 http_req_rate(10000)=1
> http_err_cnt=0 http_err_rate(10000)=0
> **** h1 0.0 CLI recv|
> ---- h1 0.0 CLI expect failed ~ "table: http1, type: ip, size:1024,
> used:(0|1\n0x[0-9a-f]*: key=127\.0\.0\.1 use=0 exp=[0-9]* gpt0=0 gpc0=0
> gpc0_rate\(10000\)=0 conn_rate\(10000\)=1 http_req_cnt=1
> http_req_rate\(10000\)=1 http_err_cnt=0 http_err_rate\(10000\)=0)\n$"
Hmmm here I think we're really hitting corner cases depending on whether
the tracked counters are released before or after the logs are emitted.
In the case of htx, the logs are emitted slightly later than before,
which may induce this. Quite honestly I'd be inclined to set use=[01]
here in the regex to cover the race condition that exists in both cases,
as there isn't any single good value. Christopher, are you also OK with
this ? I can do the patch if you're OK.
> Regards,
>
> PiBa-NL (Pieter)
>
Thanks,
Willy
> #commit b406b87
> # BUG/MEDIUM: connection: don't store recv() result into trash.data
> #
> # Cyril Bonté discovered that the proxy protocol randomly fails since
> # commit 843b7cb ("MEDIUM: chunks: make the chunk struct's fields match
> # the buffer struct"). This is because we used to store recv()'s return
> # code into trash.data which is now unsigned, so it never compares as
> # negative against 0. Let's clean this up and test the result itself
> # without storing it first.
>
> varnishtest "PROXY protocol random failures"
>
> feature ignore_unknown_macro
>
> syslog Slog_1 -repeat 8 -level info {
> recv
> expect ~ "Connect from .* to ${h1_ssl_addr}:${h1_ssl_port}"
> recv
> expect ~ "ssl-offload-http/http .* \"POST /[1-8] HTTP/2\\.0\""
> } -start
>
> haproxy h1 -conf {
> global
> nbproc 4
> nbthread 4
> tune.ssl.default-dh-param 2048
> stats bind-process 1
> log ${Slog_1_addr}:${Slog_1_port} len 2048 local0 debug err
>
> defaults
> mode http
> timeout client 1s
> timeout server 1s
> timeout connect 1s
> log global
>
> option http-use-htx
>
> listen http
> bind-process 1
> bind unix@${tmpdir}/http.socket accept-proxy name ssl-offload-http
> option forwardfor
>
> listen ssl-offload-http
> option httplog
> bind-process 2-4
> bind "fd@${ssl}" ssl crt ${testdir}/common.pem ssl no-sslv3 alpn
> h2,http/1.1
> server http unix@${tmpdir}/http.socket send-proxy
> } -start
>
>
> shell {
> HOST=${h1_ssl_addr}
> if [ "$HOST" = "::1" ] ; then
> HOST="\[::1\]"
> fi
> for i in 1 2 3 4 5 6 7 8 ; do
> urls="$urls https://$HOST:${h1_ssl_port}/$i";
> done
> curl -i -k -d 'x=x' $urls & wait $!
> }
>
> syslog Slog_1 -wait
> # commit 3e60b11
> # BUG/MEDIUM: stick-tables: Decrement ref_cnt in table_* converters
> #
> # When using table_* converters ref_cnt was incremented
> # and never decremented causing entries to not expire.
> #
> # The root cause appears to be that stktable_lookup_key()
> # was called within all sample_conv_table_* functions which was
> # incrementing ref_cnt and not decrementing after completion.
> #
> # Added stktable_release() to the end of each sample_conv_table_*
> # function and reworked the end logic to ensure that ref_cnt is
> # always decremented after use.
> #
> # This should be backported to 1.8
>
> varnishtest "stick-tables: Test expirations when used with table_*"
>
> # As some macros for haproxy are used in this file, this line is mandatory.
> feature ignore_unknown_macro
>
> # Do nothing.
> server s1 {
> } -start
>
> haproxy h1 -conf {
> # Configuration file of 'h1' haproxy instance.
> defaults
> mode http
> timeout connect 5s
> timeout server 30s
> timeout client 30s
> option http-use-htx
>
> frontend http1
> bind "fd@${my_frontend_fd}"
> stick-table size 1k expire 1ms type ip store
> conn_rate(10s),http_req_cnt,http_err_cnt,http_req_rate(10s),http_err_rate(10s),gpc0,gpc0_rate(10s),gpt0
> http-request track-sc0 req.hdr(X-Forwarded-For)
> http-request redirect location https://${s1_addr}:${s1_port}/ if {
> req.hdr(X-Forwarded-For),table_http_req_cnt(http1) -m int lt 0 }
> http-request redirect location https://${s1_addr}:${s1_port}/ if {
> req.hdr(X-Forwarded-For),table_trackers(http1) -m int lt 0 }
> http-request redirect location https://${s1_addr}:${s1_port}/ if {
> req.hdr(X-Forwarded-For),in_table(http1) -m int lt 0 }
> http-request redirect location https://${s1_addr}:${s1_port}/ if {
> req.hdr(X-Forwarded-For),table_bytes_in_rate(http1) -m int lt 0 }
> http-request redirect location https://${s1_addr}:${s1_port}/ if {
> req.hdr(X-Forwarded-For),table_bytes_out_rate(http1) -m int lt 0 }
> http-request redirect location https://${s1_addr}:${s1_port}/ if {
> req.hdr(X-Forwarded-For),table_conn_cnt(http1) -m int lt 0 }
> http-request redirect location https://${s1_addr}:${s1_port}/ if {
> req.hdr(X-Forwarded-For),table_conn_cur(http1) -m int lt 0 }
> http-request redirect location https://${s1_addr}:${s1_port}/ if {
> req.hdr(X-Forwarded-For),table_conn_rate(http1) -m int lt 0 }
> http-request redirect location https://${s1_addr}:${s1_port}/ if {
> req.hdr(X-Forwarded-For),table_gpt0(http1) -m int lt 0 }
> http-request redirect location https://${s1_addr}:${s1_port}/ if {
> req.hdr(X-Forwarded-For),table_gpc0(http1) -m int lt 0 }
> http-request redirect location https://${s1_addr}:${s1_port}/ if {
> req.hdr(X-Forwarded-For),table_gpc0_rate(http1) -m int lt 0 }
> http-request redirect location https://${s1_addr}:${s1_port}/ if {
> req.hdr(X-Forwarded-For),table_http_err_cnt(http1) -m int lt 0 }
> http-request redirect location https://${s1_addr}:${s1_port}/ if {
> req.hdr(X-Forwarded-For),table_http_err_rate(http1) -m int lt 0 }
> http-request redirect location https://${s1_addr}:${s1_port}/ if {
> req.hdr(X-Forwarded-For),table_http_req_cnt(http1) -m int lt 0 }
> http-request redirect location https://${s1_addr}:${s1_port}/ if {
> req.hdr(X-Forwarded-For),table_http_req_rate(http1) -m int lt 0 }
> http-request redirect location https://${s1_addr}:${s1_port}/ if {
> req.hdr(X-Forwarded-For),table_kbytes_in(http1) -m int lt 0 }
> http-request redirect location https://${s1_addr}:${s1_port}/ if {
> req.hdr(X-Forwarded-For),table_kbytes_out(http1) -m int lt 0 }
> http-request redirect location https://${s1_addr}:${s1_port}/ if {
> req.hdr(X-Forwarded-For),table_server_id(http1) -m int lt 0 }
> http-request redirect location https://${s1_addr}:${s1_port}/ if {
> req.hdr(X-Forwarded-For),table_sess_cnt(http1) -m int lt 0 }
> http-request redirect location https://${s1_addr}:${s1_port}/ if {
> req.hdr(X-Forwarded-For),table_sess_rate(http1) -m int lt 0 }
> http-request redirect location https://${s1_addr}:${s1_port}/ if {
> req.hdr(X-Forwarded-For),table_trackers(http1) -m int lt 0 }
> } -start
>
> client c1 -connect ${h1_my_frontend_fd_sock} {
> txreq -url "/" -hdr "X-Forwarded-For: 127.0.0.1"
> rxresp
> expect resp.status == 503
> } -run
>
> haproxy h1 -cli {
> send "show table http1"
> expect ~ "table: http1, type: ip, size:1024, used:(0|1\\n0x[0-9a-f]*:
> key=127\\.0\\.0\\.1 use=0 exp=[0-9]* gpt0=0 gpc0=0 gpc0_rate\\(10000\\)=0
> conn_rate\\(10000\\)=1 http_req_cnt=1 http_req_rate\\(10000\\)=1
> http_err_cnt=0 http_err_rate\\(10000\\)=0)\\n$"
> } -wait
> **** top 0.0 extmacro def pwd=/usr/ports/net/haproxy-devel
> **** top 0.0 extmacro def localhost=127.0.0.1
> **** top 0.0 extmacro def bad_backend=127.0.0.1 41652
> **** top 0.0 extmacro def bad_ip=192.0.2.255
> **** top 0.0 macro def testdir=/usr/ports/net/haproxy-devel/./htx-test
> **** top 0.0 macro def tmpdir=/tmp/vtc.68714.517aebde
> * top 0.0 TEST ./htx-test/connection-b00000.vtc starting
> ** top 0.0 === varnishtest "PROXY protocol random failures"
> * top 0.0 TEST PROXY protocol random failures
> ** top 0.0 === feature ignore_unknown_macro
> ** top 0.0 === syslog Slog_1 -repeat 8 -level info {
> ** Slog_1 0.0 Starting syslog server
> **** Slog_1 0.0 macro def Slog_1_addr=127.0.0.1
> **** Slog_1 0.0 macro def Slog_1_port=31734
> **** Slog_1 0.0 macro def Slog_1_sock=127.0.0.1 31734
> * Slog_1 0.0 Bound on 127.0.0.1 31734
> ** top 0.0 === haproxy h1 -conf {
> ** Slog_1 0.0 Started on 127.0.0.1 31734 (level: 6)
> *** Slog_1 0.0 Iteration 0
> ** Slog_1 0.0 === recv
> **** h1 0.0 macro def h1_cli_sock=::1 41653
> **** h1 0.0 macro def h1_cli_addr=::1
> **** h1 0.0 macro def h1_cli_port=41653
> **** h1 0.0 setenv(cli, 4)
> **** h1 0.0 macro def h1_ssl_sock=::1 41654
> **** h1 0.0 macro def h1_ssl_addr=::1
> **** h1 0.0 macro def h1_ssl_port=41654
> **** h1 0.0 setenv(ssl, 5)
> **** h1 0.0 conf| global
> **** h1 0.0 conf|\tstats socket /tmp/vtc.68714.517aebde/h1/stats.sock
> level admin mode 600
> **** h1 0.0 conf| stats socket "fd@${cli}" level admin
> **** h1 0.0 conf|
> **** h1 0.0 conf| global
> **** h1 0.0 conf| nbproc 4
> **** h1 0.0 conf| nbthread 4
> **** h1 0.0 conf| tune.ssl.default-dh-param 2048
> **** h1 0.0 conf| stats bind-process 1
> **** h1 0.0 conf| log 127.0.0.1:31734 len 2048 local0 debug err
> **** h1 0.0 conf|
> **** h1 0.0 conf| defaults
> **** h1 0.0 conf| mode http
> **** h1 0.0 conf| timeout client 1s
> **** h1 0.0 conf| timeout server 1s
> **** h1 0.0 conf| timeout connect 1s
> **** h1 0.0 conf| log global
> **** h1 0.0 conf|
> **** h1 0.0 conf|option http-use-htx
> **** h1 0.0 conf|
> **** h1 0.0 conf| listen http
> **** h1 0.0 conf| bind-process 1
> **** h1 0.0 conf| bind unix@/tmp/vtc.68714.517aebde/http.socket
> accept-proxy name ssl-offload-http
> **** h1 0.0 conf| option forwardfor
> **** h1 0.0 conf|
> **** h1 0.0 conf| listen ssl-offload-http
> **** h1 0.0 conf| option httplog
> **** h1 0.0 conf| bind-process 2-4
> **** h1 0.0 conf| bind "fd@${ssl}" ssl crt
> /usr/ports/net/haproxy-devel/./htx-test/common.pem ssl no-sslv3 alpn
> h2,http/1.1
> **** h1 0.0 conf| server http
> unix@/tmp/vtc.68714.517aebde/http.socket send-proxy
> ** h1 0.0 haproxy_start
> **** h1 0.0 opt_worker 0 opt_daemon 0 opt_check_mode 0
> **** h1 0.0 argv|exec haproxy -d -f /tmp/vtc.68714.517aebde/h1/cfg
> **** h1 0.0 XXX 7 @586
> *** h1 0.0 PID: 68718
> **** h1 0.0 macro def h1_pid=68718
> **** h1 0.0 macro def h1_name=/tmp/vtc.68714.517aebde/h1
> ** top 0.0 === shell {
> **** top 0.0 shell_cmd|exec 2>&1 ;
> **** top 0.0 shell_cmd| HOST=::1
> **** top 0.0 shell_cmd| if [ "$HOST" = "::1" ] ; then
> **** top 0.0 shell_cmd| HOST="\[::1\]"
> **** top 0.0 shell_cmd| fi
> **** top 0.0 shell_cmd| for i in 1 2 3 4 5 6 7 8 ; do
> **** top 0.0 shell_cmd| urls="$urls https://$HOST:41654/$i";
> **** top 0.0 shell_cmd| done
> **** top 0.0 shell_cmd| curl -i -k -d 'x=x' $urls & wait $!
> *** h1 0.0 debug|Note: setting global.maxconn to 2000.
> *** h1 0.0 debug|Available polling systems :
> *** h1 0.0 debug| kqueue :
> *** h1 0.0 debug|pref=300, test result OK
> *** h1 0.0 debug| poll : pref=200, test result OK
> *** h1 0.0 debug| select : pref=150, test result FAILED
> *** h1 0.0 debug|Total: 3 (2 usable), will use kqueue.
> *** h1 0.0 debug|
> *** h1 0.0 debug|Available filters :
> *** h1 0.0 debug|\t[SPOE] spoe
> *** h1 0.0 debug|\t[COMP] compression
> *** h1 0.0 debug|\t[CACHE] cache
> *** h1 0.0 debug|\t[TRACE] trace
> *** h1 0.0 debug|Using kqueue() as the polling mechanism.
> **** Slog_1 0.0 syslog|<133>Dec 15 16:42:54 haproxy[68718]: Proxy http
> started.
> **** Slog_1 0.0 syslog|<133>Dec 15 16:42:54 haproxy[68718]: Proxy
> ssl-offload-http started.
> *** h1 0.0 debug|00000000:ssl-offload-http.accept(0005)=000d from
> [::1:41655] ALPN=h2
> *** h1 0.0 debug|00000000:ssl-offload-http.clireq[000d:ffffffff]: POST /1
> HTTP/2.0
> *** h1 0.0 debug|00000000:ssl-offload-http.clihdr[000d:ffffffff]:
> user-agent: curl/7.60.0
> *** h1 0.0 debug|00000000:ssl-offload-http.clihdr[000d:ffffffff]: accept:
> */*
> *** h1 0.0 debug|00000000:ssl-offload-http.clihdr[000d:ffffffff]:
> content-length: 3
> *** h1 0.0 debug|00000000:ssl-offload-http.clihdr[000d:ffffffff]:
> content-type: application/x-www-form-urlencoded
> *** h1 0.0 debug|00000000:ssl-offload-http.clihdr[000d:ffffffff]: host:
> [::1]:41654
> *** h1 0.0 debug|00000001:http.accept(0008)=0017 from [::1:41655]
> ALPN=<none>
> **** Slog_1 0.0 syslog|<134>Dec 15 16:42:54 haproxy[68718]: Connect from
> ::1:41655 to ::1:41654 (http/HTTP)
> ** Slog_1 0.0 === expect ~ "Connect from .* to
> ${h1_ssl_addr}:${h1_ssl_port}"
> *** h1 0.0 debug|00000001:http.clireq[0017:ffffffff]: POST /1 HTTP/1.1
> *** h1 0.0 debug|00000001:http.clihdr[0017:ffffffff]: user-agent:
> curl/7.60.0
> *** h1 0.0 debug|00000001:http.clihdr[0017:ffffffff]: accept: */*
> *** h1 0.0 debug|00000001:http.clihdr[0017:ffffffff]: content-length: 3
> *** h1 0.0 debug|00000001:http.clihdr[0017:ffffffff]: content-type:
> application/x-www-form-urlencoded
> *** h1 0.0 debug|00000001:http.clihdr[0017:ffffffff]: host: [::1]:41654
> *** h1 0.0 debug|00000000:ssl-offload-http.srvrep[000d:0016]: HTTP/1.0
> 503 Service Unavailable
> *** h1 0.0 debug|00000000:ssl-offload-http.srvhdr[000d:0016]:
> cache-control: no-cache
> *** h1 0.0 debug|00000000:ssl-offload-http.srvhdr[000d:0016]:
> content-type: text/html
> **** Slog_1 0.0 EXPECT MATCH ~ "Connect from .* to ::1:41654"
> ** Slog_1 0.0 === recv
> *** h1 1.1 debug|00000001:http.clicls[adfd:ffffffff]
> *** h1 1.1 debug|00000001:http.closed[adfd:ffffffff]
> *** h1 1.1 debug|00000000:ssl-offload-http.srvcls[000d:adfd]
> *** h1 1.1 debug|00000000:ssl-offload-http.clicls[000d:adfd]
> *** h1 1.1 debug|00000000:ssl-offload-http.closed[000d:adfd]
> **** Slog_1 1.1 syslog|<134>Dec 15 16:42:55 haproxy[68718]: ::1:41655
> [15/Dec/2018:16:42:54.791] ssl-offload-http~ ssl-offload-http/http
> 0/0/0/0/1044 503 193 - - sD-- 1/1/0/0/0 0/0 "POST /1 HTTP/2.0"
> ** Slog_1 1.1 === expect ~ "ssl-offload-http/http .* \"POST /[1-8]
> HTTP/2\\.0\...
> **** Slog_1 1.1 EXPECT MATCH ~ "ssl-offload-http/http .* "POST /[1-8]
> HTTP/2\.0""
> *** Slog_1 1.1 shutting fd 3
> *** Slog_1 1.1 Iteration 1
> ** Slog_1 1.1 === recv
> *** h1 1.1 debug|00000002:ssl-offload-http.accept(0005)=000d from
> [::1:41655] ALPN=h2
> *** h1 1.1 debug|00000002:ssl-offload-http.clireq[000d:ffffffff]: POST /2
> HTTP/2.0
> *** h1 1.1 debug|00000002:ssl-offload-http.clihdr[000d:ffffffff]:
> user-agent: curl/7.60.0
> *** h1 1.1 debug|00000002:ssl-offload-http.clihdr[000d:ffffffff]: accept:
> */*
> *** h1 1.1 debug|00000002:ssl-offload-http.clihdr[000d:ffffffff]:
> content-length: 3
> *** h1 1.1 debug|00000002:ssl-offload-http.clihdr[000d:ffffffff]:
> content-type: application/x-www-form-urlencoded
> *** h1 1.1 debug|00000002:ssl-offload-http.clihdr[000d:ffffffff]: host:
> [::1]:41654
> **** Slog_1 1.1 syslog|<134>Dec 15 16:42:55 haproxy[68718]: Connect from
> ::1:41655 to ::1:41654 (http/HTTP)
> ** Slog_1 1.1 === expect ~ "Connect from .* to
> ${h1_ssl_addr}:${h1_ssl_port}"
> *** h1 1.1 debug|00000003:http.accept(0008)=0019 from [::1:41655]
> ALPN=<none>
> *** h1 1.1 debug|00000003:http.clireq[0019:ffffffff]: POST /2 HTTP/1.1
> *** h1 1.1 debug|00000003:http.clihdr[0019:ffffffff]: user-agent:
> curl/7.60.0
> *** h1 1.1 debug|00000003:http.clihdr[0019:ffffffff]: accept: */*
> *** h1 1.1 debug|00000003:http.clihdr[0019:ffffffff]: content-length: 3
> *** h1 1.1 debug|00000003:http.clihdr[0019:ffffffff]: content-type:
> application/x-www-form-urlencoded
> *** h1 1.1 debug|00000003:http.clihdr[0019:ffffffff]: host: [::1]:41654
> **** Slog_1 1.1 EXPECT MATCH ~ "Connect from .* to ::1:41654"
> ** Slog_1 1.1 === recv
> *** h1 1.1 debug|00000002:ssl-offload-http.srvrep[000d:0017]: HTTP/1.0
> 503 Service Unavailable
> *** h1 1.1 debug|00000002:ssl-offload-http.srvhdr[000d:0017]:
> cache-control: no-cache
> *** h1 1.1 debug|00000002:ssl-offload-http.srvhdr[000d:0017]:
> content-type: text/html
> *** h1 2.1 debug|00000003:http.clicls[adfd:ffffffff]
> *** h1 2.1 debug|00000003:http.closed[adfd:ffffffff]
> *** h1 2.1 debug|00000002:ssl-offload-http.srvcls[000d:adfd]
> *** h1 2.1 debug|00000002:ssl-offload-http.clicls[000d:adfd]
> *** h1 2.1 debug|00000002:ssl-offload-http.closed[000d:adfd]
> **** Slog_1 2.1 syslog|<134>Dec 15 16:42:56 haproxy[68718]: ::1:41655
> [15/Dec/2018:16:42:55.836] ssl-offload-http~ ssl-offload-http/http
> 0/0/1/0/1057 503 193 - - sD-- 1/1/0/0/0 0/0 "POST /2 HTTP/2.0"
> ** Slog_1 2.1 === expect ~ "ssl-offload-http/http .* \"POST /[1-8]
> HTTP/2\\.0\...
> **** Slog_1 2.1 EXPECT MATCH ~ "ssl-offload-http/http .* "POST /[1-8]
> HTTP/2\.0""
> *** Slog_1 2.1 shutting fd 3
> *** Slog_1 2.1 Iteration 2
> ** Slog_1 2.1 === recv
> *** h1 2.1 debug|00000004:ssl-offload-http.accept(0005)=000d from
> [::1:41655] ALPN=h2
> *** h1 2.1 debug|00000004:ssl-offload-http.clireq[000d:ffffffff]: POST /3
> HTTP/2.0
> *** h1 2.1 debug|00000004:ssl-offload-http.clihdr[000d:ffffffff]:
> user-agent: curl/7.60.0
> *** h1 2.1 debug|00000004:ssl-offload-http.clihdr[000d:ffffffff]: accept:
> */*
> *** h1 2.1 debug|00000004:ssl-offload-http.clihdr[000d:ffffffff]:
> content-length: 3
> *** h1 2.1 debug|00000004:ssl-offload-http.clihdr[000d:ffffffff]:
> content-type: application/x-www-form-urlencoded
> *** h1 2.1 debug|00000004:ssl-offload-http.clihdr[000d:ffffffff]: host:
> [::1]:41654
> *** h1 2.1 debug|00000005:http.accept(0008)=0019 from [::1:41655]
> ALPN=<none>
> **** Slog_1 2.1 syslog|<134>Dec 15 16:42:56 haproxy[68718]: Connect from
> ::1:41655 to ::1:41654 (http/HTTP)
> ** Slog_1 2.1 === expect ~ "Connect from .* to
> ${h1_ssl_addr}:${h1_ssl_port}"
> *** h1 2.1 debug|00000005:http.clireq[0019:ffffffff]: POST /3 HTTP/1.1
> *** h1 2.1 debug|00000005:http.clihdr[0019:ffffffff]: user-agent:
> curl/7.60.0
> *** h1 2.1 debug|00000005:http.clihdr[0019:ffffffff]: accept: */*
> *** h1 2.1 debug|00000005:http.clihdr[0019:ffffffff]: content-length: 3
> *** h1 2.1 debug|00000005:http.clihdr[0019:ffffffff]: content-type:
> application/x-www-form-urlencoded
> *** h1 2.1 debug|00000005:http.clihdr[0019:ffffffff]: host: [::1]:41654
> **** Slog_1 2.1 EXPECT MATCH ~ "Connect from .* to ::1:41654"
> ** Slog_1 2.1 === recv
> *** h1 2.1 debug|00000004:ssl-offload-http.srvrep[000d:0017]: HTTP/1.0
> 503 Service Unavailable
> *** h1 2.1 debug|00000004:ssl-offload-http.srvhdr[000d:0017]:
> cache-control: no-cache
> *** h1 2.1 debug|00000004:ssl-offload-http.srvhdr[000d:0017]:
> content-type: text/html
> *** h1 3.2 debug|00000005:http.clicls[adfd:ffffffff]
> *** h1 3.2 debug|00000005:http.closed[adfd:ffffffff]
> *** h1 3.2 debug|00000004:ssl-offload-http.srvcls[000d:adfd]
> *** h1 3.2 debug|00000004:ssl-offload-http.clicls[000d:adfd]
> *** h1 3.2 debug|00000004:ssl-offload-http.closed[000d:adfd]
> **** Slog_1 3.2 syslog|<134>Dec 15 16:42:57 haproxy[68718]: ::1:41655
> [15/Dec/2018:16:42:56.894] ssl-offload-http~ ssl-offload-http/http
> 0/0/0/0/1063 503 193 - - sD-- 1/1/0/0/0 0/0 "POST /3 HTTP/2.0"
> ** Slog_1 3.2 === expect ~ "ssl-offload-http/http .* \"POST /[1-8]
> HTTP/2\\.0\...
> **** Slog_1 3.2 EXPECT MATCH ~ "ssl-offload-http/http .* "POST /[1-8]
> HTTP/2\.0""
> *** Slog_1 3.2 shutting fd 3
> *** Slog_1 3.2 Iteration 3
> ** Slog_1 3.2 === recv
> *** h1 3.2 debug|00000006:ssl-offload-http.accept(0005)=000d from
> [::1:41655] ALPN=h2
> *** h1 3.2 debug|00000006:ssl-offload-http.clireq[000d:ffffffff]: POST /4
> HTTP/2.0
> *** h1 3.2 debug|00000006:ssl-offload-http.clihdr[000d:ffffffff]:
> user-agent: curl/7.60.0
> *** h1 3.2 debug|00000006:ssl-offload-http.clihdr[000d:ffffffff]: accept:
> */*
> *** h1 3.2 debug|00000006:ssl-offload-http.clihdr[000d:ffffffff]:
> content-length: 3
> *** h1 3.2 debug|00000006:ssl-offload-http.clihdr[000d:ffffffff]:
> content-type: application/x-www-form-urlencoded
> *** h1 3.2 debug|00000006:ssl-offload-http.clihdr[000d:ffffffff]: host:
> [::1]:41654
> **** Slog_1 3.2 syslog|<134>Dec 15 16:42:57 haproxy[68718]: Connect from
> ::1:41655 to ::1:41654 (http/HTTP)
> ** Slog_1 3.2 === expect ~ "Connect from .* to
> ${h1_ssl_addr}:${h1_ssl_port}"
> *** h1 3.2 debug|00000007:http.accept(0008)=0019 from [::1:41655]
> ALPN=<none>
> **** Slog_1 3.2 EXPECT MATCH ~ "Connect from .* to ::1:41654"
> ** Slog_1 3.2 === recv
> *** h1 3.2 debug|00000007:http.clireq[0019:ffffffff]: POST /4 HTTP/1.1
> *** h1 3.2 debug|00000007:http.clihdr[0019:ffffffff]: user-agent:
> curl/7.60.0
> *** h1 3.2 debug|00000007:http.clihdr[0019:ffffffff]: accept: */*
> *** h1 3.2 debug|00000007:http.clihdr[0019:ffffffff]: content-length: 3
> *** h1 3.2 debug|00000007:http.clihdr[0019:ffffffff]: content-type:
> application/x-www-form-urlencoded
> *** h1 3.2 debug|00000007:http.clihdr[0019:ffffffff]: host: [::1]:41654
> *** h1 3.2 debug|00000006:ssl-offload-http.srvrep[000d:0017]: HTTP/1.0
> 503 Service Unavailable
> *** h1 3.2 debug|00000006:ssl-offload-http.srvhdr[000d:0017]:
> cache-control: no-cache
> *** h1 3.2 debug|00000006:ssl-offload-http.srvhdr[000d:0017]:
> content-type: text/html
> *** h1 4.3 debug|00000007:http.clicls[adfd:ffffffff]
> *** h1 4.3 debug|00000007:http.closed[adfd:ffffffff]
> *** h1 4.3 debug|00000006:ssl-offload-http.srvcls[000d:adfd]
> *** h1 4.3 debug|00000006:ssl-offload-http.clicls[000d:adfd]
> *** h1 4.3 debug|00000006:ssl-offload-http.closed[000d:adfd]
> **** Slog_1 4.3 syslog|<134>Dec 15 16:42:59 haproxy[68718]: ::1:41655
> [15/Dec/2018:16:42:57.957] ssl-offload-http~ ssl-offload-http/http
> 0/0/0/0/1064 503 193 - - sD-- 1/1/0/0/0 0/0 "POST /4 HTTP/2.0"
> ** Slog_1 4.3 === expect ~ "ssl-offload-http/http .* \"POST /[1-8]
> HTTP/2\\.0\...
> **** Slog_1 4.3 EXPECT MATCH ~ "ssl-offload-http/http .* "POST /[1-8]
> HTTP/2\.0""
> *** Slog_1 4.3 shutting fd 3
> *** Slog_1 4.3 Iteration 4
> ** Slog_1 4.3 === recv
> *** h1 4.3 debug|00000008:ssl-offload-http.accept(0005)=000d from
> [::1:41655] ALPN=h2
> *** h1 4.3 debug|00000008:ssl-offload-http.clireq[000d:ffffffff]: POST /5
> HTTP/2.0
> *** h1 4.3 debug|00000008:ssl-offload-http.clihdr[000d:ffffffff]:
> user-agent: curl/7.60.0
> *** h1 4.3 debug|00000008:ssl-offload-http.clihdr[000d:ffffffff]: accept:
> */*
> *** h1 4.3 debug|00000008:ssl-offload-http.clihdr[000d:ffffffff]:
> content-length: 3
> *** h1 4.3 debug|00000008:ssl-offload-http.clihdr[000d:ffffffff]:
> content-type: application/x-www-form-urlencoded
> *** h1 4.3 debug|00000008:ssl-offload-http.clihdr[000d:ffffffff]: host:
> [::1]:41654
> **** Slog_1 4.3 syslog|<134>Dec 15 16:42:59 haproxy[68718]: Connect from
> ::1:41655 to ::1:41654 (http/HTTP)
> *** h1 4.3 debug|00000009:http.accept(0008)=0019 from [::1:41655]
> ALPN=<none>
> ** Slog_1 4.3 === expect ~ "Connect from .* to
> ${h1_ssl_addr}:${h1_ssl_port}"
> **** Slog_1 4.3 EXPECT MATCH ~ "Connect from .* to ::1:41654"
> ** Slog_1 4.3 === recv
> *** h1 4.3 debug|00000009:http.clireq[0019:ffffffff]: POST /5 HTTP/1.1
> *** h1 4.3 debug|00000009:http.clihdr[0019:ffffffff]: user-agent:
> curl/7.60.0
> *** h1 4.3 debug|00000009:http.clihdr[0019:ffffffff]: accept: */*
> *** h1 4.3 debug|00000009:http.clihdr[0019:ffffffff]: content-length: 3
> *** h1 4.3 debug|00000009:http.clihdr[0019:ffffffff]: content-type:
> application/x-www-form-urlencoded
> *** h1 4.3 debug|00000009:http.clihdr[0019:ffffffff]: host: [::1]:41654
> *** h1 4.3 debug|00000008:ssl-offload-http.srvrep[000d:0017]: HTTP/1.0
> 503 Service Unavailable
> *** h1 4.3 debug|00000008:ssl-offload-http.srvhdr[000d:0017]:
> cache-control: no-cache
> *** h1 4.3 debug|00000008:ssl-offload-http.srvhdr[000d:0017]:
> content-type: text/html
> *** h1 5.3 debug|00000008:ssl-offload-http.srvcls[000d:adfd]
> *** h1 5.3 debug|00000008:ssl-offload-http.clicls[000d:adfd]
> *** h1 5.3 debug|00000008:ssl-offload-http.closed[000d:adfd]
> *** h1 5.3 debug|00000009:http.clicls[adfd:ffffffff]
> *** h1 5.3 debug|00000009:http.closed[adfd:ffffffff]
> **** Slog_1 5.3 syslog|<134>Dec 15 16:43:00 haproxy[68718]: ::1:41655
> [15/Dec/2018:16:42:59.023] ssl-offload-http~ ssl-offload-http/http
> 0/0/0/0/1063 503 193 - - sD-- 2/1/0/0/0 0/0 "POST /5 HTTP/2.0"
> ** Slog_1 5.3 === expect ~ "ssl-offload-http/http .* \"POST /[1-8]
> HTTP/2\\.0\...
> **** Slog_1 5.3 EXPECT MATCH ~ "ssl-offload-http/http .* "POST /[1-8]
> HTTP/2\.0""
> *** Slog_1 5.3 shutting fd 3
> *** Slog_1 5.3 Iteration 5
> ** Slog_1 5.3 === recv
> *** h1 5.3 debug|0000000a:ssl-offload-http.accept(0005)=000d from
> [::1:41655] ALPN=h2
> *** h1 5.3 debug|0000000a:ssl-offload-http.clireq[000d:ffffffff]: POST /6
> HTTP/2.0
> *** h1 5.3 debug|0000000a:ssl-offload-http.clihdr[000d:ffffffff]:
> user-agent: curl/7.60.0
> *** h1 5.3 debug|0000000a:ssl-offload-http.clihdr[000d:ffffffff]: accept:
> */*
> *** h1 5.3 debug|0000000a:ssl-offload-http.clihdr[000d:ffffffff]:
> content-length: 3
> *** h1 5.3 debug|0000000a:ssl-offload-http.clihdr[000d:ffffffff]:
> content-type: application/x-www-form-urlencoded
> *** h1 5.3 debug|0000000a:ssl-offload-http.clihdr[000d:ffffffff]: host:
> [::1]:41654
> *** h1 5.3 debug|0000000b:http.accept(0008)=0019 from [::1:41655]
> ALPN=<none>
> **** Slog_1 5.3 syslog|<134>Dec 15 16:43:00 haproxy[68718]: Connect from
> ::1:41655 to ::1:41654 (http/HTTP)
> ** Slog_1 5.3 === expect ~ "Connect from .* to
> ${h1_ssl_addr}:${h1_ssl_port}"
> **** Slog_1 5.3 EXPECT MATCH ~ "Connect from .* to ::1:41654"
> ** Slog_1 5.3 === recv
> *** h1 5.3 debug|0000000b:http.clireq[0019:ffffffff]: POST /6 HTTP/1.1
> *** h1 5.3 debug|0000000b:http.clihdr[0019:ffffffff]: user-agent:
> curl/7.60.0
> *** h1 5.3 debug|0000000b:http.clihdr[0019:ffffffff]: accept: */*
> *** h1 5.3 debug|0000000b:http.clihdr[0019:ffffffff]: content-length: 3
> *** h1 5.3 debug|0000000b:http.clihdr[0019:ffffffff]: content-type:
> application/x-www-form-urlencoded
> *** h1 5.3 debug|0000000b:http.clihdr[0019:ffffffff]: host: [::1]:41654
> *** h1 5.3 debug|0000000a:ssl-offload-http.srvrep[000d:0017]: HTTP/1.0
> 503 Service Unavailable
> *** h1 5.3 debug|0000000a:ssl-offload-http.srvhdr[000d:0017]:
> cache-control: no-cache
> *** h1 5.3 debug|0000000a:ssl-offload-http.srvhdr[000d:0017]:
> content-type: text/html
> *** h1 6.4 debug|0000000a:ssl-offload-http.srvcls[000d:adfd]
> *** h1 6.4 debug|0000000a:ssl-offload-http.clicls[000d:adfd]
> *** h1 6.4 debug|0000000b:http.clicls[adfd:ffffffff]
> *** h1 6.4 debug|0000000a:ssl-offload-http.closed[000d:adfd]
> *** h1 6.4 debug|0000000b:http.closed[adfd:ffffffff]
> **** Slog_1 6.4 syslog|<134>Dec 15 16:43:01 haproxy[68718]: ::1:41655
> [15/Dec/2018:16:43:00.086] ssl-offload-http~ ssl-offload-http/http
> 0/0/0/0/1063 503 193 - - sD-- 1/1/0/0/0 0/0 "POST /6 HTTP/2.0"
> ** Slog_1 6.4 === expect ~ "ssl-offload-http/http .* \"POST /[1-8]
> HTTP/2\\.0\...
> **** Slog_1 6.4 EXPECT MATCH ~ "ssl-offload-http/http .* "POST /[1-8]
> HTTP/2\.0""
> *** Slog_1 6.4 shutting fd 3
> *** Slog_1 6.4 Iteration 6
> ** Slog_1 6.4 === recv
> *** h1 6.4 debug|0000000c:ssl-offload-http.accept(0005)=000d from
> [::1:41655] ALPN=h2
> *** h1 6.4 debug|0000000c:ssl-offload-http.clireq[000d:ffffffff]: POST /7
> HTTP/2.0
> *** h1 6.4 debug|0000000c:ssl-offload-http.clihdr[000d:ffffffff]:
> user-agent: curl/7.60.0
> *** h1 6.4 debug|0000000c:ssl-offload-http.clihdr[000d:ffffffff]: accept:
> */*
> *** h1 6.4 debug|0000000c:ssl-offload-http.clihdr[000d:ffffffff]:
> content-length: 3
> *** h1 6.4 debug|0000000c:ssl-offload-http.clihdr[000d:ffffffff]:
> content-type: application/x-www-form-urlencoded
> *** h1 6.4 debug|0000000c:ssl-offload-http.clihdr[000d:ffffffff]: host:
> [::1]:41654
> *** h1 6.4 debug|0000000d:http.accept(0008)=0019 from [::1:41655]
> ALPN=<none>
> **** Slog_1 6.4 syslog|<134>Dec 15 16:43:01 haproxy[68718]: Connect from
> ::1:41655 to ::1:41654 (http/HTTP)
> ** Slog_1 6.4 === expect ~ "Connect from .* to
> ${h1_ssl_addr}:${h1_ssl_port}"
> **** Slog_1 6.4 EXPECT MATCH ~ "Connect from .* to ::1:41654"
> ** Slog_1 6.4 === recv
> *** h1 6.4 debug|0000000d:http.clireq[0019:ffffffff]: POST /7 HTTP/1.1
> *** h1 6.4 debug|0000000d:http.clihdr[0019:ffffffff]: user-agent:
> curl/7.60.0
> *** h1 6.4 debug|0000000d:http.clihdr[0019:ffffffff]: accept: */*
> *** h1 6.4 debug|0000000d:http.clihdr[0019:ffffffff]: content-length: 3
> *** h1 6.4 debug|0000000d:http.clihdr[0019:ffffffff]: content-type:
> application/x-www-form-urlencoded
> *** h1 6.4 debug|0000000d:http.clihdr[0019:ffffffff]: host: [::1]:41654
> *** h1 6.4 debug|0000000c:ssl-offload-http.srvrep[000d:0017]: HTTP/1.0
> 503 Service Unavailable
> *** h1 6.4 debug|0000000c:ssl-offload-http.srvhdr[000d:0017]:
> cache-control: no-cache
> *** h1 6.4 debug|0000000c:ssl-offload-http.srvhdr[000d:0017]:
> content-type: text/html
> *** h1 7.4 debug|0000000d:http.clicls[adfd:ffffffff]
> *** h1 7.4 debug|0000000d:http.closed[adfd:ffffffff]
> *** h1 7.4 debug|0000000c:ssl-offload-http.srvcls[000d:adfd]
> *** h1 7.4 debug|0000000c:ssl-offload-http.clicls[000d:adfd]
> *** h1 7.4 debug|0000000c:ssl-offload-http.closed[000d:adfd]
> **** Slog_1 7.4 syslog|<134>Dec 15 16:43:02 haproxy[68718]: ::1:41655
> [15/Dec/2018:16:43:01.150] ssl-offload-http~ ssl-offload-http/http
> 0/0/0/0/1006 503 193 - - sD-- 1/1/0/0/0 0/0 "POST /7 HTTP/2.0"
> ** Slog_1 7.4 === expect ~ "ssl-offload-http/http .* \"POST /[1-8]
> HTTP/2\\.0\...
> **** Slog_1 7.4 EXPECT MATCH ~ "ssl-offload-http/http .* "POST /[1-8]
> HTTP/2\.0""
> *** Slog_1 7.4 shutting fd 3
> *** Slog_1 7.4 Iteration 7
> ** Slog_1 7.4 === recv
> *** h1 7.4 debug|0000000e:ssl-offload-http.accept(0005)=000d from
> [::1:41655] ALPN=h2
> *** h1 7.4 debug|0000000e:ssl-offload-http.clireq[000d:ffffffff]: POST /8
> HTTP/2.0
> *** h1 7.4 debug|0000000e:ssl-offload-http.clihdr[000d:ffffffff]:
> user-agent: curl/7.60.0
> *** h1 7.4 debug|0000000e:ssl-offload-http.clihdr[000d:ffffffff]: accept:
> */*
> *** h1 7.4 debug|0000000e:ssl-offload-http.clihdr[000d:ffffffff]:
> content-length: 3
> *** h1 7.4 debug|0000000e:ssl-offload-http.clihdr[000d:ffffffff]:
> content-type: application/x-www-form-urlencoded
> *** h1 7.4 debug|0000000e:ssl-offload-http.clihdr[000d:ffffffff]: host:
> [::1]:41654
> *** h1 7.4 debug|0000000f:http.accept(0008)=0019 from [::1:41655]
> ALPN=<none>
> **** Slog_1 7.4 syslog|<134>Dec 15 16:43:02 haproxy[68718]: Connect from
> ::1:41655 to ::1:41654 (http/HTTP)
> ** Slog_1 7.4 === expect ~ "Connect from .* to
> ${h1_ssl_addr}:${h1_ssl_port}"
> **** Slog_1 7.4 EXPECT MATCH ~ "Connect from .* to ::1:41654"
> *** h1 7.4 debug|0000000f:http.clireq[0019:ffffffff]: POST /8 HTTP/1.1
> *** h1 7.4 debug|0000000f:http.clihdr[0019:ffffffff]: user-agent:
> curl/7.60.0
> *** h1 7.4 debug|0000000f:http.clihdr[0019:ffffffff]: accept: */*
> *** h1 7.4 debug|0000000f:http.clihdr[0019:ffffffff]: content-length: 3
> *** h1 7.4 debug|0000000f:http.clihdr[0019:ffffffff]: content-type:
> application/x-www-form-urlencoded
> *** h1 7.4 debug|0000000f:http.clihdr[0019:ffffffff]: host: [::1]:41654
> ** Slog_1 7.4 === recv
> *** h1 7.4 debug|0000000e:ssl-offload-http.srvrep[000d:0017]: HTTP/1.0
> 503 Service Unavailable
> *** h1 7.4 debug|0000000e:ssl-offload-http.srvhdr[000d:0017]:
> cache-control: no-cache
> *** h1 7.4 debug|0000000e:ssl-offload-http.srvhdr[000d:0017]:
> content-type: text/html
> *** h1 8.4 debug|0000000f:http.clicls[adfd:ffffffff]
> *** h1 8.4 debug|0000000f:http.closed[adfd:ffffffff]
> *** h1 8.4 debug|0000000e:ssl-offload-http.srvcls[000d:adfd]
> *** h1 8.4 debug|0000000e:ssl-offload-http.clicls[000d:adfd]
> *** h1 8.4 debug|0000000e:ssl-offload-http.closed[000d:adfd]
> **** Slog_1 8.4 syslog|<134>Dec 15 16:43:03 haproxy[68718]: ::1:41655
> [15/Dec/2018:16:43:02.156] ssl-offload-http~ ssl-offload-http/http
> 0/0/1/0/1028 503 193 - - sD-- 1/1/0/0/0 0/0 "POST /8 HTTP/2.0"
> ** Slog_1 8.4 === expect ~ "ssl-offload-http/http .* \"POST /[1-8]
> HTTP/2\\.0\...
> **** Slog_1 8.4 EXPECT MATCH ~ "ssl-offload-http/http .* "POST /[1-8]
> HTTP/2\.0""
> *** Slog_1 8.4 shutting fd 3
> ** Slog_1 8.4 Ending
> **** top 8.4 shell_out| % Total % Received % Xferd Average Speed
> Time Time Time Current
> **** top 8.4 shell_out| Dload Upload
> Total Spent Left Speed
> **** top 8.4 shell_out|\r 0 0 0 0 0 0 0 0
> --:--:-- --:--:-- --:--:-- 0\r100 110 0 107 100 3 101
> 2 0:00:01 0:00:01 --:--:-- 103\r100 110 0 107 100 3 101
> 2 0:00:01 0:00:01 --:--:-- 103
> **** top 8.4 shell_out|HTTP/2 503 \r
> **** top 8.4 shell_out|cache-control: no-cache\r
> **** top 8.4 shell_out|content-type: text/html\r
> **** top 8.4 shell_out|\r
> **** top 8.4 shell_out|<html><body><h1>503 Service Unavailable</h1>
> **** top 8.4 shell_out|No server is available to handle this request.
> **** top 8.4 shell_out|</body></html>
> **** top 8.4 shell_out|\r100 110 0 107 100 3 101 2
> 0:00:01 0:00:01 --:--:-- 103\r100 110 0 107 100 3 101
> 2 0:00:01 0:00:01 --:--:-- 0
> **** top 8.4 shell_out|HTTP/2 503 \r
> **** top 8.4 shell_out|cache-control: no-cache\r
> **** top 8.4 shell_out|content-type: text/html\r
> **** top 8.4 shell_out|\r
> **** top 8.4 shell_out|<html><body><h1>503 Service Unavailable</h1>
> **** top 8.4 shell_out|No server is available to handle this request.
> **** top 8.4 shell_out|</body></html>
> **** top 8.4 shell_out|\r100 110 0 107 100 3 100 2
> 0:00:01 0:00:01 --:--:-- 102\r100 110 0 107 100 3 100
> 2 0:00:01 0:00:01 --:--:-- 0
> **** top 8.4 shell_out|HTTP/2 503 \r
> **** top 8.4 shell_out|cache-control: no-cache\r
> **** top 8.4 shell_out|content-type: text/html\r
> **** top 8.4 shell_out|\r
> **** top 8.4 shell_out|<html><body><h1>503 Service Unavailable</h1>
> **** top 8.4 shell_out|No server is available to handle this request.
> **** top 8.4 shell_out|</body></html>
> **** top 8.4 shell_out|\r100 110 0 107 100 3 100 2
> 0:00:01 0:00:01 --:--:-- 102\r100 110 0 107 100 3 100
> 2 0:00:01 0:00:01 --:--:-- 0
> **** top 8.4 shell_out|HTTP/2 503 \r
> **** top 8.4 shell_out|cache-control: no-cache\r
> **** top 8.4 shell_out|content-type: text/html\r
> **** top 8.4 shell_out|\r
> **** top 8.4 shell_out|<html><body><h1>503 Service Unavailable</h1>
> **** top 8.4 shell_out|No server is available to handle this request.
> **** top 8.4 shell_out|</body></html>
> **** top 8.4 shell_out|\r100 110 0 107 100 3 104 2
> 0:00:01 0:00:01 --:--:-- 106\r100 110 0 107 100 3 100
> 2 0:00:01 0:00:01 --:--:-- 0
> **** top 8.4 shell_out|HTTP/2 503 \r
> **** top 8.4 shell_out|cache-control: no-cache\r
> **** top 8.4 shell_out|content-type: text/html\r
> **** top 8.4 shell_out|\r
> **** top 8.4 shell_out|<html><body><h1>503 Service Unavailable</h1>
> **** top 8.4 shell_out|No server is available to handle this request.
> **** top 8.4 shell_out|</body></html>
> **** top 8.4 shell_out|\r100 110 0 107 100 3 100 2
> 0:00:01 0:00:01 --:--:-- 102\r100 110 0 107 100 3 100
> 2 0:00:01 0:00:01 --:--:-- 0
> **** top 8.4 shell_out|HTTP/2 503 \r
> **** top 8.4 shell_out|cache-control: no-cache\r
> **** top 8.4 shell_out|content-type: text/html\r
> **** top 8.4 shell_out|\r
> **** top 8.4 shell_out|<html><body><h1>503 Service Unavailable</h1>
> **** top 8.4 shell_out|No server is available to handle this request.
> **** top 8.4 shell_out|</body></html>
> **** top 8.4 shell_out|\r100 110 0 107 100 3 106 2
> 0:00:01 0:00:01 --:--:-- 108\r100 110 0 107 100 3 106
> 2 0:00:01 0:00:01 --:--:-- 0
> **** top 8.4 shell_out|HTTP/2 503 \r
> **** top 8.4 shell_out|cache-control: no-cache\r
> **** top 8.4 shell_out|content-type: text/html\r
> **** top 8.4 shell_out|\r
> **** top 8.4 shell_out|<html><body><h1>503 Service Unavailable</h1>
> **** top 8.4 shell_out|No server is available to handle this request.
> **** top 8.4 shell_out|</body></html>
> **** top 8.4 shell_out|\r100 110 0 107 100 3 104 2
> 0:00:01 0:00:01 --:--:-- 106\r100 110 0 107 100 3 104
> 2 0:00:01 0:00:01 --:--:-- 0
> **** top 8.4 shell_out|HTTP/2 503 \r
> **** top 8.4 shell_out|cache-control: no-cache\r
> **** top 8.4 shell_out|content-type: text/html\r
> **** top 8.4 shell_out|\r
> **** top 8.4 shell_out|<html><body><h1>503 Service Unavailable</h1>
> **** top 8.4 shell_out|No server is available to handle this request.
> **** top 8.4 shell_out|</body></html>
> **** top 8.4 shell_status = 0x0000
> ** top 8.4 === syslog Slog_1 -wait
> ** Slog_1 8.4 Waiting for syslog server (-1)
> * top 8.4 RESETTING after ./htx-test/connection-b00000.vtc
> ** h1 8.4 Reset and free h1 haproxy 68718
> ** h1 8.4 Wait
> ** h1 8.4 Stop HAproxy pid=68718
> **** h1 8.4 Kill(2)=0: No error: 0
> **** h1 8.4 STDOUT poll 0x11
> ** h1 8.5 WAIT4 pid=68718 status=0x0002 (user 0.000000 sys 0.023238)
> * top 8.5 TEST ./htx-test/connection-b00000.vtc completed
>
> **** top 0.0 extmacro def pwd=/usr/ports/net/haproxy-devel
> **** top 0.0 extmacro def localhost=127.0.0.1
> **** top 0.0 extmacro def bad_backend=127.0.0.1 41652
> **** top 0.0 extmacro def bad_ip=192.0.2.255
> **** top 0.0 macro def testdir=/usr/ports/net/haproxy-devel/./htx-test
> **** top 0.0 macro def tmpdir=/tmp/vtc.68714.16672579
> * top 0.0 TEST ./htx-test/stick-table-b00001.vtc starting
> ** top 0.0 === varnishtest "stick-tables: Test expirations when used with
> t...
> * top 0.0 TEST stick-tables: Test expirations when used with table_*
> ** top 0.0 === feature ignore_unknown_macro
> ** top 0.0 === server s1 {
> ** s1 0.0 Starting server
> **** s1 0.0 macro def s1_addr=127.0.0.1
> **** s1 0.0 macro def s1_port=41871
> **** s1 0.0 macro def s1_sock=127.0.0.1 41871
> * s1 0.0 Listen on 127.0.0.1 41871
> ** top 0.0 === haproxy h1 -conf {
> ** s1 0.0 Started on 127.0.0.1 41871
> **** h1 0.0 macro def h1_cli_sock=::1 41872
> **** h1 0.0 macro def h1_cli_addr=::1
> **** h1 0.0 macro def h1_cli_port=41872
> **** h1 0.0 setenv(cli, 5)
> **** h1 0.0 macro def h1_my_frontend_fd_sock=::1 41873
> **** h1 0.0 macro def h1_my_frontend_fd_addr=::1
> **** h1 0.0 macro def h1_my_frontend_fd_port=41873
> **** h1 0.0 setenv(my_frontend_fd, 6)
> **** h1 0.0 conf| global
> **** h1 0.0 conf|\tstats socket /tmp/vtc.68714.16672579/h1/stats.sock
> level admin mode 600
> **** h1 0.0 conf| stats socket "fd@${cli}" level admin
> **** h1 0.0 conf|
> **** h1 0.0 conf| # Configuration file of 'h1' haproxy instance.
> **** h1 0.0 conf| defaults
> **** h1 0.0 conf| mode http
> **** h1 0.0 conf| timeout connect 5s
> **** h1 0.0 conf| timeout server 30s
> **** h1 0.0 conf| timeout client 30s
> **** h1 0.0 conf|option http-use-htx
> **** h1 0.0 conf|
> **** h1 0.0 conf| frontend http1
> **** h1 0.0 conf| bind "fd@${my_frontend_fd}"
> **** h1 0.0 conf| stick-table size 1k expire 1ms type ip store
> conn_rate(10s),http_req_cnt,http_err_cnt,http_req_rate(10s),http_err_rate(10s),gpc0,gpc0_rate(10s),gpt0
> **** h1 0.0 conf| http-request track-sc0 req.hdr(X-Forwarded-For)
> **** h1 0.0 conf| http-request redirect location
> https://127.0.0.1:41871/ if {
> req.hdr(X-Forwarded-For),table_http_req_cnt(http1) -m int lt 0 }
> **** h1 0.0 conf| http-request redirect location
> https://127.0.0.1:41871/ if { req.hdr(X-Forwarded-For),table_trackers(http1)
> -m int lt 0 }
> **** h1 0.0 conf| http-request redirect location
> https://127.0.0.1:41871/ if { req.hdr(X-Forwarded-For),in_table(http1) -m int
> lt 0 }
> **** h1 0.0 conf| http-request redirect location
> https://127.0.0.1:41871/ if {
> req.hdr(X-Forwarded-For),table_bytes_in_rate(http1) -m int lt 0 }
> **** h1 0.0 conf| http-request redirect location
> https://127.0.0.1:41871/ if {
> req.hdr(X-Forwarded-For),table_bytes_out_rate(http1) -m int lt 0 }
> **** h1 0.0 conf| http-request redirect location
> https://127.0.0.1:41871/ if { req.hdr(X-Forwarded-For),table_conn_cnt(http1)
> -m int lt 0 }
> **** h1 0.0 conf| http-request redirect location
> https://127.0.0.1:41871/ if { req.hdr(X-Forwarded-For),table_conn_cur(http1)
> -m int lt 0 }
> **** h1 0.0 conf| http-request redirect location
> https://127.0.0.1:41871/ if { req.hdr(X-Forwarded-For),table_conn_rate(http1)
> -m int lt 0 }
> **** h1 0.0 conf| http-request redirect location
> https://127.0.0.1:41871/ if { req.hdr(X-Forwarded-For),table_gpt0(http1) -m
> int lt 0 }
> **** h1 0.0 conf| http-request redirect location
> https://127.0.0.1:41871/ if { req.hdr(X-Forwarded-For),table_gpc0(http1) -m
> int lt 0 }
> **** h1 0.0 conf| http-request redirect location
> https://127.0.0.1:41871/ if { req.hdr(X-Forwarded-For),table_gpc0_rate(http1)
> -m int lt 0 }
> **** h1 0.0 conf| http-request redirect location
> https://127.0.0.1:41871/ if {
> req.hdr(X-Forwarded-For),table_http_err_cnt(http1) -m int lt 0 }
> **** h1 0.0 conf| http-request redirect location
> https://127.0.0.1:41871/ if {
> req.hdr(X-Forwarded-For),table_http_err_rate(http1) -m int lt 0 }
> **** h1 0.0 conf| http-request redirect location
> https://127.0.0.1:41871/ if {
> req.hdr(X-Forwarded-For),table_http_req_cnt(http1) -m int lt 0 }
> **** h1 0.0 conf| http-request redirect location
> https://127.0.0.1:41871/ if {
> req.hdr(X-Forwarded-For),table_http_req_rate(http1) -m int lt 0 }
> **** h1 0.0 conf| http-request redirect location
> https://127.0.0.1:41871/ if { req.hdr(X-Forwarded-For),table_kbytes_in(http1)
> -m int lt 0 }
> **** h1 0.0 conf| http-request redirect location
> https://127.0.0.1:41871/ if {
> req.hdr(X-Forwarded-For),table_kbytes_out(http1) -m int lt 0 }
> **** h1 0.0 conf| http-request redirect location
> https://127.0.0.1:41871/ if { req.hdr(X-Forwarded-For),table_server_id(http1)
> -m int lt 0 }
> **** h1 0.0 conf| http-request redirect location
> https://127.0.0.1:41871/ if { req.hdr(X-Forwarded-For),table_sess_cnt(http1)
> -m int lt 0 }
> **** h1 0.0 conf| http-request redirect location
> https://127.0.0.1:41871/ if { req.hdr(X-Forwarded-For),table_sess_rate(http1)
> -m int lt 0 }
> **** h1 0.0 conf| http-request redirect location
> https://127.0.0.1:41871/ if { req.hdr(X-Forwarded-For),table_trackers(http1)
> -m int lt 0 }
> **** h1 0.0 conf|
> ** h1 0.0 haproxy_start
> **** h1 0.0 opt_worker 0 opt_daemon 0 opt_check_mode 0
> **** h1 0.0 argv|exec haproxy -d -f /tmp/vtc.68714.16672579/h1/cfg
> **** h1 0.0 XXX 8 @586
> *** h1 0.0 PID: 68724
> **** h1 0.0 macro def h1_pid=68724
> **** h1 0.0 macro def h1_name=/tmp/vtc.68714.16672579/h1
> ** top 0.0 === client c1 -connect ${h1_my_frontend_fd_sock} {
> ** c1 0.0 Starting client
> ** c1 0.0 Waiting for client
> *** c1 0.0 Connect to ::1 41873
> *** c1 0.0 connected fd 7 from ::1 41874 to ::1 41873
> ** c1 0.0 === txreq -url "/" -hdr "X-Forwarded-For: 127.0.0.1"
> **** c1 0.0 txreq|GET / HTTP/1.1\r
> **** c1 0.0 txreq|X-Forwarded-For: 127.0.0.1\r
> **** c1 0.0 txreq|Host: 127.0.0.1\r
> **** c1 0.0 txreq|\r
> ** c1 0.0 === rxresp
> *** h1 0.0 debug|Note: setting global.maxconn to 2000.
> *** h1 0.0 debug|Available polling systems :
> *** h1 0.0 debug| kqueue : pref=300, test result OK
> *** h1 0.0 debug|
> *** h1 0.0 debug| poll : pref=200, test result OK
> *** h1 0.0 debug| select : pref=150, test result FAILED
> *** h1 0.0 debug|Total: 3 (2 usable), will use kqueue.
> *** h1 0.0 debug|
> *** h1 0.0 debug|Available filters :
> *** h1 0.0 debug|\t[SPOE] spoe
> *** h1 0.0 debug|\t[COMP] compression
> *** h1 0.0 debug|\t[CACHE] cache
> *** h1 0.0 debug|\t[TRACE] trace
> *** h1 0.0 debug|Using kqueue() as the polling mechanism.
> *** h1 0.0 debug|00000000:http1.accept(0006)=000a from [::1:41874]
> ALPN=<none>
> *** h1 0.0 debug|00000000:http1.clireq[000a:ffffffff]: GET / HTTP/1.1
> *** h1 0.0 debug|00000000:http1.clihdr[000a:ffffffff]: x-forwarded-for:
> 127.0.0.1
> *** h1 0.0 debug|00000000:http1.clihdr[000a:ffffffff]: host: 127.0.0.1
> **** c1 0.0 rxhdr|HTTP/1.0 503 Service Unavailable\r
> **** c1 0.0 rxhdr|cache-control: no-cache\r
> **** c1 0.0 rxhdr|content-type: text/html\r
> **** c1 0.0 rxhdr|\r
> **** c1 0.0 rxhdrlen = 86
> **** c1 0.0 http[ 0] |HTTP/1.0
> **** c1 0.0 http[ 1] |503
> **** c1 0.0 http[ 2] |Service Unavailable
> **** c1 0.0 http[ 3] |cache-control: no-cache
> **** c1 0.0 http[ 4] |content-type: text/html
> **** c1 0.0 bodylen = 0
> ** c1 0.0 === expect resp.status == 503
> **** c1 0.0 EXPECT resp.status (503) == "503" match
> *** c1 0.0 closing fd 7
> ** c1 0.0 Ending
> ** top 0.0 === haproxy h1 -cli {
> ** h1 0.0 CLI starting
> ** h1 0.0 CLI waiting
> *** h1 0.0 CLI connected fd 7 from ::1 41875 to ::1 41872
> ** h1 0.0 === send "show table http1"
> **** h1 0.0 CLI send|show table http1
> ** h1 0.0 === expect ~ "table: http1, type: ip, size:1024,
> used:(0|1\\n0x[...
> *** h1 0.0 debug|00000001:GLOBAL.accept(0005)=000b from [::1:41875]
> ALPN=<none>
> **** h1 0.0 CLI connection normally closed
> *** h1 0.0 CLI closing fd 7
> *** h1 0.0 debug|00000001:GLOBAL.srvcls[adfd:ffffffff]
> *** h1 0.0 debug|00000001:GLOBAL.clicls[adfd:ffffffff]
> *** h1 0.0 debug|00000001:GLOBAL.closed[adfd:ffffffff]
> **** h1 0.0 CLI recv|# table: http1, type: ip, size:1024, used:1
> **** h1 0.0 CLI recv|0x8026612c0: key=127.0.0.1 use=1 exp=0 gpt0=0 gpc0=0
> gpc0_rate(10000)=0 conn_rate(10000)=1 http_req_cnt=1 http_req_rate(10000)=1
> http_err_cnt=0 http_err_rate(10000)=0
> **** h1 0.0 CLI recv|
> ---- h1 0.0 CLI expect failed ~ "table: http1, type: ip, size:1024,
> used:(0|1\n0x[0-9a-f]*: key=127\.0\.0\.1 use=0 exp=[0-9]* gpt0=0 gpc0=0
> gpc0_rate\(10000\)=0 conn_rate\(10000\)=1 http_req_cnt=1
> http_req_rate\(10000\)=1 http_err_cnt=0 http_err_rate\(10000\)=0)\n$"
> * top 0.0 RESETTING after ./htx-test/stick-table-b00001.vtc
> ** h1 0.0 Reset and free h1 haproxy 68724
> ** h1 0.0 Wait
> ** h1 0.0 Stop HAproxy pid=68724
> **** h1 0.0 Kill(2)=0: No error: 0
> **** h1 0.0 STDOUT poll 0x11
> ** h1 0.1 WAIT4 pid=68724 status=0x0002 (user 0.008195 sys 0.000000)
> ** s1 0.1 Waiting for server (3/-1)
> * top 0.1 TEST ./htx-test/stick-table-b00001.vtc FAILED
>
