[Bug libc/671] New: It appears syslog can go into deadlock when it receives a signal where the signal handler also syslogs

["b dot lomas at auckland dot ac dot nz" <sourceware-bugzilla@sources.redhat.com>]

I had a program which seemed unresponsive. So I attached GDB to it and got the
following stack strace:
#0  0x00a7e579 in __lll_mutex_lock_wait () from /lib/tls/libc.so.6
#1  0x00a6d955 in _L_mutex_lock_328 () from /lib/tls/libc.so.6
#2  0x093979f8 in ?? ()
#3  0x0805322f in _IO_stdin_used ()
#4  0xbfff90cc in ?? ()
#5  0xbfff9064 in ?? ()
#6  0x00ac79a0 in map () from /lib/tls/libc.so.6
#7  0x00000000 in ?? ()
#8  0x00000000 in ?? ()
#9  0x00000000 in ?? ()
#10 0xbfff8f04 in ?? ()
#11 0x00000000 in ?? ()
#12 0x00000000 in ?? ()
#13 0x0000006e in ?? ()
#14 0x00000014 in ?? ()
#15 0x00000001 in ?? ()
#16 0x09397c88 in ?? ()
#17 0x00000000 in ?? ()
#18 0x41e9970f in ?? ()
#19 0x09397c88 in ?? ()
#20 0x0000003d in ?? ()
#21 0x00a6d8f0 in sigpipe_handler () from /lib/tls/libc.so.6
#22 0x00a6ceef in syslog () from /lib/tls/libc.so.6
#23 0x0804d519 in pusherchld (sig=17) at pusher.c:212
#24 <signal handler called>
#25 0x00a71e8a in send () from /lib/tls/libc.so.6
#26 0x00a6d2a2 in vsyslog () from /lib/tls/libc.so.6
#27 0x00a6ceef in syslog () from /lib/tls/libc.so.6
#28 0x0804d8ef in pusherparent (ppipe=5, gconf=0x9395890) at pusher.c:355
#29 0x0804a821 in main (ac=1024, av=0x1) at daemon.c:465


It appears that while syslog was attempting to send it got a SIGCHLD signal,
which also syslogs.

I have a trivial program (below) which reproduces the problem more often than
not with the follow stack trace:
#0  0x0042be09 in __lll_mutex_lock_wait () from /lib/tls/libc.so.6
#1  0x0041b1b5 in _L_mutex_lock_328 () from /lib/tls/libc.so.6
#2  0x09eaa008 in ?? ()
#3  0x08048808 in _IO_stdin_used ()
#4  0xbfffb258 in ?? ()
#5  0xbfffb1f4 in ?? ()
#6  0x004743a0 in map () from /lib/tls/libc.so.6
#7  0x00000000 in ?? ()


The program is:
#include <stdio.h>
#include <syslog.h>
#include <stdlib.h>
#include <signal.h>
 
 
void
sigchldHandler(int sig)
{
        syslog(LOG_INFO,"Child %d died!!\n",getpid());
}
 
#define SLEEP_MAX 20.0
void
child()
{
        int usecsleep;
        srand(time(NULL)+getpid());
         
        usecsleep=1+(int) (SLEEP_MAX*rand()/(RAND_MAX+1.0));
 
        usleep(usecsleep);
}
 
#define CHILDREN 50
#define NUM_SYSLOGS 1000
 
int
main(int argc,char **argv)
{
        pid_t pids[CHILDREN];
        int i;
 
        signal(SIGCHLD,sigchldHandler);
 
        for(i=0;i<CHILDREN;i++)
        {
                switch((pids[i]=fork()))
                {
                        case 0:
                                child();
                                exit(0);
                        case -1:
                                fprintf(stderr,"Failed fork\n");
                                exit(1);
                }
        }
 
        for(i=0;i<NUM_SYSLOGS;i++)
                syslog(LOG_INFO,"parent: hello!");
 
        for(i=0;i<CHILDREN;i++)
                waitpid(pids[i],NULL,0);
 
        return 0;
}

Thanks

-- 
           Summary: It appears syslog can go into deadlock when it receives
                    a signal where the signal handler also syslogs
           Product: glibc
           Version: 2.3.2
            Status: NEW
          Severity: normal
          Priority: P2
         Component: libc
        AssignedTo: gotom at debian dot or dot jp
        ReportedBy: b dot lomas at auckland dot ac dot nz
                CC: glibc-bugs at sources dot redhat dot com


http://sources.redhat.com/bugzilla/show_bug.cgi?id=671

------- You are receiving this mail because: -------
You are on the CC list for the bug, or are watching someone who is.