On Dec 7, 2010, at 9:55 AM, Christopher Faylor wrote:
> I ran the test case in a loop on my Windows XP system under various
> conditions -
> no load, load, no load with most services stopped. I couldn't reproduce the
> problem.
>
> I also tried on a virtual system running Windows 7 64-bit and couldn't
> duplicate
> it.
>
> So, I'm currently stumped. I guess I'll try to add some instrumentation to
> catch
> the case where this fails.
>
> cgf
That's odd, the test case was failing for me on Win7 x64, x32, and x32 under
virtualization.
FWIW, the test case is apparently working now on the latest snapshot (tried
20101212). But if I run it in strace, there's still an exception message hidden
in the output:
--- Process 3916, exception C0000005 at 610E124A
As mentioned in another message, I was seeing this exception in even the
released 1.7.7-1 cygwin when running in strace (even though the test case was
apparently working). It might be moot, as there's no sign of a problem when the
test case is run normally.
I'll attach the trace output of the testcase running under the latest snapshot.
31 31 [main] testfork 3916 open_shared: name shared.5, n 5, shared
0x60FB0000 (wanted 0x60FB0000), h 0xC8
5734 5765 [main] testfork 3916 heap_init: heap base 0x9B0000, heap top
0x9B0000
1032 6797 [main] testfork 3916 open_shared: name
S-1-5-21-3346415893-1069646457-3062309592-1002.1, n 1, shared 0x60FC0000
(wanted 0x60FC0000), h 0xCC
129 6926 [main] testfork 3916 user_info::create: opening user shared for
'S-1-5-21-3346415893-1069646457-3062309592-1002' at 0x60FC0000
183 7109 [main] testfork 3916 user_info::create: user shared version
6112AFB3
2237 9346 [main] testfork 3916 dll_crt0_0: finished dll_crt0_0
initialization
1419 10765 [main] testfork 3916 _cygtls::remove: wait 0xFFFFFFFF
378 11143 [main] testfork 3916 _cygtls::remove: removed 0x22CE64 element 0
2067 13210 [main] testfork 3916 mount_info::conv_to_posix_path:
conv_to_posix_path (C:\cygwin\home\heath\testfork, no-keep-rel, no-add-slash)
313 13523 [main] testfork 3916 normalize_win32_path:
C:\cygwin\home\heath\testfork = normalize_win32_path
(C:\cygwin\home\heath\testfork)
223 13746 [main] testfork 3916 mount_info::conv_to_posix_path:
/home/heath/testfork = conv_to_posix_path (C:\cygwin\home\heath\testfork)
1054 14800 [main] testfork 3916 _cygwin_istext_for_stdio: fd 0: not open
460 15260 [main] testfork 3916 _cygwin_istext_for_stdio: fd 1: not open
108 15368 [main] testfork 3916 _cygwin_istext_for_stdio: fd 2: not open
561 15929 [main] testfork (3916) open_shared: name cygpid.3916, n 3916,
shared 0x60FE0000 (wanted 0x60FE0000), h 0x114
216 16145 [main] testfork 3916
**********************************************
111 16256 [main] testfork 3916 Program name:
C:\cygwin\home\heath\testfork\testfork.exe (pid 3916, ppid 1)
108 16364 [main] testfork 3916 App version: 1007.7, api: 0.230
107 16471 [main] testfork 3916 DLL version: 1007.8, api: 0.233
107 16578 [main] testfork 3916 DLL build: 20101212 00:50:41SNP
169 16747 [main] testfork 3916 OS version: Windows NT-6.1
106 16853 [main] testfork 3916 Heap size: 402653184
107 16960 [main] testfork 3916
**********************************************
106 17066 [main] testfork 3916 pinfo::thisproc: myself->dwProcessId 3916
200 17266 [main] testfork 3916 time: 1292174607 = time (0)
2122 19388 [main] testfork 3916 parse_options: glob (called func)
257 19645 [main] testfork 3916 parse_options: returning
116 19761 [main] testfork 3916 environ_init: GetEnvironmentStrings returned
0x267A88
233 19994 [main] testfork 3916 environ_init: 0x9D8298: !::=::\
214 20208 [main] testfork 3916 environ_init: 0x9D82A8:
ALLUSERSPROFILE=C:\ProgramData
218 20426 [main] testfork 3916 environ_init: 0x9D82D0:
APPDATA=C:\Users\heath\AppData\Roaming
214 20640 [main] testfork 3916 environ_init: 0x9D8300:
COMMONPROGRAMFILES=C:\Program Files\Common Files
249 20889 [main] testfork 3916 environ_init: 0x9D8338: COMPUTERNAME=HEATH-PC
221 21110 [main] testfork 3916 environ_init: 0x9D8358:
COMSPEC=C:\Windows\system32\cmd.exe
218 21328 [main] testfork 3916 environ_init: 0x9D8388: CVS_RSH=/bin/ssh
218 21546 [main] testfork 3916 environ_init: 0x9D83A0: CYGWIN=noglob
216 21762 [main] testfork 3916 environ_init: 0x9D83B8: FP_NO_HOST_CHECK=NO
255 22017 [main] testfork 3916 getwinenv: can't set native for HOME= since
no environ yet
261 22278 [main] testfork 3916 mount_info::conv_to_posix_path:
conv_to_posix_path (C:\cygwin\home\heath, no-keep-rel, no-add-slash)
113 22391 [main] testfork 3916 normalize_win32_path: C:\cygwin\home\heath =
normalize_win32_path (C:\cygwin\home\heath)
113 22504 [main] testfork 3916 mount_info::conv_to_posix_path: /home/heath
= conv_to_posix_path (C:\cygwin\home\heath)
311 22815 [main] testfork 3916 win_env::add_cache: posix /home/heath
106 22921 [main] testfork 3916 win_env::add_cache: native
HOME=C:\cygwin\home\heath
107 23028 [main] testfork 3916 posify: env var converted to HOME=/home/heath
302 23330 [main] testfork 3916 environ_init: 0x9D8428: HOME=/home/heath
416 23746 [main] testfork 3916 environ_init: 0x9D83D8: HOMEDRIVE=C:
252 23998 [main] testfork 3916 environ_init: 0x9D8440: HOMEPATH=\Users\heath
219 24217 [main] testfork 3916 environ_init: 0x9D8460: HOSTNAME=heath-PC
217 24434 [main] testfork 3916 environ_init: 0x9D8478:
INFOPATH=/usr/local/info:/usr/share/info:/usr/info:
213 24647 [main] testfork 3916 environ_init: 0x9D84B8: LANG=C.UTF-8
214 24861 [main] testfork 3916 environ_init: 0x9D84D0:
LOCALAPPDATA=C:\Users\heath\AppData\Local
213 25074 [main] testfork 3916 environ_init: 0x9D8500:
LOGONSERVER=\\HEATH-PC
213 25287 [main] testfork 3916 environ_init: 0x9D8520:
MANPATH=/usr/local/man:/usr/share/man:/usr/man:
214 25501 [main] testfork 3916 environ_init: 0x9D8558:
NUMBER_OF_PROCESSORS=1
214 25715 [main] testfork 3916 environ_init: 0x9D8578: OLDPWD=/home/heath
233 25948 [main] testfork 3916 environ_init: 0x9D8590: OS=Windows_NT
222 26170 [main] testfork 3916 getwinenv: can't set native for PATH= since
no environ yet
312 26482 [main] testfork 3916 mount_info::conv_to_posix_path:
conv_to_posix_path (C:\cygwin\usr\local\bin, keep-rel, no-add-slash)
113 26595 [main] testfork 3916 normalize_win32_path:
C:\cygwin\usr\local\bin = normalize_win32_path (C:\cygwin\usr\local\bin)
108 26703 [main] testfork 3916 mount_info::conv_to_posix_path:
/usr/local/bin = conv_to_posix_path (C:\cygwin\usr\local\bin)
112 26815 [main] testfork 3916 mount_info::conv_to_posix_path:
conv_to_posix_path (C:\cygwin\bin, keep-rel, no-add-slash)
112 26927 [main] testfork 3916 normalize_win32_path: C:\cygwin\bin =
normalize_win32_path (C:\cygwin\bin)
107 27034 [main] testfork 3916 mount_info::conv_to_posix_path: /usr/bin =
conv_to_posix_path (C:\cygwin\bin)
107 27141 [main] testfork 3916 mount_info::conv_to_posix_path:
conv_to_posix_path (C:\cygwin\bin, keep-rel, no-add-slash)
109 27250 [main] testfork 3916 normalize_win32_path: C:\cygwin\bin =
normalize_win32_path (C:\cygwin\bin)
107 27357 [main] testfork 3916 mount_info::conv_to_posix_path: /usr/bin =
conv_to_posix_path (C:\cygwin\bin)
107 27464 [main] testfork 3916 mount_info::conv_to_posix_path:
conv_to_posix_path (C:\Windows\system32, keep-rel, no-add-slash)
111 27575 [main] testfork 3916 normalize_win32_path: C:\Windows\system32 =
normalize_win32_path (C:\Windows\system32)
108 27683 [main] testfork 3916 mount_info::conv_to_posix_path:
/cygdrive/c/Windows/system32 = conv_to_posix_path (C:\Windows\system32)
111 27794 [main] testfork 3916 mount_info::conv_to_posix_path:
conv_to_posix_path (C:\Windows, keep-rel, no-add-slash)
112 27906 [main] testfork 3916 normalize_win32_path: C:\Windows =
normalize_win32_path (C:\Windows)
107 28013 [main] testfork 3916 mount_info::conv_to_posix_path:
/cygdrive/c/Windows = conv_to_posix_path (C:\Windows)
108 28121 [main] testfork 3916 mount_info::conv_to_posix_path:
conv_to_posix_path (C:\Windows\System32\Wbem, keep-rel, no-add-slash)
111 28232 [main] testfork 3916 normalize_win32_path:
C:\Windows\System32\Wbem = normalize_win32_path (C:\Windows\System32\Wbem)
107 28339 [main] testfork 3916 mount_info::conv_to_posix_path:
/cygdrive/c/Windows/System32/Wbem = conv_to_posix_path
(C:\Windows\System32\Wbem)
108 28447 [main] testfork 3916 mount_info::conv_to_posix_path:
conv_to_posix_path (C:\Windows\System32\WindowsPowerShell\v1.0\, keep-rel,
add-slash)
246 28693 [main] testfork 3916 normalize_win32_path:
C:\Windows\System32\WindowsPowerShell\v1.0\ = normalize_win32_path
(C:\Windows\System32\WindowsPowerShell\v1.0\)
114 28807 [main] testfork 3916 mount_info::conv_to_posix_path:
/cygdrive/c/Windows/System32/WindowsPowerShell/v1.0/ = conv_to_posix_path
(C:\Windows\System32\WindowsPowerShell\v1.0\)
112 28919 [main] testfork 3916 mount_info::conv_to_posix_path:
conv_to_posix_path (C:\Program Files\Perforce, keep-rel, no-add-slash)
111 29030 [main] testfork 3916 normalize_win32_path: C:\Program
Files\Perforce = normalize_win32_path (C:\Program Files\Perforce)
108 29138 [main] testfork 3916 mount_info::conv_to_posix_path:
/cygdrive/c/Program Files/Perforce = conv_to_posix_path (C:\Program
Files\Perforce)
516 29654 [main] testfork 3916 win_env::add_cache: posix
/usr/local/bin:/usr/bin:/usr/bin:/cygdrive/c/Windows/system32:/cygdrive/c/Windows:/cygdrive/c/Windows/System32/Wbem:/cygdrive/c/Windows/System32/WindowsPowerShell/v1.0/:/cygdrive/c/Program
Files/Perforce
143 29797 [main] testfork 3916 win_env::add_cache: native
PATH=C:\cygwin\usr\local\bin;C:\cygwin\bin;C:\cygwin\bin;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Windows\System32\WindowsPowerShell\v1.0\;C:\Program
Files\Perforce
109 29906 [main] testfork 3916 posify: env var converted to
PATH=/usr/local/bin:/usr/bin:/usr/bin:/cygdrive/c/Windows/system32:/cygdrive/c/Windows:/cygdrive/c/Windows/System32/Wbem:/cygdrive/c/Windows/System32/WindowsPowerShell/v1.0/:/cygdrive/c/Program
Files/Perforce
331 30237 [main] testfork 3916 environ_init: 0x9E8800:
PATH=/usr/local/bin:/usr/bin:/usr/bin:/cygdrive/c/Windows/system32:/cygdrive/c/Windows:/cygdrive/c/Windows/System32/Wbem:/cygdrive/c/Windows/System32/WindowsPowerShell/v1.0/:/cygdrive/c/Program
Files/Perforce
213 30450 [main] testfork 3916 environ_init: 0x9D85A8:
PATHEXT=.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC
221 30671 [main] testfork 3916 environ_init: 0x9D85F0: PRINTER=Brother
MFC-7820N USB Printer
246 30917 [main] testfork 3916 environ_init: 0x9D8620:
PROCESSOR_ARCHITECTURE=x86
222 31139 [main] testfork 3916 environ_init: 0x9E88D8:
PROCESSOR_IDENTIFIER=x86 Family 6 Model 23 Stepping 10, GenuineIntel
228 31367 [main] testfork 3916 environ_init: 0x9D8640: PROCESSOR_LEVEL=6
227 31594 [main] testfork 3916 environ_init: 0x9E8928:
PROCESSOR_REVISION=170a
232 31826 [main] testfork 3916 environ_init: 0x9E8948:
PROGRAMFILES=C:\Program Files
232 32058 [main] testfork 3916 environ_init: 0x9E8970:
PS1=\[\e]0;\w\a\]\n\[\e[32m\...@\h \[\e[33m\]\w\[\e[0m\]\n\$
359 32417 [main] testfork 3916 environ_init: 0x9E89B8:
PSModulePath=C:\Windows\system32\WindowsPowerShell\v1.0\Modules\
232 32649 [main] testfork 3916 environ_init: 0x9E8A00:
PUBLIC=C:\Users\Public
231 32880 [main] testfork 3916 environ_init: 0x9E8A20:
PWD=/home/heath/testfork
232 33112 [main] testfork 3916 environ_init: 0x9E8A40:
ProgramData=C:\ProgramData
228 33340 [main] testfork 3916 environ_init: 0x9E8A60: SESSIONNAME=Console
210 33550 [main] testfork 3916 environ_init: 0x9D8658: SHLVL=1
214 33764 [main] testfork 3916 environ_init: 0x9E8A80: SYSTEMDRIVE=C:
214 33978 [main] testfork 3916 environ_init: 0x9E8A98: SYSTEMROOT=C:\Windows
213 34191 [main] testfork 3916 environ_init: 0x9E8AB8: TERM=xterm
209 34400 [main] testfork 3916 environ_init: 0x9E8AC8: USER=heath
209 34609 [main] testfork 3916 environ_init: 0x9E8AD8: USERDOMAIN=heath-PC
205 34814 [main] testfork 3916 environ_init: 0x9E8AF8: USERNAME=heath
209 35023 [main] testfork 3916 environ_init: 0x9E8B10:
USERPROFILE=C:\Users\heath
213 35236 [main] testfork 3916 environ_init: 0x9E8B30: WINDIR=C:\Windows
213 35449 [main] testfork 3916 environ_init: 0x9E8B48: _=/usr/bin/strace
223 35672 [main] testfork 3916 pinfo_init: Set nice to 0
113 35785 [main] testfork 3916 pinfo_init: pid 3916, pgid 3916
460 36245 [main] testfork 3916 dtable::extend: size 32, fds 0x6124168C
1161 37406 [main] testfork 3916 pwdgrp::load: \etc\passwd curr_lines 8
144 37550 [main] testfork 3916 pwdgrp::load: \etc\passwd load succeeded
1404 38954 [main] testfork 3916 pwdgrp::load: \etc\group curr_lines 18
125 39079 [main] testfork 3916 pwdgrp::load: \etc\group load succeeded
181 39260 [main] testfork 3916 cygheap_user::ontherange: what 2, pw 0x9E8F10
110 39370 [main] testfork 3916 cygheap_user::ontherange: HOME is already in
the environment /home/heath
836 40206 [main] testfork 3916 build_argv: argv[0] =
'C:\cygwin\home\heath\testfork\testfork'
108 40314 [main] testfork 3916 build_argv: argc 1
274 40588 [main] testfork 3916 mount_info::conv_to_posix_path:
conv_to_posix_path (C:\cygwin\home\heath\testfork\testfork, keep-rel,
no-add-slash)
209 40797 [main] testfork 3916 normalize_win32_path:
C:\cygwin\home\heath\testfork\testfork = normalize_win32_path
(C:\cygwin\home\heath\testfork\testfork)
174 40971 [main] testfork 3916 mount_info::conv_to_posix_path:
/home/heath/testfork/testfork = conv_to_posix_path
(C:\cygwin\home\heath\testfork\testfork)
1678 42649 [main] testfork 3916 build_fh_pc: fh 0x612417E4
257 42906 [main] testfork 3916 fhandler_pipe::create_selectable:
CreateNamedPipe: name \\.\pipe\cygwin-c5e39b7a9d22bafb-tty0-from-master, size
4096
790 43696 [sig] testfork 3916 wait_sig: entering ReadFile loop, my_readsig
0xEC, my_sendsig 0xF0
485 44181 [main] testfork 3916 fhandler_pipe::create_selectable: pipe busy
124 44305 [main] testfork 3916 fhandler_base::set_flags: flags 0x10002,
supplied_bin 0x0
171 44476 [main] testfork 3916 fhandler_base::set_flags: O_TEXT/O_BINARY
set in flags 0x10000
108 44584 [main] testfork 3916 fhandler_base::set_flags: filemode set to
binary
430 45014 [main] testfork 3916 alloc_sd: uid 1002, gid 513, attribute 2190
170 45184 [main] testfork 3916 cygsid::debug_print: alloc_sd: owner SID =
S-1-5-21-3346415893-1069646457-3062309592-1002 (+)
113 45297 [main] testfork 3916 cygsid::debug_print: alloc_sd: group SID =
S-1-5-21-3346415893-1069646457-3062309592-513 (+)
159 45456 [main] testfork 3916 alloc_sd: ACL-Size: 124
359 45815 [main] testfork 3916 alloc_sd: Created SD-Size: 200
108 45923 [main] testfork 3916 fhandler_tty_slave::open: (538): tty
output_mutex: waiting 500 ms
240 46163 [main] testfork 3916 fhandler_tty_slave::open: (538): tty
output_mutex: acquired
145 46308 [main] testfork 3916 tty::create_inuse: cygtty.slave_alive.0 0x12C
149 46457 [main] testfork 3916 fhandler_tty_slave::open: (541): tty
output_mutex released
254 46711 [main] testfork 3916 open_shared: name cygpid.2808, n 2808,
shared 0x3D0000 (wanted 0x0), h 0x130
174 46885 [main] testfork 3916 fhandler_tty_slave::open: dup handles
directly since I'm allmighty.
249 47134 [main] testfork 3916 fhandler_tty_slave::open: duplicated
from_master 0x1BC->0x130 from tty_owner
110 47244 [main] testfork 3916 fhandler_tty_slave::open: duplicated
to_master 0x1C4->0x138 from tty_owner
113 47357 [main] testfork 3916 init_cygheap::manage_console_count:
fhandler_tty_slave::open: console_count 1, amount 1, no ctty,
avoid_freeing_console 0
231 47588 [main] testfork 3916 fhandler_console::need_invisible:
invisible_console 0
286 47874 [main] testfork 3916 fhandler_tty_slave::open: /dev/tty0 opened,
usecount 1
114 47988 [main] testfork 3916 _pinfo::set_ctty: old no ctty
110 48098 [main] testfork 3916 _pinfo::set_ctty: attaching ctty /dev/tty0
sid 3916, pid 3916, pgid 3916, tty->pgid 3268, tty->sid 3872
154 48252 [main] testfork 3916 open_shared: name cygpid.3872, n 3872,
shared 0x3D0000 (wanted 0x0), h 0x134
163 48415 [main] testfork 3916 _pinfo::set_ctty: cygheap->ctty 0x0, arch
0x61241A3C
217 48632 [main] testfork 3916 _pinfo::set_ctty: ctty NULL
136 48768 [main] testfork 3916 init_cygheap::manage_console_count:
_pinfo::set_ctty: console_count 2, amount 1, ctty /dev/tty0,
avoid_freeing_console 0
108 48876 [main] testfork 3916 _pinfo::set_ctty: /dev/tty0 ctty, usecount 2
494 49370 [main] testfork 3916 build_fh_pc: fh 0x61241CDC
117 49487 [main] testfork 3916 fhandler_tty_slave::open: copied
fhandler_tty_slave archetype
115 49602 [main] testfork 3916 fhandler_base::set_flags: flags 0x10002,
supplied_bin 0x0
107 49709 [main] testfork 3916 fhandler_base::set_flags: O_TEXT/O_BINARY
set in flags 0x10000
107 49816 [main] testfork 3916 fhandler_base::set_flags: filemode set to
binary
107 49923 [main] testfork 3916 init_cygheap::manage_console_count:
fhandler_tty_slave::open<arch>: console_count 3, amount 1, ctty /dev/tty0,
avoid_freeing_console 0
108 50031 [main] testfork 3916 fhandler_tty_slave::open: /dev/tty0 opened,
usecount 3
107 50138 [main] testfork 3916 _pinfo::set_ctty: old ctty /dev/tty0
294 50432 [main] testfork 3916 _pinfo::set_ctty: attaching ctty /dev/tty0
sid 3872, pid 3916, pgid 3916, tty->pgid 3268, tty->sid 3872
155 50587 [main] testfork 3916 open_shared: name cygpid.3872, n 3872,
shared 0x3D0000 (wanted 0x0), h 0x1EC
397 50984 [main] testfork 3916 fhandler_console::need_invisible:
invisible_console 0
180 51164 [main] testfork 3916 __set_errno: void dll_crt0_1(void*):947 val 0
1254 52418 [main] testfork 3916 sig_send: sendsig 0xF0, pid 3916, signal
-39, its_me 1
113 52531 [main] testfork 3916 sig_send: wakeup 0x1EC
308 52839 [sig] testfork 3916 wait_sig: signalling pack.wakeup 0x1EC
110 52949 [main] testfork 3916 sig_send: Waiting for pack.wakeup 0x1EC
111 53060 [main] testfork 3916 sig_send: returning 0x0 from sending signal
-39
180 53240 [main] testfork 3916 set_signal_mask: oldmask 0x0, newmask 0x0,
mask_bits 0x0
143 53383 [main] testfork 3916 set_signal_mask: not calling
sig_dispatch_pending
--- Process 3916, exception C0000005 at 610E124A
264 53647 [main] testfork 3916 exception::handle: In cygwin_except_handler
exc 0xC0000005 at 0x610E124A sp 0x22CA90
123 53770 [main] testfork 3916 exception::handle: In cygwin_except_handler
sig 11 at 0x610E124A
108 53878 [main] testfork 3916 exception::handle: In cygwin_except_handler
calling 0x0
21822 75700 [main] testfork 3916 set_signal_mask: oldmask 0x0, newmask
0xFDFEFAFF, mask_bits 0x0
135 75835 [main] testfork 3916 set_signal_mask: not calling
sig_dispatch_pending
116 75951 [main] testfork 3916 sig_send: sendsig 0xF0, pid 3916, signal
-34, its_me 1
122 76073 [main] testfork 3916 sig_send: wakeup 0x170
145 76218 [sig] testfork 3916 wait_sig: signalling pack.wakeup 0x170
124 76342 [main] testfork 3916 sig_send: Waiting for pack.wakeup 0x170
116 76458 [main] testfork 3916 sig_send: returning 0x0 from sending signal
-34
73586 150044 [main] testfork 3916 nanosleep: nanosleep (200)
201310 351354 [main] testfork 3916 nanosleep: 0 = nanosleep (200, 0)
784 352138 [main] testfork 3916 _cygwin_istext_for_stdio: fd 0: opened as
binary
141 352279 [main] testfork 3916 _cygwin_istext_for_stdio: fd 1: opened as
binary
158 352437 [main] testfork 3916 _cygwin_istext_for_stdio: fd 2: not open
871 353308 [main] testfork 3916 fhandler_base::fstat: here
154 353462 [main] testfork 3916 time: 1292174607 = time (0)
304 353766 [main] testfork 3916 cygpsid::debug_print: get_sids_info: owner
SID = S-1-5-21-3346415893-1069646457-3062309592-1002
159 353925 [main] testfork 3916 cygpsid::debug_print: get_sids_info: group
SID = S-1-5-21-3346415893-1069646457-3062309592-513
133 354058 [main] testfork 3916 get_info_from_sd: ACL 2190, uid 1002, gid 513
226 354284 [main] testfork 3916 fstat64: 0 = fstat (1, 0x22C4A8)
314 354598 [main] testfork 3916 isatty: 1 = isatty (1)
695 355293 [main] testfork 3916 fhandler_tty_slave::write: tty0,
write(9E95C8, 12)
118 355411 [main] testfork 3916 fhandler_tty_slave::write: (746): tty
output_mutex: waiting -1 ms
117 355528 [main] testfork 3916 fhandler_tty_slave::write: (746): tty
output_mutex: acquired
123 355651 [main] testfork 3916 fhandler_tty_slave::write: (789): tty
output_mutex released
1091 356742 [main] testfork 3916 set_signal_mask: oldmask 0xFDFEFAFF, newmask
0x0, mask_bits 0xFDFEFAFF
118 356860 [main] testfork 3916 sig_send: sendsig 0xF0, pid 3916, signal
-39, its_me 1
123 356983 [main] testfork 3916 sig_send: wakeup 0x174
200 357183 [sig] testfork 3916 wait_sig: signalling pack.wakeup 0x174
131 357314 [main] testfork 3916 sig_send: Waiting for pack.wakeup 0x174
140 357454 [main] testfork 3916 sig_send: returning 0x0 from sending signal
-39
1854 359308 [unknown (0x670)] testfork 3916 _cygtls::remove: wait 0x0
124 359432 [unknown (0x670)] testfork 3916 _cygtls::remove: removed
0x18DACE64 element 1
1613 361045 [main] testfork 3916 child_info::child_info: subproc_ready 0x13C
149 361194 [main] testfork 3916 fork: entering
1088 362282 [main] testfork 3916 sig_send: sendsig 0xF0, pid 3916, signal
-40, its_me 1
257 362539 [main] testfork 3916 sig_send: wakeup 0x158
187 362726 [sig] testfork 3916 wait_sig: signalling pack.wakeup 0x158
113 362839 [main] testfork 3916 sig_send: Waiting for pack.wakeup 0x158
112 362951 [main] testfork 3916 sig_send: returning 0x0 from sending signal
-40
176 363127 [main] testfork 3916 frok::parent: priority class 32
476 363603 [main] testfork 3916 frok::parent: stack - bottom 0x230000, top
0x22CB30, size 13520
113 363716 [main] testfork 3916 frok::parent: CreateProcessW
(C:\cygwin\home\heath\testfork\testfork.exe,
C:\cygwin\home\heath\testfork\testfork.exe, 0, 0, 1, 0x20, 0, 0, 0x22CAA8,
0x22CB08)
113 363829 [main] testfork 3916 time: 1292174607 = time (0)
13282 377111 [main] testfork 3916 child_info::sync: n 2, waiting for
subproc_ready(0x13C) and child process(0x178)
47 47 [main] testfork 1236 child_copy: cygheap - hp 0x140 low
0x61240880, high 0x61241F6C, res 1
512 559 [main] testfork 1236 child_copy: done
474 1033 [main] testfork 1236 open_shared: name shared.5, n 5, shared
0x60FB0000 (wanted 0x60FB0000), h 0x88
333 1366 [main] testfork 1236 heap_init: heap base 0x9B0000, heap top
0xA00000
139 1505 [main] testfork 1236 open_shared: name (null), n 1, shared
0x60FC0000 (wanted 0x60FC0000), h 0xCC
112 1617 [main] testfork 1236 user_info::create: opening user shared for
'' at 0x60FC0000
146 1763 [main] testfork 1236 user_info::create: user shared version
6112AFB3
228 1991 [main] testfork (1236) open_shared: name cygpid.1236, n 1236,
shared 0x60FE0000 (wanted 0x60FE0000), h 0x98
203 2194 [main] testfork 1236
**********************************************
145 2339 [main] testfork 1236 Program name:
C:\cygwin\home\heath\testfork\testfork.exe (pid 1236, ppid 1)
120 2459 [main] testfork 1236 App version: 1007.8, api: 0.0
114 2573 [main] testfork 1236 DLL version: 1007.8, api: 0.233
102 2675 [main] testfork 1236 DLL build: 20101212 00:50:41SNP
151 2826 [main] testfork 1236 OS version: Windows NT-6.1
102 2928 [main] testfork 1236 Heap size: 402653184
134 3062 [main] testfork 1236
**********************************************
103 3165 [main] testfork 1236 pinfo::thisproc: myself->dwProcessId 1236
1295 4460 [main] testfork 1236 child_copy: dll data - hp 0x140 low
0x6115E000, high 0x61166DA4, res 1
410726 415186 [main] testfork 1236 child_copy: dll bss - hp 0x140 low
0x611DA000, high 0x6120E8D8, res 1
2715 417901 [main] testfork 1236 child_copy: user heap - hp 0x140 low
0x9B0000, high 0xA00000, res 1
132 418033 [main] testfork 1236 child_copy: done
332 418365 [main] testfork 1236 child_copy: data - hp 0x140 low 0x402000,
high 0x402020, res 1
172 418537 [main] testfork 1236 child_copy: bss - hp 0x140 low 0x403000,
high 0x403120, res 1
112 418649 [main] testfork 1236 child_copy: done
168 418817 [main] testfork 1236 fixup_mmaps_after_fork: succeeded
1022 419839 [main] testfork 1236 dll_crt0_0: finished dll_crt0_0
initialization
640 420479 [main] testfork 1236 _cygtls::remove: wait 0xFFFFFFFF
267 420746 [main] testfork 1236 _cygtls::remove: removed 0x22CE64 element 0
453 421199 [main] testfork 1236 frok::child: child is running. pid 1236,
ppid 0, stack here 0x22CB28
133 421332 [main] testfork 1236 sync_with_parent: signalling parent: after
longjmp
117 421449 [main] testfork 1236 child_info::ready: signalled 0x13C that I
was ready
44542 421653 [main] testfork 3916 child_info::sync: pid 1236, WFMO returned 0,
res 1
205 421858 [main] testfork 3916 open_shared: name cygpid.1236, n 1236,
shared 0x3E0000 (wanted 0x0), h 0x174
354 422212 [main] testfork 3916 proc_subproc: args: 1, 2280172
373 422585 [main] testfork 3916 _pinfo::dup_proc_pipe: duped wr_proc_pipe
0xE0 for pid 1236(1236)
574 423159 [main] testfork 3916 pinfo::wait: created tracking thread for pid
1236, winpid 0x4D4, rd_pipe 0x180
112 423271 [main] testfork 3916 proc_subproc: added pid 1236 to proc table,
slot 0
237 423508 [main] testfork 3916 proc_subproc: returning 1
150 423658 [main] testfork 3916 frok::parent: child is alive (but stopped)
4268 427926 [main] testfork 3916 child_copy: stack - hp 0x178 low 0x22CB30,
high 0x230000, res 1
900 428826 [main] testfork 3916 child_copy: done
124 428950 [main] testfork 3916 frok::parent: copying data/bss of a linked
dll
1080 430030 [main] testfork 3916 child_copy: linked dll data - hp 0x178 low
0x65B82000, high 0x65B820C0, res 1
320 430350 [main] testfork 3916 child_copy: linked dll bss - hp 0x178 low
0x65B83000, high 0x65B83130, res 1
113 430463 [main] testfork 3916 child_copy: done
121 430584 [main] testfork 3916 resume_child: signalled child
142 430726 [main] testfork 3916 child_info::sync: n 2, waiting for
subproc_ready(0x13C) and child process(0x178)
9587 431036 [main] testfork 1236 sync_with_parent: awake
199 431235 [main] testfork 1236 sync_with_parent: no problems
113 431348 [main] testfork 1236 frok::child: hParent 0x140, load_dlls 0
212 431560 [main] testfork 1236 dtable::fixup_after_fork: fd 0 (/dev/tty0)
326 431886 [main] testfork 1236 fhandler_tty_slave::fixup_after_fork:
/dev/tty0 inherited, usecount 3
467 432353 [main] testfork 1236 dtable::fixup_after_fork: fd 1 (/dev/tty0)
114 432467 [main] testfork 1236 fhandler_tty_slave::fixup_after_fork:
/dev/tty0 inherited, usecount 3
159 432626 [main] testfork 1236 sync_with_parent: signalling parent:
performed fork fixup
111 432737 [main] testfork 1236 child_info::ready: signalled 0x13C that I
was ready
2521 435258 [main] testfork 1236 fork: 0 = fork()
216 435474 [main] testfork 1236 set_signal_mask: oldmask 0x0, newmask 0x0,
mask_bits 0x0
140 435614 [main] testfork 1236 set_signal_mask: not calling
sig_dispatch_pending
6229 436955 [main] testfork 3916 child_info::sync: pid 1236, WFMO returned 0,
res 1
205 437160 [main] testfork 3916 sig_send: sendsig 0xF0, pid 3916, signal
-41, its_me 1
153 437313 [main] testfork 3916 sig_send: wakeup 0x158
179 437492 [sig] testfork 3916 wait_sig: signalling pack.wakeup 0x158
117 437609 [main] testfork 3916 sig_send: Waiting for pack.wakeup 0x158
124 437733 [main] testfork 3916 sig_send: returning 0x0 from sending signal
-41
754 438487 [main] testfork 3916 fork: 1236 = fork()
119 438606 [main] testfork 3916 set_signal_mask: oldmask 0x0, newmask 0x0,
mask_bits 0x0
126 438732 [main] testfork 3916 set_signal_mask: not calling
sig_dispatch_pending
6980 445712 [proc_waiter] testfork 3916 cygthread::stub: thread
'proc_waiter', id 0xE70, stack_ptr 0x18DACDA0
14419 450033 [sig] testfork 1236 wait_sig: entering ReadFile loop, my_readsig
0xC0, my_sendsig 0xD0
14125 464158 [main] testfork 1236 set_signal_mask: oldmask 0x0, newmask
0xFDFEFAFF, mask_bits 0x0
150 464308 [main] testfork 1236 set_signal_mask: not calling
sig_dispatch_pending
141 464449 [main] testfork 1236 set_signal_mask: oldmask 0xFDFEFAFF, newmask
0xFDFEFAFF, mask_bits 0x0
119 464568 [main] testfork 1236 set_signal_mask: not calling
sig_dispatch_pending
1161 465729 [main] testfork 1236 fhandler_tty_slave::write: tty0,
write(9E95C8, 17)
168 465897 [main] testfork 1236 fhandler_tty_slave::write: (746): tty
output_mutex: waiting -1 ms
117 466014 [main] testfork 1236 fhandler_tty_slave::write: (746): tty
output_mutex: acquired
127 466141 [main] testfork 1236 fhandler_tty_slave::write: (789): tty
output_mutex released
2464 468605 [main] testfork 1236 close: close (0)
157 468762 [main] testfork 1236 init_cygheap::manage_console_count:
fhandler_tty_slave::close: console_count 2, amount -1, ctty /dev/tty0,
avoid_freeing_console 0
117 468879 [main] testfork 1236 fhandler_tty_slave::close: /dev/tty0 closed,
usecount 2
114 468993 [main] testfork 1236 fhandler_tty_slave::close: just returning
because archetype usecount is != 0
1197 470190 [main] testfork 1236 close: 0 = close (0)
1642 471832 [main] testfork 1236 close: close (1)
115 471947 [main] testfork 1236 init_cygheap::manage_console_count:
fhandler_tty_slave::close: console_count 1, amount -1, ctty /dev/tty0,
avoid_freeing_console 0
3961 475908 [main] testfork 1236 fhandler_tty_slave::close: /dev/tty0 closed,
usecount 1
946 476854 [main] testfork 1236 fhandler_tty_slave::close: just returning
because archetype usecount is != 0
139 476993 [main] testfork 1236 close: 0 = close (1)
2055 479048 [main] testfork 1236 close: close (2)
1817 480865 [main] testfork 1236 __set_errno:
cygheap_fdget::cygheap_fdget(int, bool, bool):393 val 9
330 481195 [main] testfork 1236 close: -1 = close (2)
877 482072 [main] testfork 1236 do_exit: do_exit (0), exit_state 1
243 482315 [main] testfork 1236 void: 0x0 = signal (20, 0x1)
115 482430 [main] testfork 1236 void: 0x0 = signal (1, 0x1)
114 482544 [main] testfork 1236 void: 0x0 = signal (2, 0x1)
113 482657 [main] testfork 1236 void: 0x0 = signal (3, 0x1)
160 482817 [main] testfork 1236 init_cygheap::close_ctty: closing
cygheap->ctty 0x61241A3C
124 482941 [main] testfork 1236 init_cygheap::manage_console_count:
fhandler_tty_slave::close: console_count 0, amount -1, ctty /dev/tty0,
avoid_freeing_console 0
138 483079 [main] testfork 1236 fhandler_tty_slave::close: /dev/tty0 closed,
usecount 0
114 483193 [main] testfork 1236 fhandler_tty_slave::close: closing last open
/dev/tty0 handle
125 483318 [main] testfork 1236 fhandler_tty_common::close: tty0
<0x130,0x138> closing
297 483615 [main] testfork 1236 sigproc_terminate: entering
191 483806 [main] testfork 1236 sig_send: sendsig 0xD0, pid 1236, signal
-42, its_me 1
219 484025 [sig] testfork 1236 wait_sig: saw __SIGEXIT
114 484139 [sig] testfork 1236 wait_sig: signal thread exiting
1304 485443 [main] testfork 1236 sig_send: Not waiting for sigcomplete.
its_me 1 signal -42
113 485556 [main] testfork 1236 sig_send: returning 0x0 from sending signal
-42
186 485742 [main] testfork 1236 proc_terminate: nprocs 0
115 485857 [main] testfork 1236 proc_terminate: leaving
269 486126 [main] testfork 1236 __to_clock_t: dwHighDateTime 0,
dwLowDateTime 200288
115 486241 [main] testfork 1236 __to_clock_t: total 00000000 00000014
142 486383 [main] testfork 1236 __to_clock_t: dwHighDateTime 0,
dwLowDateTime 400576
128 486511 [main] testfork 1236 __to_clock_t: total 00000000 00000028
2263 488774 [main] testfork 1236 pinfo::exit: Calling ExitProcess n 0x0,
exitcode 0x0
49992 495704 [proc_waiter] testfork 3916
pinfo::maybe_set_exit_code_from_windows: pid 1236, exit value - old 0x8000000,
windows 0xDEADBEEF, cygwin 0x8000000
245 495949 [proc_waiter] testfork 3916 sig_send: sendsig 0xF0, pid 3916,
signal 20, its_me 1
201 496150 [sig] testfork 3916 sigpacket::process: signal 20 processing
115 496265 [sig] testfork 3916 _cygtls::find_tls: sig 20
104 496369 [sig] testfork 3916 sigpacket::process: default signal 20 ignored
84 496453 [sig] testfork 3916 sigpacket::process: returning 1
84 496537 [sig] testfork 3916 proc_subproc: args: 3, 0
84 496621 [sig] testfork 3916 proc_subproc: looking for processes to reap,
nprocs 1
84 496705 [sig] testfork 3916 proc_subproc: finished processing
terminated/stopped child
82 496787 [sig] testfork 3916 proc_subproc: returning 1
122 496909 [proc_waiter] testfork 3916 sig_send: Not waiting for
sigcomplete. its_me 1 signal 20
111 497020 [proc_waiter] testfork 3916 sig_send: returning 0x0 from sending
signal 20
124 497144 [proc_waiter] testfork 3916 proc_waiter: exiting wait thread for
pid 1236
21043 518187 [main] testfork 3916 set_signal_mask: oldmask 0x0, newmask
0xFDFEFAFF, mask_bits 0x0
385 518572 [main] testfork 3916 set_signal_mask: not calling
sig_dispatch_pending
117 518689 [main] testfork 3916 set_signal_mask: oldmask 0xFDFEFAFF, newmask
0xFDFEFAFF, mask_bits 0x0
116 518805 [main] testfork 3916 set_signal_mask: not calling
sig_dispatch_pending
2044 520849 [main] testfork 3916 fhandler_tty_slave::write: tty0,
write(9E95C8, 20)
144 520993 [main] testfork 3916 fhandler_tty_slave::write: (746): tty
output_mutex: waiting -1 ms
124 521117 [main] testfork 3916 fhandler_tty_slave::write: (746): tty
output_mutex: acquired
933 522050 [main] testfork 3916 fhandler_tty_slave::write: (789): tty
output_mutex released
857 522907 [main] testfork 3916 sig_send: sendsig 0xF0, pid 3916, signal
-34, its_me 1
138 523045 [main] testfork 3916 sig_send: wakeup 0x180
208 523253 [sig] testfork 3916 wait_sig: signalling pack.wakeup 0x180
149 523402 [main] testfork 3916 sig_send: Waiting for pack.wakeup 0x180
127 523529 [main] testfork 3916 sig_send: returning 0x0 from sending signal
-34
139 523668 [main] testfork 3916 wait4: calling proc_subproc, pid 1236,
options 0
122 523790 [main] testfork 3916 proc_subproc: args: 4, 2284288
129 523919 [main] testfork 3916 proc_subproc: wval->pid 1236, wval->options 0
149 524068 [main] testfork 3916 checkstate: nprocs 1
215 524283 [main] testfork 3916 stopped_or_terminated: considering pid 1236
164 524447 [main] testfork 3916 remove_proc: removing procs[0], pid 1236,
nprocs 1
503 524950 [main] testfork 3916 checkstate: returning 1
172 525122 [main] testfork 3916 proc_subproc: released waiting thread
126 525248 [main] testfork 3916 proc_subproc: finished processing
terminated/stopped child
117 525365 [main] testfork 3916 proc_subproc: returning 1
120 525485 [main] testfork 3916 wait4: 0 = WaitForSingleObject (...)
134 525619 [main] testfork 3916 wait4: intpid 1236, status 0x22CCBC,
w->status 0, options 0, res 1236
709 526328 [main] testfork 3916 fhandler_tty_slave::write: tty0,
write(9E95C8, 26)
125 526453 [main] testfork 3916 fhandler_tty_slave::write: (746): tty
output_mutex: waiting -1 ms
120 526573 [main] testfork 3916 fhandler_tty_slave::write: (746): tty
output_mutex: acquired
129 526702 [main] testfork 3916 fhandler_tty_slave::write: (789): tty
output_mutex released
2808 529510 [main] testfork 3916 close: close (0)
253 529763 [main] testfork 3916 init_cygheap::manage_console_count:
fhandler_tty_slave::close: console_count 2, amount -1, ctty /dev/tty0,
avoid_freeing_console 0
131 529894 [main] testfork 3916 fhandler_tty_slave::close: /dev/tty0 closed,
usecount 2
141 530035 [main] testfork 3916 fhandler_tty_slave::close: just returning
because archetype usecount is != 0
125 530160 [main] testfork 3916 close: 0 = close (0)
1600 531760 [main] testfork 3916 close: close (1)
119 531879 [main] testfork 3916 init_cygheap::manage_console_count:
fhandler_tty_slave::close: console_count 1, amount -1, ctty /dev/tty0,
avoid_freeing_console 0
167 532046 [main] testfork 3916 fhandler_tty_slave::close: /dev/tty0 closed,
usecount 1
127 532173 [main] testfork 3916 fhandler_tty_slave::close: just returning
because archetype usecount is != 0
119 532292 [main] testfork 3916 close: 0 = close (1)
1866 534158 [main] testfork 3916 close: close (2)
117 534275 [main] testfork 3916 __set_errno:
cygheap_fdget::cygheap_fdget(int, bool, bool):393 val 9
117 534392 [main] testfork 3916 close: -1 = close (2)
892 535284 [main] testfork 3916 do_exit: do_exit (0), exit_state 1
118 535402 [main] testfork 3916 void: 0x0 = signal (20, 0x1)
122 535524 [main] testfork 3916 void: 0x0 = signal (1, 0x1)
117 535641 [main] testfork 3916 void: 0x0 = signal (2, 0x1)
117 535758 [main] testfork 3916 void: 0x0 = signal (3, 0x1)
164 535922 [main] testfork 3916 init_cygheap::close_ctty: closing
cygheap->ctty 0x61241A3C
123 536045 [main] testfork 3916 init_cygheap::manage_console_count:
fhandler_tty_slave::close: console_count 0, amount -1, ctty /dev/tty0,
avoid_freeing_console 0
118 536163 [main] testfork 3916 fhandler_tty_slave::close: /dev/tty0 closed,
usecount 0
117 536280 [main] testfork 3916 fhandler_tty_slave::close: closing last open
/dev/tty0 handle
163 536443 [main] testfork 3916 fhandler_tty_common::close: tty0
<0x130,0x138> closing
155 536598 [main] testfork 3916 do_exit: 3916 == pgrp 3916, send
SIG{HUP,CONT} to stopped children
122 536720 [main] testfork 3916 kill_pgrp: pid 3916, signal -1
2156 538876 [main] testfork 3916 open_shared: name cygpid.2808, n 2808,
shared 0x3E0000 (wanted 0x0), h 0x138
496 539372 [main] testfork 3916 open_shared: name cygpid.3700, n 3700,
shared 0x4E0000 (wanted 0x0), h 0x120
268 539640 [main] testfork 3916 pinfo::init: execed process windows pid
3700, cygwin pid 3872
298 539938 [main] testfork 3916 open_shared: name cygpid.3872, n 3872,
shared 0x4E0000 (wanted 0x0), h 0x120
282 540220 [main] testfork 3916 open_shared: name cygpid.3268, n 3268,
shared 0x500000 (wanted 0x0), h 0x12C
210 540430 [main] testfork 3916 open_shared: name cygpid.3828, n 3828,
shared 0x520000 (wanted 0x0), h 0x178
179 540609 [main] testfork 3916 pinfo::init: execed process windows pid
3828, cygwin pid 3268
200 540809 [main] testfork 3916 open_shared: name cygpid.3268, n 3268,
shared 0x520000 (wanted 0x0), h 0x178
343 541152 [main] testfork 3916 __set_errno: int kill_pgrp(pid_t,
siginfo_t&):334 val 3
126 541278 [main] testfork 3916 kill_pgrp: -1 = kill (3916, -1)
785 542063 [main] testfork 3916 sigproc_terminate: entering
123 542186 [main] testfork 3916 sig_send: sendsig 0xF0, pid 3916, signal
-42, its_me 1
150 542336 [sig] testfork 3916 wait_sig: saw __SIGEXIT
93 542429 [sig] testfork 3916 wait_sig: signal thread exiting
859 543288 [main] testfork 3916 sig_send: Not waiting for sigcomplete.
its_me 1 signal -42
113 543401 [main] testfork 3916 sig_send: returning 0x0 from sending signal
-42
111 543512 [main] testfork 3916 proc_terminate: nprocs 0
110 543622 [main] testfork 3916 proc_terminate: leaving
174 543796 [main] testfork 3916 __to_clock_t: dwHighDateTime 0,
dwLowDateTime 901296
113 543909 [main] testfork 3916 __to_clock_t: total 00000000 0000005A
110 544019 [main] testfork 3916 __to_clock_t: dwHighDateTime 0,
dwLowDateTime 901296
110 544129 [main] testfork 3916 __to_clock_t: total 00000000 0000005A
1662 545791 [main] testfork 3916 pinfo::exit: Calling ExitProcess n 0x0,
exitcode 0x0
--
Problem reports: http://cygwin.com/problems.html
FAQ: http://cygwin.com/faq/
Documentation: http://cygwin.com/docs.html
Unsubscribe info: http://cygwin.com/ml/#unsubscribe-simple
