Snapshot 20040225: make hangs/errors out

[Rolf Campbell]

Christopher Faylor wrote:
>>>I made a fix last night that allowed me to run this for 2500+
>>>iterations.  Of course, I have managed to do that before without error,
>>>so that doesn't mean much, I guess.  Backing the change out resulted in
>>>a 'virtual memory exhausted' error in less than a hundred iterations,
>>>however.  Odd that I can duplicate it so readily now.  I think my
>>>computer was previously trying to shield me from the pain of debugging
>>>this problem.
>>>
>>>There is a new snapshot up now with my fix in it.  Please try it.
>>
>>Sigh.  Literally two minutes after sending this email, the "make -j"
>>test that I was running at home errored out with a different error.
>>
>>Back to the drawing board...
> 
> 
> Hmm.  I can't duplicate the failure I saw so maybe it would still be
> instructive to see how the current snapshot works for others.
> 
> Please send test results here.
> 
> cgf
> 

'06 snapshot, froze after 128 iterations (0% cpu, no error output).
I've attached the end of the strace output.  I will run it a few more 
times to make sure this is consistant.

-Rolf

**********************************************
Program name: C:\cygwin\bin\sh.exe (2884)
   248   43520 [main] uname 2816 writev: writev (1, 0x22EEB0, 1)
App version:  1005.8, api: 0.111
    96   43616 [main] uname 2816 fhandler_base::write: binary write
DLL version:  1005.8, api: 0.111
   118   43734 [main] uname 2816 fhandler_base::write: 14 = write 
(0xA040280, 14)
DLL build:    20040306 23:59:38SNP
   107   43841 [main] uname 2816 writev: 14 = write (1, 0x22EEB0, 1), 
errno 0
OS version:   Windows NT-5.1
  9827 1053360 [proc] make 2168 proc_subproc: args: 2, 1
   170   44011 [main] uname 2816 close: close (1)
Heap size:    1073741824
   154 1053514 [proc] make 2168 proc_subproc: pid 4080[1] terminated, 
handle 0x674, nchildren 3, nzombies 3
   151   44162 [main] uname 2816 fhandler_base::close: closing 
'/tmp/cygwin/freeze.1' handle 0x6E8
Date/Time:    2004-03-08 11:18:11
**********************************************
   151 1053665 [proc] make 2168 proc_subproc: zombifying [1], pid 4080, 
handle 0x674, nchildren 3
   131   44293 [main] uname 2816 close: 0 = close (1)
   103 1053768 [proc] make 2168 proc_subproc: returning 1
    77 1053845 [proc] make 2168 sig_send: sendsig 0x70C, pid 2168, 
signal 20, its_me 1
   289    1133 [main] sh 2884 events_init: windows_system_directory 
'C:\WINDOWS\System32\', windows_system_directory_length 20
   243   44536 [main] uname 2816 do_exit: do_exit (0), exit_state 0
   132 1053977 [proc] make 2168 sig_send: Not waiting for sigcomplete. 
its_me 1 signal 20
    99   44635 [main] uname 2816 void: 0x0 = signal (20, 0x1)
   142    1275 [main] sh 2884 _cygwin_istext_for_stdio: fd 0: opened as 
binary
   108 1054085 [proc] make 2168 sig_send: returning 0x0 from sending 
signal 20
    65   44700 [main] uname 2816 void: 0x0 = signal (1, 0x1)
    90   44790 [main] uname 2816 void: 0x0 = signal (2, 0x1)
   133 1054218 [proc] make 2168 wait_subproc: looping
   150    1425 [main] sh 2884 _cygwin_istext_for_stdio: fd 1: opened as 
binary
    51   44841 [main] uname 2816 void: 0x0 = signal (3, 0x1)
   134 1054352 [sig] make 2168 sigpacket::process: signal 20 processing
   129   44970 [main] uname 2816 fhandler_base::close: closing 
'/tmp/cygwin/freeze.1.err' handle 0x738
   151    1576 [main] sh 2884 _cygwin_istext_for_stdio: fd 2: opened as 
binary
    70 1054422 [sig] make 2168 _cygtls::find_tls: sig 20
    94 1054516 [sig] make 2168 sigpacket::process: signal 20, about to 
call 0x40C540
   144   45114 [main] uname 2816 sigproc_terminate: entering
    54 1054570 [sig] make 2168 setup_handler: trying to send sig 20 but 
