Hi,
William Edwards schreef op 2022-08-06 17:41:
Igor Cicimov schreef op 2022-08-04 01:46:
Because of keep-alive?
Disabling keepalive on the server side using `option
http-server-close` fixes the issue. I've yet to figure out why.
The connections with which this issue occurs are always in FIN_WAIT2
("Connection is closed, and the socket is waiting for a shutdown from
the remote end.") on the backend server, and in CLOSE_WAIT ("The remote
end has shut down, waiting for the socket to close.") on the HAProxy
side. The connections on both sides are shut down within 25 to 30
seconds (before /proc/sys/net/ipv4/tcp_fin_timeout). HAProxy does wait
until `timeout server` before terminating the request. Could it be that
the active close is delayed due to a bug?
Here is a dump of a session with this issue:
```
root@lb0-1:~# haproxyctl show sess
0x7f13c4030020: proto=tcpv4 src=185.233.175.144:54656 fe=fr_other
be=bk_http.kls srv=http-kls03.vk.ha.cyberfusion.cloud ts=00 age=44s
calls=6 rate=0 cpu=0 lat=0 rq[f=498400a0h,i=0,an=8000h,rx=,wx=,ax=]
rp[f=80040000h,i=0,an=4000000h,rx=4m16s,wx=,ax=]
s0=[8,290008h,fd=35,ex=] s1=[8,200118h,fd=36,ex=] exp=4m16s
root@lb0-1:~# haproxyctl show sess 0x7f13c4030020
0x7f13c4030020: [08/Aug/2022:15:41:12.450130] id=14094 proto=tcpv4
source=185.233.175.144:54656
flags=0xc4e, conn_retries=3, srv_conn=0x560d53757c60, pend_pos=(nil)
waiting=0
frontend=fr_other (id=5 mode=http), listener=? (id=2)
addr=185.233.175.132:443
backend=bk_http.kls (id=15 mode=http) addr=10.40.7.10:58770
server=http-kls03.vk.ha.cyberfusion.cloud (id=1) addr=10.40.7.13:80
task=0x7f13c4037eb0 (state=0x00 nice=0 calls=6 rate=0 exp=4m8s
tmask=0x2 age=52s)
txn=0x7f13c4036ba0 flags=0x3000 meth=1 status=200 req.st=MSG_DONE
rsp.st=MSG_DATA req.f=0x4e rsp.f=0x0e
si[0]=0x7f13c40302c8 (state=EST flags=0x290008 endp0=CS:0x7f13c40285b0
exp=<NEVER> et=0x000 sub=0)
si[1]=0x7f13c4030320 (state=EST flags=0x200118 endp1=CS:0x7f13c401f9e0
exp=<NEVER> et=0x000 sub=1)
co0=0x7f13c4030890 ctrl=tcpv4 xprt=SSL mux=H1 data=STRM
target=LISTENER:0x560d52929730
flags=0x80043300 fd=35 fd.state=22 updt=0 fd.tmask=0x2
cs=0x7f13c40285b0 csf=0x0000d000 ctx=0x7f13c401fa30
co1=0x7f13c401fd60 ctrl=tcpv4 xprt=RAW mux=H1 data=STRM
target=SERVER:0x560d53757c60
flags=0x00003300 fd=36 fd.state=22 updt=0 fd.tmask=0x2
cs=0x7f13c401f9e0 csf=0x00000000 ctx=0x7f13c401f760
req=0x7f13c4030030 (f=0x498400a0 an=0x8000 pipe=0 tofwd=0 total=124)
an_exp=<NEVER> rex=<NEVER> wex=<NEVER>
buf=0x7f13c4030038 data=(nil) o=0 p=0 i=0 size=0
htx=0x560d50a5e7c0 flags=0x0 size=0 data=0 used=0 wrap=NO extra=0
res=0x7f13c4030090 (f=0x80040000 an=0x4000000 pipe=0 tofwd=-1
total=5199)
an_exp=<NEVER> rex=4m8s wex=<NEVER>
buf=0x7f13c4030098 data=(nil) o=0 p=0 i=0 size=0
htx=0x560d50a5e7c0 flags=0x0 size=0 data=0 used=0 wrap=NO extra=0
```
P.S. doc/management.txt says:
show sess <id>
[...]
You may find a description of all fields
returned in src/dumpstats.c
... but these fields were moved away from src/dumpstats.c in commit
74c24fb071ed9b76e10e12c237d2e7d3ff4025d8. I'm not sure where to report
this issue.
-------------------------
From: William Edwards <[email protected]>
Sent: Thursday, 4 August 2022, 00:26
To: [email protected] <[email protected]>
Subject: Server timeouts since HAProxy 2.2
[You don't often get email from [email protected]. Learn why
this is important at https://aka.ms/LearnAboutSenderIdentification ]
Hi,
Two days ago, I upgraded my first production system from HAProxy
1.8.19
to 2.2.9. Since then, many HTTP requests are hitting the server
timeout.
Before upgrade:
root@lb0-0:~# zgrep 'sD--' /var/log/haproxy.log.5.gz | wc -l
0
root@lb0-0:~# zgrep 'sD--' /var/log/haproxy.log.4.gz | wc -l
0
root@lb0-0:~# zgrep 'sD--' /var/log/haproxy.log.3.gz | wc -l
0
After upgrade:
# Day of upgrade
root@lb0-0:~# zgrep 'sD--' /var/log/haproxy.log.2.gz | wc -l
3798
# Yesterday
root@lb0-0:~# grep 'sD--' /var/log/haproxy.log.1 | wc -l
127176
# Today, so far
root@lb0-0:~# grep 'sD--' /var/log/haproxy.log | wc -l
85063
For this specific request, Ta ("total active time for the HTTP
request")
is 3, and Tt ("total TCP session duration time, between the moment the
proxy accepted it and the moment both ends were closed") is 300004 (5
minutes, the server timeout):
Aug 3 00:31:05 lb0-0 haproxy[16884]: $ip:62223
[03/Aug/2022:00:26:05.337] fr_other~
bk_http.lyr_http-lyr02.cf.ha.cyberfusion.cloud/http-lyr02.cf.ha.cyberfusion.cloud
0/0/0/3/300004 200 27992 - - sD-- 616/602/226/226/0 0/0 "GET
https://$domain/wp-content/uploads/2022/07/20220712_155022-300x300.jpg
HTTP/2.0"
The backend server indeed served the request within Ta:
$domain $ip - - [03/Aug/2022:00:26:05 +0200] "GET
/wp-content/uploads/2022/07/20220712_155022-300x300.jpg HTTP/1.1" 200
28008 "https://$domain/stoffen/"; "Mozilla/5.0 (Windows NT 10.0; Win64;
x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/103.0.0.0
Safari/537.36"
The timeouts only occur with 5 out of 13 backends. There is no clear
pattern, i.e. the timeouts don't come in bursts, and they aren't
caused
by fixed clients.
Does anyone know why the TCP session is kept open, and the HTTP
request
is not responded to by HAProxy after the backend server responded to
the
HTTP request, but only after the server timeout is reached?
--
With kind regards,
William Edwards
Know Your Customer due diligence on demand, powered by intelligent
process automation
Blogs [1] | LinkedIn [2] | Twitter [3]
Encompass Corporation UK Ltd | Company No. SC493055 | Address: Level
3, 33 Bothwell Street, Glasgow, UK, G2 6NL
Encompass Corporation Pty Ltd | ACN 140 556 896 | Address: Level 10,
117 Clarence Street, Sydney, New South Wales, 2000
Encompass Corporation US Ltd | Company No. 7946259 | Address: 5th
floor, 1460 Broadway, New York, New York, 10036
This email and any attachments is intended only for the use of the
individual or entity named above and may contain confidential
information
If you are not the intended recipient, any dissemination, distribution
or copying of this email is prohibited.
If received in error, please notify us immediately by return email and
destroy the original message.
Links:
------
[1] https://www.encompasscorporation.com/blog/
[2] https://www.linkedin.com/company/encompass-corporation/
[3] https://twitter.com/EncompassCorp
--
With kind regards,
William Edwards
