Hey Willy,
this morning I was running another test without kqueue but sadly with
the same result. Here is my test protocol:
Running fine with nokqueue for about an hour at about 20% CPU per
process, then sudden CPU spike on all processes up to 90%, I started
ktrace but meanwhile the CPU went back to around 33% on each process
[2]. Then after 10 more minutes 3 of the 8 haproxy processes died with a
segfault.
kernel: pid 3963 (haproxy), uid 0: exited on signal 11 (core dumped)
Unfortunately the coredump [1] is not that expressive even with compiled
debug symbols.
The remaining 5 processes survived another 10 minutes before they ramped
up cpu again - this time up to 100%. I have created a ktrace in this
state before reaching the 100%. [3]
When they were at 100% and not accepting any requests anymore I took
another ktrace sample but _nothing_ was written to the output anymore!
That means in this state no syscalls where happening anymore? I also
took a full ktrace sample with IO and everything - it was empty as well.
So it seems unrelated to kqueue as well. Later I will try to run the
test with a fraction of the traffic without nbproc (all the traffic is
too much for one process)
You can find the coredump and the traces here:
[1] http://smyck.org/haproxy/haproxy_coredump_freebsd_poll.txt
[2] http://smyck.org/haproxy/haproxy_ktrace_poll_01_30_percent.txt
[3]
http://smyck.org/haproxy/haproxy_krace_poll_remaining_processes_ramping_up_cpu.txt
I hope that already helps to narrow it down a bit.
Kind regards,
John
Willy Tarreau wrote:
Hi John-Paul,
On Tue, May 06, 2014 at 11:57:08PM +0200, John-Paul Bader wrote:
Hey,
I will do more elaborate test runs in the next couple of days.
No problem.
I will
create traces with ktrace which is not as nice as strace but at least
will provide more context. Is there anything in particular you'd be
interested in like only syscalls?
I tend to think that syscalls should tell us what's happening. Indeed,
FreeBSD and Linux are both modern operating systems and quite close,
so in general, what works on one of them works on the other one without
any difficulty. The only differences here might be :
- kqueue vs epoll
- specific return value of a syscall that we don't handle properly
(eg: we had a few ENOTCONN vs EAGAIN issues in the past)
Meanwhile I have build haproxy with debug symbols but in the tests I ran
today, haproxy did not coredump but only went for the 100% CPU way of
failing where I had to kill it manually. This happened with httpclose
and with keep-alive so I'd say the problem is not really related to that.
I'm not surprized. If the OS makes a difference, it's in the lower layers,
so what close vs keep-alive may do is only hint the problem to happen more
often.
What I'm thinking about is that it's possible that we don't always properly
consider an error on a file descriptor, then we don't remove it properly
from the list of polled FDs, and that it might be returned by the poller
as active when we think it's closed. At this point, everything can happen :
- loop forever because we get an error when trying to access this fd
and we can't remove it from the polled fd list ;
- crash when we try to dereference the connection which is attached
to this fd.
Its so sad because before the CPU load suddenly risees, and
requests/connections aren't handled anymore haproxy performs so well and
effortless.
Also, if I can help by providing access to a FreeBSD machine, just let
me know. I have plenty :)
At some point it could be useful, especially if we manage to reproduce
the problem on a test platform.
If you have any other idea apart from ktrace, coredumps to make
troubleshooting more effective I'd be more than happy to help.
There's something you can try to see if it's related to what I suspect
above. If you apply this patch and it crashes earlier, it definitely
means that we're having a problem with an fd which is reported after
being closed :
diff --git a/src/connection.c b/src/connection.c
index 1483f18..27bb6c5 100644
--- a/src/connection.c
+++ b/src/connection.c
@@ -44,7 +44,7 @@ int conn_fd_handler(int fd)
unsigned int flags;
if (unlikely(!conn))
- return 0;
+ abort();
conn_refresh_polling_flags(conn);
flags = conn->flags& ~CO_FL_ERROR; /* ensure to call the wake handler
upon error */
If this happens, retry without kqueue, it will use poll and the issue
should not appear, or we have a bigger bug.
Regards,
Willy
--
John-Paul Bader | Software Development
www.wooga.com
wooga GmbH | Saarbruecker Str. 38 | D-10405 Berlin
Sitz der Gesellschaft: Berlin; HRB 117846 B
Registergericht Berlin-Charlottenburg
Geschaeftsfuehrung: Jens Begemann, Philipp Moeser