signal 20 already armed
    61 1054631 [sig] make 2168 setup_handler: signal 20 not delivered
   149   45263 [sig] uname 2816 wait_sig: done
    49 1054680 [sig] make 2168 sigpacket::process: returning 0
    62   45325 [sig] uname 2816 _cygtls::remove: wait 0x0
    76 1054756 [sig] make 2168 proc_subproc: args: 3, 0
    60 1054816 [sig] make 2168 proc_subproc: looking for processes to reap
    71 1054887 [sig] make 2168 proc_subproc: finished processing 
terminated/stopped child
   173   45498 [main] uname 2816 proc_terminate: nchildren 0, nzombies 0
    50 1054937 [sig] make 2168 proc_subproc: returning 1
   112   45610 [main] uname 2816 proc_terminate: leaving
   716   46326 [main] uname 2816 __to_clock_t: dwHighDateTime 0, 
dwLowDateTime 156250
    60   46386 [main] uname 2816 __to_clock_t: total 00000000 0000000F
    51   46437 [main] uname 2816 __to_clock_t: dwHighDateTime 0, 
dwLowDateTime 312500
    50   46487 [main] uname 2816 __to_clock_t: total 00000000 0000001F
  1763    3339 [main] sh 2884 parse_options: error_start (called func)
   100    3439 [main] sh 2884 parse_options: returning
    52    3491 [main] sh 2884 pinfo_init: pid 2884, pgid 2168
   419    3910 [main] sh 2884 sigproc_init: process/signal handling 
enabled(C1)
    78    3988 [main] sh 2884 dll_crt0_1: user_data->main 0x4081F0
    60    4048 [main] sh 2884 wait_for_sigthread: wait_sig_inited 0x750
   242    4290 [sig] sh 2884 wait_sig: subproc_ready 0x778
16516 1057217 [main] make 2884! spawn_guts: res = 20000
   168    4458 [sig] sh 2884 wait_sig: entering ReadFile loop, readsig 
0x740, myself->sendsig 0x73C
    69 1057286 [main] make 2884! spawn_guts: parent handle 0x7F8
   131 1057417 [main] make 2884! spawn_guts: 1 = DuplicateHandle, oldh 
0x65C, newh 0x6A0
    95 1057512 [main] make 2884! sigproc_terminate: entering
    56 1057568 [main] make 2884! proc_terminate: nchildren 0, nzombies 0
    48 1057616 [main] make 2884! proc_terminate: leaving
    65 1057681 [main] make 2884! __to_clock_t: dwHighDateTime 0, 
dwLowDateTime 0
  1808   48295 [main] uname 2816 _pinfo::exit: Calling ExitProcess 0
   142 1057823 [main] make 2884! __to_clock_t: total 00000000 00000000
    71 1057894 [main] make 2884! __to_clock_t: dwHighDateTime 0, 
dwLowDateTime 156250
    90 1057984 [main] make 2884! __to_clock_t: total 00000000 0000000F
35890  223586 [proc] sh 3776 proc_subproc: args: 2, 0
   502  224088 [proc] sh 3776 proc_subproc: pid 2816[0] terminated, 
handle 0x70C, nchildren 1, nzombies 0
  1789 1059773 [main] make 2884! _pinfo::exit: Calling ExitProcess 131072
   318  224406 [proc] sh 3776 proc_subproc: zombifying [0], pid 2816, 
handle 0x70C, nchildren 1
   128  224534 [proc] sh 3776 proc_subproc: returning 1
   271  224805 [proc] sh 3776 sig_send: sendsig 0x74C, pid 3776, signal 
20, its_me 1
   290  225095 [proc] sh 3776 sig_send: Not waiting for sigcomplete. 
its_me 1 signal 20
   223  225318 [proc] sh 3776 sig_send: returning 0x0 from sending signal 20
  6524 1061461 [proc] make 2168 proc_subproc: args: 2, 0
    67 1061528 [proc] make 2168 proc_subproc: pid 2884[0], reparented 
old hProcess 0x65C, new 0x6A0
    49 1061577 [proc] make 2168 proc_subproc: returning 0
  1007  226325 [proc] sh 3776 wait_subproc: looping
   158 1061735 [proc] make 2168 wait_subproc: looping
     9  226334 [sig] sh 3776 sigpacket::process: signal 20 processing
   160  226494 [sig] sh 3776 _cygtls::find_tls: sig 20
    49  226543 [sig] sh 3776 sigpacket::process: default signal 20 ignored
    58  226601 [sig] sh 3776 sigpacket::process: returning 1
    58  226659 [sig] sh 3776 proc_subproc: args: 3, 0
    76  226735 [sig] sh 3776 proc_subproc: looking for processes to reap
    60  226795 [sig] sh 3776 checkstate: nchildren 0, nzombies 1
    59  226854 [sig] sh 3776 stopped_or_terminated: considering pid 2816
    72  226926 [sig] sh 3776 remove_zombie: removing 0, pid 2816, nzombies 1
    58  226984 [main] sh 3776 wait4: 0 = WaitForSingleObject (...)
  5180    9638 [main] sh 2884 sigaction: signal 2, newact 0x0, oldact 
