Sophie - caught in the act

Howdy,

I have a truss of sophie (3.03) getting stuck.  I can forward the whole
thing to the list if there's somebody with enough C experience to look at
the code.  The truss shows thread #1 getting a SIGCLD in the accept, and
then never reentering it.  It ends up getting stuck in a sigsuspend()
doing...something.  I assume it's trying to reinstall/install a signal
handler, but the called function is never returning.

Failure:

26412/2:        3780.0345       signotifywait()                                 = 18
26412/2:        3780.0353       lwp_sigredirect(1, SIGCLD, 0xFEC0FC6C)          = 0
26412/2:                queued: 0
26412/1:        3780.0357           Received signal #18, SIGCLD, in accept() [caught]
26412/1:              siginfo: SIGCLD CLD_EXITED pid=20829 status=0x0000
26412/1:        3780.0360       accept(4, 0x00000000, 0x00000000, 1)            Err#91 ERESTART
26412/1:        3780.0379       sigprocmask(SIG_SETMASK, 0xFEEECFB8, 0x00000000) = 0
26412/1:                 set = 0 0 0 0
26412/1:        3780.0384       waitid(P_ALL, 0, 0xFFBEE6B0, WEXITED|WTRAPPED|WNOHANG) = 0
26412/1:              siginfo: SIGCLD CLD_EXITED pid=20829 status=0x0000
26412/1:        3780.0388       waitid(P_ALL, 0, 0xFFBEE6B0, WEXITED|WTRAPPED|WNOHANG) Err#10 ECHILD
26412/1:        3780.0391       sigprocmask(SIG_SETMASK, 0xFEEF8CE0, 0x00000000) = 0
26412/1:                 set = 0xFFBFFEFF 0x00001FFF 0 0
26412/1:        3780.0396       setcontext(0xFFBEE648)
26412/1:        3780.0399       alarm(0)                                        = 0
26412/1:        3780.0402       setitimer(ITIMER_REAL, 0xFFBEEC68, 0xFFBEEC58)  = 0
26412/1:                 value:  interval:    0.000000 sec  value:    0.000000 sec
26412/1:                ovalue:  interval:    0.000000 sec  value:    0.000000 sec
26412/1:        3780.0407       sigaction(SIGALRM, 0xFFBEEAE8, 0xFFBEEC18)      = 0
26412/1:            new: hand = 0xFEED7A14 mask = 0xFFBFFEFF 0x00001FFF 0 0 flags = 0x0008
26412/1:            old: hand = 0x00000001 mask = 0 0 0 0 flags = 0x0000
26412/1:        3780.0569       setitimer(ITIMER_REAL, 0xFFBEEC68, 0x00000000)  = 0
26412/1:                 value:  interval:    0.000000 sec  value: 0.000010 sec
26412/1:        3780.0765           Received signal #14, SIGALRM [caught]
26412/1:        3780.0776       sigprocmask(SIG_SETMASK, 0xFEEECFB8, 0x00000000) = 0
26412/1:                 set = 0 0 0 0
26412/1:        3780.0786       sigprocmask(SIG_SETMASK, 0xFEEF8CE0, 0x00000000) = 0
26412/1:                 set = 0xFFBFFEFF 0x00001FFF 0 0
26412/1:        3780.0804       setcontext(0xFFBEE5D8)
26412/1:        sigsuspend(0xFFBEEBE8)          (sleeping...)
26412/1:                sigmask = 0 0 0 0
26412/2:        signotifywait()                 (sleeping...)
26412/3:        lwp_cond_wait(0xFEEF34E8, 0xFEEF34F8, 0xFEEECD80) (sleeping...)
26412/3:                condvar type: USYNC_THREAD
26412/3:                mutex type: USYNC_THREAD
26412/3:                timeout: 300.000000000 sec
26412/3:        4079.5613       lwp_cond_wait(0xFEEF34E8, 0xFEEF34F8, 0xFEEECD80) Err#62 ETIME

A normal truss shows the thread falling through to the accept as you'd
expect:

