[Bug 193] New: syslog-ng 3.3. 6 spins at 100% on FreeBSD with spoof-source compiled in
https://bugzilla.balabit.com/show_bug.cgi?id=193 Summary: syslog-ng 3.3.6 spins at 100% on FreeBSD with spoof- source compiled in Product: syslog-ng Version: 3.3.x Platform: PC OS/Version: FreeBSD Status: ASSIGNED Severity: normal Priority: unspecified Component: syslog-ng AssignedTo: algernon@balabit.hu ReportedBy: algernon@balabit.hu Type of the Report: regression Estimated Hours: 0.0 With the default syslog-ng.conf on FreeBSD, syslog-ng 3.3.6 will spin at 100% CPU when spoof source is enabled. 3.3.5 did not have this problem, neither does it happen with --disable-spoof-source, and by all accounts, this is a problem in syslog-ng, so a lib/ivykis upgrade will not help. -- Configure bugmail: https://bugzilla.balabit.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.
https://bugzilla.balabit.com/show_bug.cgi?id=193 Gergely Nagy <algernon@balabit.hu> changed: What |Removed |Added ---------------------------------------------------------------------------- Target Milestone|--- |3.3.7 -- Configure bugmail: https://bugzilla.balabit.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.
https://bugzilla.balabit.com/show_bug.cgi?id=193 Peter Czanik <czanik@balabit.hu> changed: What |Removed |Added ---------------------------------------------------------------------------- CC| |czanik@balabit.hu --- Comment #1 from Peter Czanik <czanik@balabit.hu> 2012-09-03 11:58:36 --- It also spins at 100% CPU, when spoof source is disabled. Tested on FreeBSD 8.1 and 9.0 with 3.3.6 release, 3.3.6 HEAD. Disabled spoof source was tested using the patch from bug #192 -- Configure bugmail: https://bugzilla.balabit.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.
https://bugzilla.balabit.com/show_bug.cgi?id=193 Gergely Nagy <algernon@balabit.hu> changed: What |Removed |Added ---------------------------------------------------------------------------- Summary|syslog-ng 3.3.6 spins at |syslog-ng 3.3.6 spins at |100% on FreeBSD with spoof- |100% on FreeBSD |source compiled in | --- Comment #2 from Gergely Nagy <algernon@balabit.hu> 2012-09-03 12:04:41 --- (In reply to comment #1)
It also spins at 100% CPU, when spoof source is disabled. Tested on FreeBSD 8.1 and 9.0 with 3.3.6 release, 3.3.6 HEAD. Disabled spoof source was tested using the patch from bug #192
Right. That's what I 'found' too: with an internal() and udp() source (spoof-source enabled), I see no spin. I suspect it's one of the other stuff in the default src source that misbehaves. -- Configure bugmail: https://bugzilla.balabit.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.
https://bugzilla.balabit.com/show_bug.cgi?id=193 --- Comment #3 from Gergely Nagy <algernon@balabit.hu> 2012-09-03 12:40:58 --- With many help from Peter Czanik, we arrived to the conclusion that either -F or -d stops syslog-ng from spinning. If both are missing, it will spin on FreeBSD. The same is not true on Linux, however. I'll try bisecting it, and see where that leads. -- Configure bugmail: https://bugzilla.balabit.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.
https://bugzilla.balabit.com/show_bug.cgi?id=193 Lennert Buytenhek <buytenh@wantstofly.org> changed: What |Removed |Added ---------------------------------------------------------------------------- CC| |buytenh@wantstofly.org --- Comment #4 from Lennert Buytenhek <buytenh@wantstofly.org> 2012-09-03 19:32:07 --- This turns out to be (another!) ivykis bug: iv_signal uses a spinlock to protect its process-wide state, but uses a PTHREAD_PROCESS_PRIVATE spinlock instead of a PTHREAD_PROCESS_SHARED one, which screws up when iv_signal's atfork handlers are called, and the child's spinlock ends up corrupt after the fork(). I have a fix that I'll commit to ivykis HEAD and stable-v0.30 once you let me know whom to credit the discovery of this issue to. -- Configure bugmail: https://bugzilla.balabit.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.
https://bugzilla.balabit.com/show_bug.cgi?id=193 Cy Schubert <cy@FreeBSD.org> changed: What |Removed |Added ---------------------------------------------------------------------------- CC| |cy@FreeBSD.org --- Comment #5 from Cy Schubert <cy@FreeBSD.org> 2012-09-03 19:55:21 --- Cy Schubert (cy@FreeBSD.org) here. I did try it with -d and -F (separately and together). It looped. I then performed the same under gdb and my results are as follows: ^C (gdb) bt #0 0x342263bb in kevent () from /lib/libc.so.7 #1 0x33cb7d8f in iv_kqueue_poll (st=0x35857500, active=0x7fbfe944, to=0x7fbfe93c) at iv_method_kqueue.c:150 #2 0x33cb77dd in iv_main () at iv_main.c:275 #3 0x33c9bfb2 in main_loop_run () at mainloop.c:735 #4 0x0804928a in main (argc=1, argv=0x7fbfea0c) at main.c:262 (gdb) c Continuing. ^C Program received signal SIGINT, Interrupt. 0x342263bb in kevent () from /lib/libc.so.7 (gdb) bt #0 0x342263bb in kevent () from /lib/libc.so.7 #1 0x33cb7d8f in iv_kqueue_poll (st=0x35857500, active=0x7fbfe944, to=0x7fbfe93c) at iv_method_kqueue.c:150 #2 0x33cb77dd in iv_main () at iv_main.c:275 #3 0x33c9bfb2 in main_loop_run () at mainloop.c:735 #4 0x0804928a in main (argc=1, argv=0x7fbfea0c) at main.c:262 (gdb) I haven't had a chance to look at the code yet but a spin-lock seems to make sense. -- Configure bugmail: https://bugzilla.balabit.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.
https://bugzilla.balabit.com/show_bug.cgi?id=193 --- Comment #6 from Lennert Buytenhek <buytenh@wantstofly.org> 2012-09-03 20:01:49 --- The parent process blocks in kevent(), this is expected. The 100% CPU problem is in the child process, which runs with a broken spinlock after the iv_signal atfork handlers run. Try s/PTHREAD_PROCESS_PRIVATE/PTHREAD_PROCESS_SHARED/ on lib/ivykis/modules/iv_signal.c and rebuilding. -- Configure bugmail: https://bugzilla.balabit.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.
https://bugzilla.balabit.com/show_bug.cgi?id=193 --- Comment #7 from Lennert Buytenhek <buytenh@wantstofly.org> 2012-09-03 20:03:48 --- Sorry, I mean lib/ivykis/modules/spinlock.h. :-) -- Configure bugmail: https://bugzilla.balabit.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.
https://bugzilla.balabit.com/show_bug.cgi?id=193 --- Comment #8 from Gergely Nagy <algernon@balabit.hu> 2012-09-03 23:02:23 --- (In reply to comment #6)
The parent process blocks in kevent(), this is expected. The 100% CPU problem is in the child process, which runs with a broken spinlock after the iv_signal atfork handlers run. Try s/PTHREAD_PROCESS_PRIVATE/PTHREAD_PROCESS_SHARED/ on lib/ivykis/modules/iv_signal.c and rebuilding.
I just did that on spinlock.h, and the spin's gone. I haven't done further testing yet, though. -- Configure bugmail: https://bugzilla.balabit.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.
https://bugzilla.balabit.com/show_bug.cgi?id=193 --- Comment #9 from Lennert Buytenhek <buytenh@wantstofly.org> 2012-09-04 05:43:27 --- I have committed the fix to the ivykis master and stable-v0.30 branches. I'll release 0.30.3 by the end of this week or so if nothing else pops up before that time. -- Configure bugmail: https://bugzilla.balabit.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.
On Tue, Sep 04, 2012 at 05:43:28AM +0200, bugzilla@bugzilla.balabit.com wrote:
--- Comment #9 from Lennert Buytenhek <buytenh@wantstofly.org> 2012-09-04 05:43:27 --- I have committed the fix to the ivykis master and stable-v0.30 branches. I'll release 0.30.3 by the end of this week or so if nothing else pops up before that time.
This is the fix I committed to stable-v0.30: commit 84963e1987d38bd8c77dd74dcacdfe9344fc0fe8 Author: Lennert Buytenhek <buytenh@wantstofly.org> Date: Mon Sep 3 19:01:27 2012 +0200 spinlock.h: Use PTHREAD_PROCESS_SHARED for pthread-backed spinlocks. iv_signal maintains an AVL tree of registered signal interests, which is protected from concurrent modifications as well as from lookup versus modification races by a spinlock. To be able to reset the disposition of each signal for which there is an iv_signal object registered back to SIG_DFL in the child process after fork(), we have to walk the AVL tree from the child process, but this requires that the child sees a consistent version of the AVL tree, and that requires that we don't add or remove signal interests in one thread while calling fork() in another thread in the parent process. To guarantee the consistency of the AVL tree data structure across fork() calls, iv_signal registers atfork handlers which lock the spinlock in the parent process before the fork() happens, and unlock the spinlock in both the parent process and the child process after the fork() completes. However, for this to work properly, the spinlock that iv_signal uses must be initialized as a shared spinlock (PTHREAD_PROCESS_SHARED) instead of as a process private spinlock (PTHREAD_PROCESS_PRIVATE) as is done currently. This trips up at least FreeBSD, as FreeBSD's libpthread apparently has different implementations for process private spinlocks and shared spinlocks, and trying to lock an unlocked process private spinlock in a fork()ed child process causes the child to go into an infinite loop. Fix this by having spinlock.h initialize pthread spinlocks as shared spinlocks. This was showing up as an issue on FreeBSD builds of syslog-ng. Reported-by: Cy Schubert <cy@FreeBSD.org> Tested-by: Gergely Nagy <algernon@balabit.hu> Signed-off-by: Lennert Buytenhek <buytenh@wantstofly.org> diff --git a/modules/spinlock.h b/modules/spinlock.h index 1978317..6451f85 100644 --- a/modules/spinlock.h +++ b/modules/spinlock.h @@ -25,7 +25,7 @@ static inline void spin_init(spinlock_t *lock) { - pthread_spin_init(lock, PTHREAD_PROCESS_PRIVATE); + pthread_spin_init(lock, PTHREAD_PROCESS_SHARED); } static inline void spin_lock(spinlock_t *lock)
https://bugzilla.balabit.com/show_bug.cgi?id=193 Gergely Nagy <algernon@balabit.hu> changed: What |Removed |Added ---------------------------------------------------------------------------- Resolution| |FIXED Status|ASSIGNED |RESOLVED --- Comment #10 from Gergely Nagy <algernon@balabit.hu> 2012-09-04 20:03:32 --- Updated the lib/ivykis submodule to point to the head of stable-v0.30, which has Lennert's fix. Closing this, will be in 3.3.7. -- Configure bugmail: https://bugzilla.balabit.com/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are watching all bug changes.
participants (2)
-
bugzilla@bugzilla.balabit.com
-
Lennert Buytenhek