0x22EF00
    78  227062 [main] sh 3776 wait4: intpid -1, status 0x22ED58, 
w->status 0, options 0, res 2816
    80    9718 [main] sh 2884 void: 0x0 = signal (2, 0x40F5A0)
   106  227168 [sig] sh 3776 checkstate: returning 1
    96    9814 [main] sh 2884 sigaction: signal 3, newact 0x0, oldact 
0x22EF00
    69  227237 [main] sh 3776 do_exit: do_exit (0), exit_state 0
   132    9946 [main] sh 2884 void: 0x0 = signal (3, 0x40F5A0)
    53  227290 [sig] sh 3776 proc_subproc: released waiting thread
    91  227381 [main] sh 3776 void: 0x0 = signal (20, 0x1)
   127   10073 [main] sh 2884 sigaction: signal 15, newact 0x0, oldact 
0x22EF00
    71  227452 [sig] sh 3776 proc_subproc: finished processing 
terminated/stopped child
    58  227510 [main] sh 3776 void: 0x0 = signal (1, 0x1)
   126   10199 [main] sh 2884 void: 0x0 = signal (15, 0x0)
    71  227581 [sig] sh 3776 proc_subproc: returning 1
    54  227635 [main] sh 3776 void: 0x40F5A0 = signal (2, 0x1)
   154   10353 [main] sh 2884 cwdstuff::get: posix /tmp/cygwin
   132  227767 [main] sh 3776 void: 0x40F5A0 = signal (3, 0x1)
    67   10420 [main] sh 2884 cwdstuff::get: (/tmp/cygwin) = 
cwdstuff::get (0x22DF50, 4096, 1, 1), errno 0
    95  227862 [main] sh 3776 fhandler_base::close: closing 
'/tmp/cygwin/freeze.1' handle 0x6E8
    74  227936 [main] sh 3776 fhandler_base::close: closing 
'/tmp/cygwin/freeze.1.err' handle 0x738
    60  227996 [main] sh 3776 sigproc_terminate: entering
    85  228081 [sig] sh 3776 wait_sig: done
     0  228081 [main] sh 3776 proc_terminate: nchildren 0, nzombies 0
   119  228200 [main] sh 3776 proc_subproc: args: 3, 1
     0  228200 [sig] sh 3776 _cygtls::remove: wait 0x0
    69  228269 [main] sh 3776 proc_subproc: clear waiting threads
   625   11045 [main] sh 2884 do_exit: do_exit (0), exit_state 0
   182  228451 [main] sh 3776 proc_subproc: finished clearing
    89   11134 [main] sh 2884 void: 0x0 = signal (20, 0x1)
    90  228541 [main] sh 3776 proc_subproc: returning 1
    94   11228 [main] sh 2884 void: 0x0 = signal (1, 0x1)
    94  228635 [main] sh 3776 proc_terminate: leaving
    94   11322 [main] sh 2884 void: 0x40F5A0 = signal (2, 0x1)
    72   11394 [main] sh 2884 void: 0x40F5A0 = signal (3, 0x1)
   172  228807 [main] sh 3776 __to_clock_t: dwHighDateTime 0, 
dwLowDateTime 312500
   101  228908 [main] sh 3776 __to_clock_t: total 00000000 0000001F
   128   11522 [main] sh 2884 fhandler_base::close: closing 
'/tmp/cygwin/freeze.1' handle 0x6E8
    53  228961 [main] sh 3776 __to_clock_t: dwHighDateTime 0, 
dwLowDateTime 156250
    90   11612 [main] sh 2884 fhandler_base::close: closing 
'/tmp/cygwin/freeze.1.err' handle 0x738
    62  229023 [main] sh 3776 __to_clock_t: total 00000000 0000000F
    55   11667 [main] sh 2884 sigproc_terminate: entering
    75   11742 [sig] sh 2884 wait_sig: done
    54   11796 [sig] sh 2884 _cygtls::remove: wait 0x0
   -55   11741 [main] sh 2884 proc_terminate: nchildren 0, nzombies 0
   231   11972 [main] sh 2884 proc_terminate: leaving
  -201  228822 [proc] sh 3776 wait_subproc: done
   182   12154 [main] sh 2884 __to_clock_t: dwHighDateTime 0, 
