Hi,

A few more details (replicated it a few more times). Here's curl output (with 
timestamps):

11:54:13.155873 *   Trying 2400:8902:e001:2df::1:443...
11:54:13.155994 * Connected to tiles.stadiamaps.com (2400:8902:e001:2df::1) 
port 443 (#0)
11:54:13.156419 * ALPN, offering h2
11:54:13.156434 * ALPN, offering http/1.1
11:54:13.169542 * successfully set certificate verify locations:
11:54:13.172037 *  CAfile: /etc/ssl/certs/ca-certificates.crt
11:54:13.173069 *  CApath: /etc/ssl/certs
11:54:13.174675 * TLSv1.3 (OUT), TLS handshake, Client hello (1):
11:54:13.176525 * TLSv1.3 (IN), TLS handshake, Server hello (2):
11:54:13.178153 * TLSv1.3 (IN), TLS handshake, Encrypted Extensions (8):
11:54:13.180422 * TLSv1.3 (IN), TLS handshake, Certificate (11):
11:54:13.182663 * TLSv1.3 (IN), TLS handshake, CERT verify (15):
11:54:13.185808 * TLSv1.3 (IN), TLS handshake, Finished (20):
11:54:13.186843 * TLSv1.3 (OUT), TLS change cipher, Change cipher spec (1):
11:54:13.187808 * TLSv1.3 (OUT), TLS handshake, Finished (20):
11:54:13.189628 * SSL connection using TLSv1.3 / TLS_AES_256_GCM_SHA384
11:54:13.190638 * ALPN, server accepted to use h2
11:54:13.191722 * Server certificate:
11:54:13.191998 *  subject: CN=*.stadiamaps.com
11:54:13.192218 *  start date: Jun  2 00:00:00 2023 GMT
11:54:13.192399 *  expire date: May  5 23:59:59 2024 GMT
11:54:13.192824 *  subjectAltName: host "tiles.stadiamaps.com" matched cert's 
"*.stadiamaps.com"
11:54:13.192994 *  issuer: C=GB; ST=Greater Manchester; L=Salford; O=Sectigo 
Limited; CN=Sectigo ECC Domain Validation Secure Server CA
11:54:13.193222 *  SSL certificate verify ok.
11:54:13.193434 * Using HTTP2, server supports multi-use
11:54:13.193875 * Connection state changed (HTTP/2 confirmed)
11:54:13.194032 * Copying HTTP/2 data in stream buffer to connection buffer 
after upgrade: len=0
11:54:13.195117 * Using Stream ID: 1 (easy handle 0x5626e427ead0)
11:54:13.204248 > GET /data/terrarium/17/0/1.png HTTP/2
11:54:13.204248 > Host: tiles.stadiamaps.com
11:54:13.204248 > user-agent: curl/7.74.0
11:54:13.204248 > accept: */*
11:54:13.204248 > referer: stadiamaps.com
11:54:13.204248 >
11:54:13.206071 * TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
11:54:13.206429 * TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
11:54:13.206971 * old SSL session ID is stale, removing
11:54:13.207292 * Connection state changed (MAX_CONCURRENT_STREAMS == 100)!
11:54:13.207864 < HTTP/2 404
11:54:13.208213 < date: Fri, 08 Sep 2023 11:54:07 GMT
11:54:13.208507 < content-type: application/xml
11:54:13.208654 < content-length: 239
11:54:13.208800 < stadia-cache: HIT
11:54:13.210078 < alt-svc: h3=":443";ma=900;
11:54:13.210248 < strict-transport-security: max-age=31536000; 
includeSubDomains; preload
11:54:13.210451 < stadia-entrypoint: tyo2-pop-g2-apket
11:54:13.210696 < stadia-property: 1
11:54:13.210981 < access-control-allow-origin: *
11:54:13.211202 < access-control-allow-headers: Stadia-Auth,Content-Type
11:54:13.211344 < access-control-allow-methods: GET,OPTIONS
11:54:13.211568 < x-robots-tag: noindex
11:54:13.211711 <
11:57:47.910425 * Connection #0 to host tiles.stadiamaps.com left intact
<?xml version="1.0" 
encoding="UTF-8"?><Error><Code>NoSuchKey</Code><RequestId>tx00000fda15e18e3cfd485-0064fb0b5f-485e3665-default</RequestId><HostId>485e3665-default-default</HostId></Error>

It appears that some timeout is hitting causing it to clear the buffer and 
succeed. Here's out timeout section:

 # connect [to a backend server]
 timeout connect      12400ms
 # wait for a full request [from a client]
 timeout http-request 9300ms
 # wait for any data from the server (time to first byte/header)
 timeout server          60s
 # wait for the client (keep-alive for h1.1, client for h1.1 & h2)
 timeout http-keep-alive  3m
 timeout client           3m

Could the relatively long period (10s) + high limit (50m) be resulting in 
freq_ctr_remain_period or freq_ctr_overshoot_period returning sometime odd? 
I've tried to understand those functions, but I'm still a little bit from fully 
understanding how everything works together.

Luke

—
Luke Seelenbinder
Stadia Maps | Founder & CEO
stadiamaps.com

> On Sep 8, 2023, at 13:42, Luke Seelenbinder 
> <luke.seelenbin...@stadiamaps.com> wrote:
> 
> Hi Christopher,
> 
> Thanks for the hint. I was able to replicate it and capture the following 
> from `show sess all`:
> 
> 0x562d78315da0: [08/Sep/2023:11:33:40.093147] id=32890 proto=tcpv4 
> source=<CLIENTIP>:34452
>   flags=0x100c4a, conn_retries=0, conn_exp=<NEVER> conn_et=0x000 
> srv_conn=0x562d77d74d60, pend_pos=(nil) waiting=0 epoch=0x3
>   frontend=stadiamaps (id=3 mode=http), listener=? (id=3) addr=<SRVIP>:443
>   backend=varnish (id=4 mode=http) addr=unix
>   server=varnish_local (id=1) addr=unix
>   task=0x562d781fba60 (state=0x00 nice=0 calls=2 rate=0 exp=38s tid=0(1/0) 
> age=21s)
>   txn=0x562d78373dc0 flags=0x843000 meth=1 status=404 req.st=MSG_DONE 
> rsp.st=MSG_DATA req.f=0x4c rsp.f=0x0d
>   scf=0x562d780c0fd0 flags=0x00002402 state=EST 
> endp=CONN,0x562d782bd030,0x05005001 sub=1 rex=2m38s wex=<NEVER>
>       h2s=0x562d782bd030 h2s.id=1 .st=HCR .flg=0x7001 .rxbuf=0@(nil)+0/0
>       .sc=0x562d780c0fd0(.flg=0x00002402 .app=0x562d78315da0) 
> .sd=0x562d78a50490(.flg=0x05005001)
>       .subs=0x562d780c0fe8(ev=1 tl=0x562d78655590 tl.calls=0 
> tl.ctx=0x562d780c0fd0 tl.fct=sc_conn_io_cb)
>       h2c=0x562d78843ea0 h2c.st0=FRH .err=0 .maxid=1 .lastid=-1 .flg=0x0200 
> .nbst=1 .nbsc=1
>       .fctl_cnt=0 .send_cnt=0 .tree_cnt=1 .orph_cnt=0 .sub=1 .dsi=0 
> .dbuf=0@(nil)+0/0
>       .mbuf=[1..1|32],h=[0@(nil)+0/0],t=[0@(nil)+0/0] .task=0x562d78f317f0 
> .exp=<NEVER>
>       co0=0x562d783e5d70 ctrl=tcpv4 xprt=SSL mux=H2 data=STRM 
> target=LISTENER:0x562d774e7ec0
>       flags=0x80000300 fd=209 fd.state=121 updt=0 fd.tmask=0x1
>   scb=0x562d78022fb0 flags=0x00001013 state=EST 
> endp=CONN,0x562d77fad040,0x05004001 sub=1 rex=38s wex=<NEVER>
>       h1s=0x562d77fad040 h1s.flg=0x4090 .sd.flg=0x5004001 .req.state=MSG_DONE 
> .res.state=MSG_DONE
>       .meth=GET status=404 .sd.flg=0x05004001 .sc.flg=0x00001013 
> .sc.app=0x562d78315da0
>       .subs=0x562d78022fc8(ev=1 tl=0x562d785fbbb0 tl.calls=2 
> tl.ctx=0x562d78022fb0 tl.fct=sc_conn_io_cb)
>       h1c=0x562d78f71f70 h1c.flg=0x80000000 .sub=0 .ibuf=0@(nil)+0/0 
> .obuf=0@(nil)+0/0 .task=0x562d78c95990 .exp=<NEVER>
>       co1=0x562d78955070 ctrl=unix_stream xprt=RAW mux=H1 data=STRM 
> target=SERVER:0x562d77d74d60
>       flags=0x00000300 fd=172 fd.state=120 updt=0 fd.tmask=0x1
>   req=0x562d78315dc0 (f=0x20848000 an=0x48000 pipe=0 tofwd=0 total=158)
>       an_exp=<NEVER> buf=0x562d78315dc8 data=(nil) o=0 p=0 i=0 size=0
>       htx=0x562d7641d860 flags=0x0 size=0 data=0 used=0 wrap=NO extra=0
>   res=0x562d78315e10 (f=0xa0040000 an=0x24000000 pipe=0 tofwd=0 total=498)
>       an_exp=1m41s buf=0x562d78315e18 data=0x562d78a25f50 o=0 p=0 i=16384 
> size=16384
>       htx=0x562d78a25f50 flags=0x14 size=16336 data=301 used=1 wrap=NO extra=0
> 
> Anything obvious to you? The data size is 301 bytes and it just hangs after 
> receiving headers for a few seconds (more than 6, but I'm not sure exactly 
> how many). It seems to flush the buffer as soon as some timeout triggers.
> 
> I'm still on 2.8.2, and based on what you said, it shouldn't matter for this .
> 
> Best,
> Luke
> 
> —
> Luke Seelenbinder
> Stadia Maps | Founder & CEO
> stadiamaps.com
> 
>> On Sep 7, 2023, at 15:40, Christopher Faulet <cfau...@haproxy.com> wrote:
>> 
>> Le 07/09/2023 à 14:52, Luke Seelenbinder a écrit :
>>> Could this fix:
>>> > BUG/MEDIUM: h1-htx: Ensure chunked parsing with full output buffer
>>> have caused this issue with bwlim? I was only able to replicate the 
>>> behavior in HTTP/1.1.
>> 
>> If your responses are chunked, it is possible. But only for responses 
>> exceeding the buffer size. A "show sess all" may help to diagnose the bug.
>> 
>> -- 
>> Christopher Faulet
>> 
> 

Reply via email to