Hi Patrick,
First thank you for this nice and helpful report.
Would it be possible to have an output of this command the next time you
reproduce such an issue please?
echo "show sess" | socat stdio <haproxy stats socket path>
I have only one question (see below).
On 05/24/2017 10:40 AM, Willy Tarreau wrote:
Hi Patrick,
On Tue, May 23, 2017 at 01:49:42PM -0400, Patrick Hemmer wrote:
(...)
haproxy 28856 root 1u IPv4 420797940 0t0 TCP
10.0.33.145:35754->10.0.33.147:1029 (CLOSE_WAIT)
haproxy 28856 root 2u IPv4 420266351 0t0 TCP
10.0.33.145:52898->10.0.33.147:1029 (CLOSE_WAIT)
haproxy 28856 root 3r REG 0,3 0 4026531956 net
haproxy 28856 root 4u IPv4 422150834 0t0 TCP
10.0.33.145:38874->10.0.33.147:1029 (CLOSE_WAIT)
These ones are very interesting.
These traces also seem interesting to me.
# strace -p 28856
Process 28856 attached
epoll_wait(0, {}, 200, 319) = 0
epoll_wait(0, {}, 200, 0) = 0
epoll_wait(0, {}, 200, 362) = 0
epoll_wait(0, {}, 200, 0) = 0
epoll_wait(0, {}, 200, 114) = 0
epoll_wait(0, {}, 200, 0) = 0
epoll_wait(0, {}, 200, 203) = 0
epoll_wait(0, {}, 200, 0) = 0
epoll_wait(0, {}, 200, 331) = 0
epoll_wait(0, {}, 200, 0)
Were such "epoll_wait(0, 0, 200, 0)" calls infinitively displayed?
In fact I am wondering if it is normal to have so much epoll_wait(0, {},
200, 0) calls for a haproxy process which has shut down.
I suspect they are in relation with peer tasks (obviously which has
expired).
If this is the case, and with configurations with only peer tasks,
haproxy would definitively hang consuming a lot of CPU resources.
So, I had a look at the peer struct task 'expire' member handling code,
and I have just found a situation where pollers in relation with peer
tasks are often called with an expired timeout leading haproxy to
consume a lot of CPU resources. In fact this happens each time the peer
task has expired during a fraction of second.
It is easy to reproduce this issue with a sort of peer simulator ;):
strace -ttf socat TCP4-LISTEN:<peer port>,reuseaddr,fork SYSTEM:"echo
200;sleep 10"
This peer must be started *before* the other remote haproxy process with
only peers as backends.
strace is here only to have an idea of the moment where the remote
haproxy peer has just connected.
The sleep command is here to have enough time to block (ctrl + s) our
peer simulator process after the haproxy peer has just connected.
So this peer accepts any remote peer sessions sending "200" status
messages (and that's all).
A haproxy peer which connects to such a peer which does not reply to a
synchronization request would endlessly consume high CPU ressources
until you unblock (ctrl + q) the peer simulator process.
*Unhappily, I do not see any relation between this bug and the
"CLOSE_WAIT peer state issue" which prevents haproxy from correctly
shutting down.*
I have attached a patch to this mail which fixes this issue.
Regards,
Fred.
>From 855635c42b89e25a52255dd5edc8c872e888656e Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Fr=C3=A9d=C3=A9ric=20L=C3=A9caille?= <[email protected]>
Date: Mon, 29 May 2017 13:47:16 +0200
Subject: [PATCH] BUG/MINOR: Wrong peer task expiration handling during
synchronization processing.
When a peer task has sent a synchronization request to remote peers
its next expiration date was updated based on a resynchronization timeout
value which itself may have already expired leading the underlying
poller to wait for 0ms during a fraction of second (consuming high CPU
resources).
With this patch we update such peer task expiration dates only if
the resynchronization timeout is not already expired.
Thanks to Patrick Hemmer who reported an issue with nice traces
which helped in finding this one.
This patch may be backported to 1.7 and 1.6.
---
src/peers.c | 5 +++--
1 file changed, 3 insertions(+), 2 deletions(-)
diff --git a/src/peers.c b/src/peers.c
index 0c8861f..0ebc040 100644
--- a/src/peers.c
+++ b/src/peers.c
@@ -1957,8 +1957,9 @@ static struct task *process_peer_sync(struct task * task)
if ((peers->flags & PEERS_RESYNC_STATEMASK) != PEERS_RESYNC_FINISHED) {
/* Resync not finished*/
- /* reschedule task to resync timeout, to ended resync if needed */
- task->expire = tick_first(task->expire, peers->resync_timeout);
+ /* reschedule task to resync timeout if not expired, to ended resync if needed */
+ if (!tick_is_expired(peers->resync_timeout, now_ms))
+ task->expire = tick_first(task->expire, peers->resync_timeout);
}
} /* !stopping */
else {
--
2.1.4
