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 > <[email protected]> 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 <[email protected]> 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 >> >
