Re: 2001-06-28 CVS ash Background Win32 Process Hang Problem

[Jason Tishler <Jason dot Tishler at dothill dot com>]

I have some more (hopefully useful) information...

On Tue, Jul 10, 2001 at 04:28:11PM -0400, Jason Tishler wrote:
> The problem does not occur in 1.3.2 -- so it has been introduced since
> that release.

It appears that this problem was introduced somewhere between 1.3.2
(which uname -a indicates was built on 2001-05-20 23:28) and when the
2001-05-22 snapshot was built.  Unfortunately, even after reviewing the
CVS commit mailing list, I could not find the culprit.

Anyway, I've attached two strace logs -- the first exhibits the hang,
then second does not.  The first one is produced by:

    $ strace -o hang.log sh hang.sh

and the second by:

    $ strace -o nohang.log bash hang.sh

Here is an interesting snippet from hang.log:

 1262  248348 [main] sh 428 spawn_guts: spawn_guts null_app_name 0 (c:\WINNT\system32\notepad.exe, c:\WINNT\system32\notepad.exe)
 1701  250049 [main] sh 428 spawn_guts: 463 = spawn_guts (/mnt/c/WINNT/system32/notepad, c:\WINNT\system32\notepad.exe)
  276  250325 [main] sh 428 proc_subproc: args: 1, 37876916
  189  250514 [main] sh 428 proc_subproc: added pid 463 to wait list, slot 0, winpid 0x1CF, handle 0x344
  171  250685 [main] sh 428 proc_subproc: returning 1                             166  250851 [main] sh 428 spawn_guts: spawned windows pid 463
  178  251029 [proc] sh 428 wait_subproc: looping

XXX hangs here XXX

55124741 55375770 [proc] sh 428 proc_subproc: args: 2, 0
  318 55376088 [proc] sh 428 proc_subproc: pid 463[0] terminated, handle 0x344, nchildren 1, nzombies 0
  220 55376308 [proc] sh 428 proc_subproc: zombifying [0], pid 463, handle 0x344, nchildren 1
  171 55376479 [proc] sh 428 proc_subproc: returning 1
  161 55376640 [proc] sh 428 sig_send: pid 428, signal 20, its_me 1
  164 55376804 [proc] sh 428 sig_send: Not waiting for sigcomplete.  its_me 1 signal 20
  162 55376966 [proc] sh 428 sig_send: returning 0 from sending signal 20
  159 55377125 [proc] sh 428 wait_subproc: looping
  171 55377296 [main] sh 428 spawn_guts: subprocess exited

Note that when the hang returns there appears to be some unusually large
numbers in column one and two which seem to indicate uninitialized or
corrupted memory.

Also attached is a gdb session obtained by attaching to the hung sh.exe.
It appears that Cygwin is hung on WaitForMultipleObjects(), but nwait is
also a huge number...

Thanks,
Jason

-- 
Jason Tishler
Director, Software Engineering       Phone: 732.264.8770 x235
Dot Hill Systems Corp.               Fax:   732.264.8798
82 Bethany Road, Suite 7             Email: Jason.Tishler@dothill.com
Hazlet, NJ 07730 USA                 WWW:   http://www.dothill.com

hang.log.gz

nohang.log.gz

(gdb) bt
#0  0x77f6828b in ?? ()
#1  0x77f1cd92 in ?? ()
#2  0x61052d73 in spawn_guts (hToken=0x0, 
    prog_arg=0x412d68 "/mnt/c/WINNT/system32/notepad", argv=0x412c5c, 
    envp=0x412c74, mode=2) at ../../../../src/winsup/cygwin/spawn.cc:753
#3  0x610534f7 in _spawnve (hToken=0x0, mode=3, 
    path=0x412d68 "/mnt/c/WINNT/system32/notepad", argv=0x412c5c, 
    envp=0x412c74) at ../../../../src/winsup/cygwin/spawn.cc:895
#4  0x6100ef4d in _execve (path=0x412d68 "/mnt/c/WINNT/system32/notepad", 
    argv=0x412c5c, envp=0x412c74) at ../../../../src/winsup/cygwin/exec.cc:35
#5  0x6107b702 in execve (path=0x412d68 "/mnt/c/WINNT/system32/notepad", 
    argv=0x412c5c, envp=0x412c74)
    at ../../../../../src/newlib/libc/posix/execve.c:13
..
(gdb) f 2
#2  0x61052d73 in spawn_guts (hToken=0x0, 
    prog_arg=0x412d68 "/mnt/c/WINNT/system32/notepad", argv=0x412c5c, 
    envp=0x412c74, mode=2) at ../../../../src/winsup/cygwin/spawn.cc:753
753           switch (WaitForMultipleObjects (nwait, waitbuf, FALSE, INFINITE))
Current language:  auto; currently c++
(gdb) list
748       res = 0;
749       exited = FALSE;
750       MALLOC_CHECK;
751       for (int i = 0; i < 100; i++)
752         {
753           switch (WaitForMultipleObjects (nwait, waitbuf, FALSE, INFINITE))
754             {
755             case WAIT_OBJECT_0:
756               sigproc_printf ("subprocess exited");
757               DWORD exitcode;
(gdb) p nwait
$1 = 2147348480