dwLowDateTime 0
    51   12205 [main] sh 2884 __to_clock_t: total 00000000 00000000
    49   12254 [main] sh 2884 __to_clock_t: dwHighDateTime 0, 
dwLowDateTime 156250
    53   12307 [main] sh 2884 __to_clock_t: total 00000000 0000000F
  2167  230989 [proc] sh 3776 _cygtls::remove: wait 0x0
   -12  230977 [main] sh 3776 _pinfo::exit: Calling ExitProcess 0
  1599   13906 [main] sh 2884 _pinfo::exit: Calling ExitProcess 0
  6988 1068723 [proc] make 2168 proc_subproc: args: 2, 1
   119 1068842 [proc] make 2168 proc_subproc: pid 3776[1] terminated, 
handle 0x664, nchildren 2, nzombies 4
   247 1069089 [proc] make 2168 proc_subproc: zombifying [1], pid 3776, 
handle 0x664, nchildren 2
    74 1069163 [proc] make 2168 proc_subproc: returning 1
    58 1069221 [proc] make 2168 sig_send: sendsig 0x70C, pid 2168, 
signal 20, its_me 1
    80 1069301 [proc] make 2168 sig_send: Not waiting for sigcomplete. 
its_me 1 signal 20
     6 1069307 [sig] make 2168 sigpacket::process: signal 20 processing
    56 1069363 [proc] make 2168 sig_send: returning 0x0 from sending 
signal 20
    52 1069415 [sig] make 2168 _cygtls::find_tls: sig 20
    54 1069469 [proc] make 2168 wait_subproc: looping
    62 1069531 [sig] make 2168 sigpacket::process: signal 20, about to 
call 0x40C540
    58 1069589 [proc] make 2168 proc_subproc: args: 2, 0
   106 1069695 [proc] make 2168 proc_subproc: pid 2884[0] terminated, 
handle 0x6A0, nchildren 1, nzombies 5
    45 1069740 [proc] make 2168 proc_subproc: zombifying [0], pid 2884, 
handle 0x6A0, nchildren 1
    45 1069785 [proc] make 2168 proc_subproc: returning 1
    45 1069830 [proc] make 2168 sig_send: sendsig 0x70C, pid 2168, 
signal 20, its_me 1
    49 1069879 [proc] make 2168 sig_send: Not waiting for sigcomplete. 
its_me 1 signal 20
    43 1069922 [proc] make 2168 sig_send: returning 0x0 from sending 
signal 20
    43 1069965 [proc] make 2168 wait_subproc: looping
  -321 1069644 [sig] make 2168 setup_handler: trying to send sig 20 but 
signal 20 already armed
   401 1070045 [sig] make 2168 setup_handler: signal 20 not delivered
    41 1070086 [sig] make 2168 sigpacket::process: returning 0
    48 1070134 [sig] make 2168 proc_subproc: args: 3, 0
    40 1070174 [sig] make 2168 proc_subproc: looking for processes to reap
    42 1070216 [sig] make 2168 proc_subproc: finished processing 
terminated/stopped child
    41 1070257 [sig] make 2168 proc_subproc: returning 1
    48 1070305 [sig] make 2168 sigpacket::process: signal 20 processing
    43 1070348 [sig] make 2168 _cygtls::find_tls: sig 20
    43 1070391 [sig] make 2168 sigpacket::process: signal 20, about to 
call 0x40C540
    42 1070433 [sig] make 2168 setup_handler: trying to send sig 20 but 
signal 20 already armed
    42 1070475 [sig] make 2168 setup_handler: signal 20 not delivered
    41 1070516 [sig] make 2168 sigpacket::process: returning 0
    43 1070559 [sig] make 2168 proc_subproc: args: 3, 0
    41 1070600 [sig] make 2168 proc_subproc: looking for processes to reap
    41 1070641 [sig] make 2168 proc_subproc: finished processing 
terminated/stopped child
    43 1070684 [sig] make 2168 proc_subproc: returning 1


--
Unsubscribe info:      http://cygwin.com/ml/#unsubscribe-simple
Problem reports:       http://cygwin.com/problems.html
Documentation:         http://cygwin.com/docs.html
FAQ:                   http://cygwin.com/faq/