[ast-developers] Hang because job management _within_ the SIGCHLD signal handler... / was: Re: AT&T Software Technology ast alpha software download update

the AT&T Software Technology ast alpha 2013-07-27 source release
has been posted to the download site
http://www.research.att.com/sw/download/alpha/
the package names and md5 checksums are
INIT 8cdf2460c146a7412ee1f2d37d19e3ce
ast-base 46a03d0e49840acedef8c0623cbef85c
ast-open f61766d8cb1f91c960a3a2a1385adcd6
ast-ksh 911d28c7263e90ec1e8037ad0b6db643
the md5 sums should match the ones listed on the download page
still verifying builds on some architectures
should be ok on linux & solaris
for the next week or so stability/regression patches will take priority

I hit (again) one of the nasty and hard to reproduce problems (which
means: No... I don't have a testcase... ;-( ) related to job
management:
-- snip --
5841: /home/test001/ksh93/ast_ksh_20130727/build_i386_64bit_debug/arch/sol11
fffffd7ffbcaa44a nanosleep (fffffd7fffdfd008, fffffd7fffdfcff8)
fffffd7ffba70c90 tvsleep () + 40
fffffd7ffbb0ec3c asorelax () + 3c
fffffd7ffbb0ebbb asolock () + bb
fffffd7ffbb19a36 dballoc () + 96
fffffd7ffbb1a131 dbresize () + d1
fffffd7ffbb10728 _ast_calloc () + 128
fffffd7ffb88b064 jobsave_create () + 104
fffffd7ffb88bd32 job_reap () + 6d2
fffffd7ffb88b659 job_waitsafe () + 89
fffffd7ffbca2326 __sighndlr () + 6
fffffd7ffbc94ffc call_user_handler () + 2a4
fffffd7ffbc95223 sigacthandler (12, fffffd7fffdfd7b0, fffffd7fffdfd450) + db
--- called from signal handler with signal 18 (SIGCLD) ---
fffffd7ffbb1a76b vmdbcheck () + 1bb
fffffd7ffbb19e9e dbfree () + 27e
fffffd7ffbb10c0c _ast_free () + 12c
fffffd7ffb8e1021 sh_subshell () + 16f1
fffffd7ffb8a83cf comsubst () + 10ff
fffffd7ffb8a244d varsub () + 58d
fffffd7ffb89fa16 copyto () + 10e6
fffffd7ffb89ce83 sh_mactrim () + 2a3
fffffd7ffb8ac9a6 sh_setlist () + 2e6
fffffd7ffb8e9ca7 sh_exec () + 1367
fffffd7ffb8ee803 sh_exec () + 5ec3
fffffd7ffb8ef973 sh_exec () + 7033
fffffd7ffb8ee831 sh_exec () + 5ef1
fffffd7ffb8ee803 sh_exec () + 5ec3
fffffd7ffb8f5eab sh_funscope_20120720 () + aeb
fffffd7ffb8f3a9a sh_funct () + 37a
fffffd7ffb8ebc94 sh_exec () + 3354
fffffd7ffb844007 exfile () + 1147
fffffd7ffb842e82 sh_main () + 1752
000000000040c0b2 main () + 92
000000000040becc ???????? ()
-- snip --

... this hang occured because ksh93 tries to do job management from
within the signal handler... which is IMO _far_ from being safe to
do...

David: Is there *ANY* way the job management can be moved out of the
signal handler and just rely on the siginfo data ?

----

Bye,
Roland

--
__ . . __
(o.\ \/ /.o) roland.mainz at nrubsig.org
\__\/\/__/ MPEG specialist, C&&JAVA&&Sun&&Unix programmer
/O /==\ O\ TEL +49 641 3992797
(;O/ \/ \O;)

Glenn Fowler

2013-07-29 14:03:30 UTC

I hit (again) one of the nasty and hard to reproduce problems (which
means: No... I don't have a testcase... ;-( ) related to job
-- snip --
5841: /home/test001/ksh93/ast_ksh_20130727/build_i386_64bit_debug/arch/sol11
fffffd7ffbcaa44a nanosleep (fffffd7fffdfd008, fffffd7fffdfcff8)
fffffd7ffba70c90 tvsleep () + 40
fffffd7ffbb0ec3c asorelax () + 3c
fffffd7ffbb0ebbb asolock () + bb
fffffd7ffbb19a36 dballoc () + 96
fffffd7ffbb1a131 dbresize () + d1
fffffd7ffbb10728 _ast_calloc () + 128
fffffd7ffb88b064 jobsave_create () + 104
fffffd7ffb88bd32 job_reap () + 6d2
fffffd7ffb88b659 job_waitsafe () + 89
fffffd7ffbca2326 __sighndlr () + 6
fffffd7ffbc94ffc call_user_handler () + 2a4
fffffd7ffbc95223 sigacthandler (12, fffffd7fffdfd7b0, fffffd7fffdfd450) + db
--- called from signal handler with signal 18 (SIGCLD) ---
fffffd7ffbb1a76b vmdbcheck () + 1bb
fffffd7ffbb19e9e dbfree () + 27e
fffffd7ffbb10c0c _ast_free () + 12c
fffffd7ffb8e1021 sh_subshell () + 16f1
fffffd7ffb8a83cf comsubst () + 10ff
fffffd7ffb8a244d varsub () + 58d
fffffd7ffb89fa16 copyto () + 10e6
fffffd7ffb89ce83 sh_mactrim () + 2a3
fffffd7ffb8ac9a6 sh_setlist () + 2e6
fffffd7ffb8e9ca7 sh_exec () + 1367
fffffd7ffb8ee803 sh_exec () + 5ec3
fffffd7ffb8ef973 sh_exec () + 7033
fffffd7ffb8ee831 sh_exec () + 5ef1
fffffd7ffb8ee803 sh_exec () + 5ec3
fffffd7ffb8f5eab sh_funscope_20120720 () + aeb
fffffd7ffb8f3a9a sh_funct () + 37a
fffffd7ffb8ebc94 sh_exec () + 3354
fffffd7ffb844007 exfile () + 1147
fffffd7ffb842e82 sh_main () + 1752
000000000040c0b2 main () + 92
000000000040becc ???????? ()
-- snip --
... this hang occured because ksh93 tries to do job management from
within the signal handler... which is IMO _far_ from being safe to
do...
David: Is there *ANY* way the job management can be moved out of the
signal handler and just rely on the siginfo data ?

this one is simple
VMALLOC_OPTIONS=<anything-that-pushes-the-debug-discipline>
is not thread or signal safe
it may be possible to add signal safety, less optimistic about thread safety
=> don't use vmdebug if you are threading or signal storming or spawning children <=

right now its not at the top of the todo list because past experience
show that any vmalloc coding in this area costs at least 2 weeks to get right

Roland Mainz

2013-07-30 13:40:48 UTC

[snip]

Post by Roland Mainz
I hit (again) one of the nasty and hard to reproduce problems (which
means: No... I don't have a testcase... ;-( ) related to job
-- snip --

[snip]

Post by Roland Mainz
-- snip --
... this hang occured because ksh93 tries to do job management from
within the signal handler... which is IMO _far_ from being safe to
do...
David: Is there *ANY* way the job management can be moved out of the
signal handler and just rely on the siginfo data ?

Attached (as "astksh20130727_prototype_process_sigchld_outside_signalhandler001.diff.txt")
is a prototype (hacked) patch for discussion.

* The good news are:
- SIGCHLD processing now seems to be reliable. I can't find a simple
testcase to break it (but see the item about the testsuite below)
- SIGCHLD processing now works without problems under "valgrind" control
- The patch seems to fix a lot of Cedric's issues with signals being
lost. Even the testcase where a $ ... while ! wait ; sleep 8 ; done #
was loosing signals now works... if I replace the "sleep 8" with
"compound -a dummy ; poll -t 8 dummy" (so there seems to be a seperate
problem with "sleep" ... somehow)

* The bad news are:
- The patch doesn't work very well for interactive shells
- The "sigchld.sh" testsuite module fails in several places... AFAIK
the reason is that we don't check the list of queued CHLD signals in
all places where they should be checked (e.g. each time before we
execute a shell statement and before and after running external
processes and each time wait(1) internally wakes up from a signal)
- $ jobs -l # reports already purged processes... erm... no clue why... ;-(

* Notes about interactive mode:
An interactive shell AFAIK requires to report terminating childs
"immediately" if some shell options are set (erm... David: Which
option is this again ?). AFAIK this can be archived by two ways:
1. wake up from time-to-time (e.g. polling) ... but this has a bad
effect in CPU usage (imagine 1000 shell sessions in a multi-user
system waking-up 10 times per second... or imagine the impact for
battery life in a laptop)
2. add some glue to the editor code to wake up for each signald and
process it when |sfpkrd()| returns...
-- snip --
(gdb) where
#0 0x00007fc2be588860 in __poll_nocancel () at
../sysdeps/unix/syscall-template.S:81
#1 0x000000000050280d in sfpkrd (fd=0, argbuf=0x7fff33545080, n=80,
rc=0, tm=-1, action=1)
at /home/test001/work/ast_ksh_20130727/build_i386_64bit_debug_patched/src/lib/libast/sfio/sfpkrd.c:142
#2 0x0000000000410fb9 in ed_read (context=0x7fc2bf063960, fd=0,
buff=0x7fff33545080 "\240PT3\377\177", size=80, reedit=0)
at /home/test001/work/ast_ksh_20130727/build_i386_64bit_debug_patched/src/cmd/ksh93/edit/edit.c:884
-- snip --
... that's the strategy my patch attempts...

David: What do you think ?

----

Bye,
Roland
--
__ . . __
(o.\ \/ /.o) roland.mainz at nrubsig.org
\__\/\/__/ MPEG specialist, C&&JAVA&&Sun&&Unix programmer
/O /==\ O\ TEL +49 641 3992797
(;O/ \/ \O;)
-------------- next part --------------
diff -r -u original/src/cmd/ksh93/edit/edit.c build_i386_64bit_debug/src/cmd/ksh93/edit/edit.c
--- src/cmd/ksh93/edit/edit.c 2013-03-29 00:02:06.000000000 +0100
+++ src/cmd/ksh93/edit/edit.c 2013-07-30 15:28:25.920003108 +0200
@@ -882,6 +882,8 @@
errno = 0;
if(!waitevent || (rv=(*waitevent)(fd,-1L,0))>=0)
rv = sfpkrd(fd,buff,size,delim,-1L,mode);
+
+ job_waitsafe(SIGCHLD, NULL, NULL);
}
if(rv < 0)
{
diff -r -u original/src/cmd/ksh93/sh/fault.c build_i386_64bit_debug/src/cmd/ksh93/sh/fault.c
--- src/cmd/ksh93/sh/fault.c 2013-07-23 19:24:50.000000000 +0200
+++ src/cmd/ksh93/sh/fault.c 2013-07-29 20:57:34.568716091 +0200
@@ -117,8 +117,13 @@
register char *trap;
register struct checkpt *pp = (struct checkpt*)shp->jmplist;
int action=0;
- if(sig==SIGCHLD)
- sfprintf(sfstdout,"childsig\n");
+
+ if (sig==SIGCHLD)
+ {
+ set_trapinfo(shp,sig,info);
+ return;
+ }
+
#ifdef SIGWINCH
if(sig==SIGWINCH)
{
@@ -139,13 +144,7 @@
sigrelease(sig);
kill(getpid(),sig);
}
- if(shp->savesig)
- {
- /* critical region, save and process later */
- if(!(shp->sigflag[sig]&SH_SIGIGNORE))
- shp->savesig = sig;
- return;
- }
+
/* handle ignored signals */
if(trap && *trap==0)
return;
@@ -292,6 +291,8 @@
shp->st.trapcom = (char**)calloc(n,sizeof(char*));
shp->sigflag = (unsigned char*)calloc(n,sizeof(char));
shp->gd->sigmsg = (char**)calloc(n,sizeof(char*));
+ shp->siginfo = (void**)calloc(sizeof(void*),shp->gd->sigmax);
+
for(tp=shtab_signals; sig=tp->sh_number; tp++)
{
n = (sig>>SH_SIGBITS);
@@ -329,8 +330,6 @@
}
else
{
- if(!shp->siginfo)
- shp->siginfo = (void**)calloc(sizeof(void*),shp->gd->sigmax);
flag |= SH_SIGFAULT;
if(sig==SIGALRM && fun!=SIG_DFL && fun!=(sh_sigfun_t)sh_fault)
signal(sig,fun);
@@ -472,6 +471,7 @@
shp->sigflag[sig] &= ~SH_SIGTRAP;
if(sig==SIGCHLD)
{
+ job_waitsafe(sig, NULL, NULL);
job_chldtrap(shp,shp->st.trapcom[SIGCHLD],1);
continue;
}
@@ -686,7 +686,14 @@
signal(sig,SIG_DFL);
sigrelease(sig);
kill(getpid(),sig);
+#if 1
+ while(shp->siginfo[SIGCHLD])
+ {
+ job_waitsafe(SIGCHLD, NULL, NULL);
+ }
+#else
pause();
+#endif
}
#if SHOPT_KIA
if(sh_isoption(shp,SH_NOEXEC))
diff -r -u original/src/cmd/ksh93/sh/jobs.c build_i386_64bit_debug/src/cmd/ksh93/sh/jobs.c
--- src/cmd/ksh93/sh/jobs.c 2013-07-17 18:22:06.000000000 +0200
+++ src/cmd/ksh93/sh/jobs.c 2013-07-29 15:52:05.790485028 +0200
@@ -362,9 +362,9 @@
* This is the SIGCLD interrupt routine
*/
#ifdef _lib_sigaction
-static void job_waitsafe(int sig, siginfo_t *info, void *context)
+void job_waitsafe(int sig, siginfo_t *info, void *context)
#else
-static void job_waitsafe(int sig)
+void job_waitsafe(int sig)
#endif
{
if(job.in_critical || vmbusy())
@@ -648,9 +648,9 @@
{
register int ntry=0;
job.fd = JOBTTY;
- signal(SIGCHLD,job_waitsafe);
+ signal(SIGCHLD,sh_fault);
# if defined(SIGCLD) && (SIGCLD!=SIGCHLD)
- signal(SIGCLD,job_waitsafe);
+ signal(SIGCLD,sh_fault);
# endif
if(njob_savelist < NJOB_SAVELIST)
init_savelist();
diff -r -u original/src/cmd/ksh93/sh/xec.c build_i386_64bit_debug/src/cmd/ksh93/sh/xec.c
--- src/cmd/ksh93/sh/xec.c 2013-07-25 02:37:26.000000000 +0200
+++ src/cmd/ksh93/sh/xec.c 2013-07-28 05:36:31.827214685 +0200
@@ -2710,8 +2710,10 @@
Namval_t *oldnspace = shp->namespace;
int offset = stktell(stkp);
int flag=NV_NOASSIGN|NV_NOARRAY|NV_VARNAME;
+#if 0
if(cp)
errormsg(SH_DICT,ERROR_exit(1),e_ident,fname);
+#endif
sfputc(stkp,'.');
sfputr(stkp,fname,0);
np = nv_open(stkptr(stkp,offset),shp->var_tree,flag);

Glenn Fowler

2013-07-30 14:12:36 UTC

--047d7b6d8d7cb1934204e2bac182
Content-Type: text/plain; charset=ISO-8859-1
[snip]

Post by Roland Mainz
I hit (again) one of the nasty and hard to reproduce problems (which
means: No... I don't have a testcase... ;-( ) related to job
-- snip --

[snip]

Attached (as "astksh20130727_prototype_process_sigchld_outside_signalhandler001.diff.txt")
is a prototype (hacked) patch for discussion.
- SIGCHLD processing now seems to be reliable. I can't find a simple
testcase to break it (but see the item about the testsuite below)
- SIGCHLD processing now works without problems under "valgrind" control
- The patch seems to fix a lot of Cedric's issues with signals being
lost. Even the testcase where a $ ... while ! wait ; sleep 8 ; done #
was loosing signals now works... if I replace the "sleep 8" with
"compound -a dummy ; poll -t 8 dummy" (so there seems to be a seperate
problem with "sleep" ... somehow)
- The patch doesn't work very well for interactive shells
- The "sigchld.sh" testsuite module fails in several places... AFAIK
the reason is that we don't check the list of queued CHLD signals in
all places where they should be checked (e.g. each time before we
execute a shell statement and before and after running external
processes and each time wait(1) internally wakes up from a signal)
- $ jobs -l # reports already purged processes... erm... no clue why... ;-(
An interactive shell AFAIK requires to report terminating childs
"immediately" if some shell options are set (erm... David: Which
1. wake up from time-to-time (e.g. polling) ... but this has a bad
effect in CPU usage (imagine 1000 shell sessions in a multi-user
system waking-up 10 times per second... or imagine the impact for
battery life in a laptop)
2. add some glue to the editor code to wake up for each signald and
process it when |sfpkrd()| returns...
-- snip --
(gdb) where
#0 0x00007fc2be588860 in __poll_nocancel () at
../sysdeps/unix/syscall-template.S:81
#1 0x000000000050280d in sfpkrd (fd=0, argbuf=0x7fff33545080, n=80,
rc=0, tm=-1, action=1)
at /home/test001/work/ast_ksh_20130727/build_i386_64bit_debug_patched/src/lib/libast/sfio/sfpkrd.c:142
#2 0x0000000000410fb9 in ed_read (context=0x7fc2bf063960, fd=0,
buff=0x7fff33545080 "\240PT3\377\177", size=80, reedit=0)
at /home/test001/work/ast_ksh_20130727/build_i386_64bit_debug_patched/src/cmd/ksh93/edit/edit.c:884
-- snip --
... that's the strategy my patch attempts...

for the current code do you see failures when the vmalloc debug method is not used?

Roland Mainz

2013-07-30 14:16:28 UTC

--047d7b6d8d7cb1934204e2bac182
Content-Type: text/plain; charset=ISO-8859-1
[snip]

Post by Roland Mainz
I hit (again) one of the nasty and hard to reproduce problems (which
means: No... I don't have a testcase... ;-( ) related to job
-- snip --

[snip]

for the current code do you see failures when the vmalloc debug method is not used?

Sporadically... yes. But I'm not sure whether this is an issue in
vmalloc or something else. I'm not even sure whether the job lkist
handling code in ksh93 is the root cause of most of the trouble. This
is all made much harder because Linux doesn't have much usefull tools
to instrument signal handlers so I have to walk the code by hand.

----

Bye,
Roland

--
__ . . __
(o.\ \/ /.o) roland.mainz at nrubsig.org
\__\/\/__/ MPEG specialist, C&&JAVA&&Sun&&Unix programmer
/O /==\ O\ TEL +49 641 3992797
(;O/ \/ \O;)

Glenn Fowler

2013-07-30 14:49:13 UTC

--047d7b6d8d7cb1934204e2bac182
Content-Type: text/plain; charset=ISO-8859-1
[snip]

Post by Roland Mainz
I hit (again) one of the nasty and hard to reproduce problems (which
means: No... I don't have a testcase... ;-( ) related to job
-- snip --

[snip]

for the current code do you see failures when the vmalloc debug method is not used?

it might be good to nail down this problem first
otherwise we might be applying fixes for something that's not broken

I just yesterday plugged a few EINTR holes in src/lib/libast/vmalloc/vmdcsystem.c
that may be part of what you saw

Irek Szczesniak

2013-07-30 15:14:18 UTC

--047d7b6d8d7cb1934204e2bac182
Content-Type: text/plain; charset=ISO-8859-1
[snip]

Post by Roland Mainz
I hit (again) one of the nasty and hard to reproduce problems (which
means: No... I don't have a testcase... ;-( ) related to job
-- snip --

[snip]

for the current code do you see failures when the vmalloc debug method is not used?

it might be good to nail down this problem first
otherwise we might be applying fixes for something that's not broken

Chime in on this topic. sh_fault() is one piece of brokenness from head to tail.
Just from looking at it for five minutes I can tell you:
- SIGWINCH handling is broken. You can't seriously assume that
nv_putval() is save to use in a signal handler. Practical testing
shows that if you run unset LINES COLUMNS and recreate the variables
in a loop and resize the window (just drag the right bottom border
around in Gnome or KDE) the storm of WINCH signals will trigger a SEGV
sooner or later in a random location of shell code
- A lot of variables like shp->st.trapcom[sig] are accessed from
inside and outside the signal handler without protection, i.e. atomic
load/store instructions. You permanently risk a broken state if
signals of different types meet each other in sh_fault()
- shp->trapnote & | = anything <-- what happens in nested signal
handler calls? Guess?
- Another notorious abuse:
482 if(shp->siginfo)
483 {
484 do ip = shp->siginfo[sig];
485 while
(asocasptr(&shp->siginfo[sig],ip,0)!=ip);
486 }
How is this suppose to be signal safe? You read from shp->siginfo[sig]
unsafe but do the write using atomic instructions? Likewise filling
the queue must be done with atomic instructions to handle nested
signal handler calls.
- All variables read or written from both a signal handler and user
code must be of storage type volatile. Missing here, too.
Surprisingly, if you look at the assembler code, the compiler caches a
lot of values in registers or hidden temporary stack variables. May be
another source of trouble. May? Not may. Correction: It is.

Post by Glenn Fowler
From what I can glance in 5 minutes sh_fault() is notoriously signal

unsafe by violating every known rule about writing signal handlers
(i.e. keep the code as short as possible, use only async signal safe
functions, use volatile storage and atomic r/w instructions for
communication) and should be thrown away. No amount of one line fixes
can rescue it. Please. Just throw this **** away and rewrite it from
scratch.

Irek

Cedric Blancher

2013-07-30 16:22:04 UTC

Post by Irek Szczesniak

--047d7b6d8d7cb1934204e2bac182
Content-Type: text/plain; charset=ISO-8859-1
[snip]

Post by Roland Mainz
I hit (again) one of the nasty and hard to reproduce problems (which
means: No... I don't have a testcase... ;-( ) related to job
-- snip --

[snip]

for the current code do you see failures when the vmalloc debug method is not used?

it might be good to nail down this problem first
otherwise we might be applying fixes for something that's not broken

Chime in on this topic. sh_fault() is one piece of brokenness from head to tail.
- SIGWINCH handling is broken. You can't seriously assume that
nv_putval() is save to use in a signal handler. Practical testing
shows that if you run unset LINES COLUMNS and recreate the variables
in a loop and resize the window (just drag the right bottom border
around in Gnome or KDE) the storm of WINCH signals will trigger a SEGV
sooner or later in a random location of shell code
- A lot of variables like shp->st.trapcom[sig] are accessed from
inside and outside the signal handler without protection, i.e. atomic
load/store instructions. You permanently risk a broken state if
signals of different types meet each other in sh_fault()
- shp->trapnote & | = anything <-- what happens in nested signal
handler calls? Guess?
482 if(shp->siginfo)
483 {
484 do ip = shp->siginfo[sig];
485 while
(asocasptr(&shp->siginfo[sig],ip,0)!=ip);
486 }
How is this suppose to be signal safe? You read from shp->siginfo[sig]
unsafe but do the write using atomic instructions? Likewise filling
the queue must be done with atomic instructions to handle nested
signal handler calls.
- All variables read or written from both a signal handler and user
code must be of storage type volatile. Missing here, too.
Surprisingly, if you look at the assembler code, the compiler caches a
lot of values in registers or hidden temporary stack variables. May be
another source of trouble. May? Not may. Correction: It is.
From what I can glance in 5 minutes sh_fault() is notoriously signal
unsafe by violating every known rule about writing signal handlers
(i.e. keep the code as short as possible, use only async signal safe
functions, use volatile storage and atomic r/w instructions for
communication) and should be thrown away. No amount of one line fixes
can rescue it. Please. Just throw this **** away and rewrite it from
scratch.

I'd refrain from using strong language but yes, sh_fault() is a source
of raised eyebrows. Why does it have to be so complex? Why can't
sh_fault() just record all siginfo structures in a queue and let the
sh_chksig() do all the work. The prodding of the shp->sig* variables
from both signal handler and user code sides is unsafe beyond measure
and combined with the code prodding in the job.* variables makes it a
nightmare.

+1 for Irek's analysis.

Ced

--
Cedric Blancher <cedric.blancher at gmail.com>
Institute Pasteur

Irek Szczesniak

2013-08-09 10:57:12 UTC

Post by Irek Szczesniak