Le 08/09/2023 à 13:42, Luke Seelenbinder a écrit :
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 .
Indeed, it is not related to any fixed bug.
The response "an_exp" expiration date is quite huge (1m41s). But I didn't notice
it at first. You have configured 2 bwlim-out filters to use the same table with
different limits. So I guess it is possible to block some streams for a while if
its rate exceeds the first limit (50m on 10s) because the same source address is
already limited by the second limit (100m on 10s).
This kind of configuration cannot work.
--
Christopher Faulet