26412/2:        3772.5941       signotifywait()                                 = 18
26412/2:        3772.5950       lwp_sigredirect(1, SIGCLD, 0xFEC0FC6C)          = 0
26412/2:                queued: 0
26412/1:        3772.5955           Received signal #18, SIGCLD, in accept() [caught]
26412/1:              siginfo: SIGCLD CLD_EXITED pid=20779 status=0x0000
26412/1:        3772.5958       accept(4, 0x00000000, 0x00000000, 1)            Err#91 ERESTART
26412/1:        3772.5963       sigprocmask(SIG_SETMASK, 0xFEEECFB8, 0x00000000) = 0
26412/1:                 set = 0 0 0 0
26412/1:        3772.5968       waitid(P_ALL, 0, 0xFFBEE6B0, WEXITED|WTRAPPED|WNOHANG) = 0
26412/1:              siginfo: SIGCLD CLD_EXITED pid=20779 status=0x0000
26412/1:        3772.5976       waitid(P_ALL, 0, 0xFFBEE6B0, WEXITED|WTRAPPED|WNOHANG) Err#10 ECHILD
26412/1:        3772.5982       sigprocmask(SIG_SETMASK, 0xFEEF8CE0, 0x00000000) = 0
26412/1:                 set = 0xFFBFFEFF 0x00001FFF 0 0
26412/1:        3772.5987       setcontext(0xFFBEE648)
26412/1:        3772.5990       alarm(0)                                        = 0
26412/1:        3772.5993       setitimer(ITIMER_REAL, 0xFFBEEC68, 0xFFBEEC58)  = 0
26412/1:                 value:  interval:    0.000000 sec  value:    0.000000 sec
26412/1:                ovalue:  interval:    0.000000 sec  value:    0.000000 sec
26412/1:        3772.5998       sigaction(SIGALRM, 0xFFBEEAE8, 0xFFBEEC18)      = 0
26412/1:            new: hand = 0xFEED7A14 mask = 0xFFBFFEFF 0x00001FFF 0 0 flags = 0x0008
26412/1:            old: hand = 0x00000001 mask = 0 0 0 0 flags = 0x0000
26412/1:        3772.6004       setitimer(ITIMER_REAL, 0xFFBEEC68, 0x00000000)  = 0
26412/1:                 value:  interval:    0.000000 sec  value:    0.000010 sec
26412/1:        3772.6114           Received signal #14, SIGALRM, in sigsuspend() [caught]
26412/1:        3772.6117       sigsuspend(0xFFBEEBE8)                          Err#4 EINTR
26412/1:                sigmask = 0 0 0 0
26412/1:        3772.6122       sigprocmask(SIG_SETMASK, 0xFEEECFB8, 0x00000000) = 0
26412/1:                 set = 0 0 0 0
26412/1:        3772.6126       sigprocmask(SIG_SETMASK, 0xFEEF8CE0, 0x00000000) = 0
26412/1:                 set = 0xFFBFFEFF 0x00001FFF 0 0
26412/1:        3772.6130       setcontext(0xFFBEE5D8)
26412/1:        3772.6145       sigaction(SIGALRM, 0xFFBEEAE8, 0x00000000)       = 0
26412/1:            new: hand = 0x00000001 mask = 0 0 0 0 flags = 0x0000
26412/1:        3772.6149       setitimer(ITIMER_REAL, 0xFFBEEC58, 0x00000000)  = 0
26412/1:                 value:  interval:    0.000000 sec  value:    0.000000 sec
26412/1:        accept(4, 0x00000000, 0x00000000, 1) (sleeping...)
26412/2:        signotifywait()                 (sleeping...)
26412/3:        lwp_cond_wait(0xFEEF34E8, 0xFEEF34F8, 0xFEEECD80) (sleeping...)
26412/3:                condvar type: USYNC_THREAD
26412/3:                mutex type: USYNC_THREAD
26412/3:                timeout: 300.000000000 sec
26412/1:        3779.5399       accept(4, 0x00000000, 0x00000000, 1)            = 5
26412/1:        3779.5455       fork1()                                         = 20829
20829/1:        3779.5455       fork1()         (returning as child ...)        = 26412

Careful examination shows the failed code is getting the SIGALRM at a
different place, so perhaps there's a race condition where the thread
doesn't fall out of the for(;;) loop in the code.

Anyone?

David.

----

PS, as a side note, I tried 3.04RC2, and it stopped working pretty
quickly.  Didn't have a chance to play with it further.