Mail Archives: cygwin-developers/2002/09/08/13:58:12
Hi!
Sunday, 08 September, 2002 Christopher Faylor cgf AT redhat DOT com wrote:
CF> If you don't want to understand what's going on then that is perfectly
CF> fine. However, please don't just assume that if turning on an ifdef
CF> causes a problem to apparently go away that you've done anything more
CF> than add an additional delay to cygwin or moved something to a different
CF> memory location or something.
I'm doing my best to understand how things work. And i concluded that
for handle protection to work right it's essential to update the list
whenever we call DuplicateHandle() and replace some handle with its
duplicate. Maybe i'm wrong here, please correct me if so.
Next, i've come over setclexec and then realized that it was disabled.
So, i'm slightly puzzled. Probably i misunderstood how handle
protection works. Is protected handles list directly inherited from
parent process, or recreated from scratch when cygwin initialization
code processes a list of fhandlers passed from parent?
Here's an strace which demonstrates the problem.
693 4839233 [main] expect 238 tty::make_pipes: tty1 from_slave 0x264, to_slave 0x210
167 4839400 [main] expect 238 tty::get_event: created event cygtty1.input.avail
118 4839518 [main] expect 238 add_handle: protecting handle 'output_mutex', inherited flag 1
79 4839597 [main] expect 238 add_handle: protecting handle 'input_mutex', inherited flag 1
75 4839672 [main] expect 238 tty::common_init: tty1 opened
89 4839761 [main] expect 238 tty::create_inuse: cygtty1.master_alive = 0x214
78 4839839 [main] expect 238 fhandler_base::set_flags: flags 0x10002, supplied_bin 0x0
71 4839910 [main] expect 238 fhandler_base::set_flags: O_TEXT/O_BINARY set in flags 0x10000
71 4839981 [main] expect 238 fhandler_base::set_flags: filemode set to binary
70 4840051 [main] expect 238 fhandler_pty_master::open: opened pty master tty1<0x616278AC>
71 4840122 [main] expect 238 _open: 8 = open (/dev/ptmx, 0x2)
827 4840949 [main] expect 238 fhandler_pty_master::set_close_on_exec: from_slave 0x274, to_slave 0x188
76 4841025 [main] expect 238 _fcntl: 0 = fcntl (8, 2, 0x1)
153 4841178 [main] expect 238 dtable::build_fhandler: fd 9, fh 0x61627A5C
85 4841263 [main] expect 238 dtable::build_fhandler: fd 10, fh 0x61627BBC
74 4841337 [main] expect 238 fhandler_base::set_flags: flags 0x10000, supplied_bin 0x0
71 4841408 [main] expect 238 fhandler_base::set_flags: O_TEXT/O_BINARY set in flags 0x10000
69 4841477 [main] expect 238 fhandler_base::set_flags: filemode set to binary
69 4841546 [main] expect 238 fhandler_base::init: created new fhandler_base for handle 0xA4, bin 1
70 4841616 [main] expect 238 fhandler_base::set_flags: flags 0x10001, supplied_bin 0x0
69 4841685 [main] expect 238 fhandler_base::set_flags: O_TEXT/O_BINARY set in flags 0x10000
70 4841755 [main] expect 238 fhandler_base::set_flags: filemode set to binary
70 4841825 [main] expect 238 fhandler_base::init: created new fhandler_base for handle 0x8, bin 1
75 4841900 [main] expect 238 make_pipe: 0 = make_pipe ([9, 10], 16384, 0x10000)
129 4842029 [main] expect 238 dtable::build_fhandler: fd 11, fh 0x61627604
84 4842113 [main] expect 238 dtable::build_fhandler: fd 12, fh 0x61627AE4
73 4842186 [main] expect 238 fhandler_base::set_flags: flags 0x10000, supplied_bin 0x0
70 4842256 [main] expect 238 fhandler_base::set_flags: O_TEXT/O_BINARY set in flags 0x10000
70 4842326 [main] expect 238 fhandler_base::set_flags: filemode set to binary
69 4842395 [main] expect 238 fhandler_base::init: created new fhandler_base for handle 0xA0, bin 1
85 4842480 [main] expect 238 fhandler_base::set_flags: flags 0x10001, supplied_bin 0x0
71 4842551 [main] expect 238 fhandler_base::set_flags: O_TEXT/O_BINARY set in flags 0x10000
69 4842620 [main] expect 238 fhandler_base::set_flags: filemode set to binary
71 4842691 [main] expect 238 fhandler_base::init: created new fhandler_base for handle 0x2AC, bin 1
74 4842765 [main] expect 238 make_pipe: 0 = make_pipe ([11, 12], 16384, 0x10000)
128 4842893 [main] expect 238 dtable::build_fhandler: fd 13, fh 0x61625E6C
84 4842977 [main] expect 238 dtable::build_fhandler: fd 14, fh 0x616283CC
73 4843050 [main] expect 238 fhandler_base::set_flags: flags 0x10000, supplied_bin 0x0
70 4843120 [main] expect 238 fhandler_base::set_flags: O_TEXT/O_BINARY set in flags 0x10000
70 4843190 [main] expect 238 fhandler_base::set_flags: filemode set to binary
69 4843259 [main] expect 238 fhandler_base::init: created new fhandler_base for handle 0x23C, bin 1
70 4843329 [main] expect 238 fhandler_base::set_flags: flags 0x10001, supplied_bin 0x0
70 4843399 [main] expect 238 fhandler_base::set_flags: O_TEXT/O_BINARY set in flags 0x10000
69 4843468 [main] expect 238 fhandler_base::set_flags: filemode set to binary
69 4843537 [main] expect 238 fhandler_base::init: created new fhandler_base for handle 0x2A4, bin 1
75 4843612 [main] expect 238 make_pipe: 0 = make_pipe ([13, 14], 16384, 0x10000)
74 4843686 [main] expect 238 fork: entering
201 4843887 [main] expect 238 add_handle: protecting handle 'subproc_ready', inherited flag 1
86 4843973 [main] expect 238 add_handle: protecting handle 'forker_finished', inherited flag 1
86 4844059 [main] expect 238 stack_base: bottom 0x2480000, top 0x480000, stack 0x2478FA8, size 28760, reserve 33554432
87 4844146 [main] expect 238 fork_parent: CreateProcess (e:\unix\usr\local\bin\expect.exe, e:\unix\usr\local\bin\expect.exe, 0, 0, 1, 20, 0, 0, 0x2479438, 0x2479488)
141 4844287 [main] expect 238 add_handle: protecting handle 'passed_cygheap_h', inherited flag 1
1194 4845481 [main] expect 238 delete_handle: nuking handle 'passed_cygheap_h'
245 4845726 [main] expect 238 add_handle: protecting handle 'pinfo_shared_handle', inherited flag 0
101 4845827 [main] expect 238 add_handle: protecting handle 'pi.hThread', inherited flag 0
82 4845909 [main] expect 238 add_handle: protecting handle 'childhProc', inherited flag 0
79 4845988 [main] expect 238 proc_subproc: args: 1, 38245416
81 4846069 [main] expect 238 add_handle: protecting handle 'pid_handle', inherited flag 0
160 4846229 [main] expect 238 proc_subproc: added pid 150 to wait list, slot 0, winpid 0x96, handle 0x204
82 4846311 [main] expect 238 proc_subproc: returning 1
77 4846388 [main] expect 238 add_handle: protecting handle 'fork_stupidity', inherited flag 0
77 4846465 [main] expect 238 sync_with_child: waiting for child. reason: waiting for longjmp, hang_child 1
91 4846556 [proc] expect 238 wait_subproc: looping
**********************************************
Program name: e:\unix\usr\local\bin\expect.exe (150)
App version: 1001.3, api: 0.21
DLL version: 1003.13, api: 0.62
DLL build: 2002-09-08 20:30
OS version: Windows NT-4.0
Date/Time: 2002-09-08 21:35:57
**********************************************
98 3501 [unknown (0x101)] expect 150 open_shared: name shared, shared 0xA000000 (wanted 0xA000000), h 0x54
1773 5274 [unknown (0x101)] expect 150 heap_init: heap base 0xA010000, heap top 0xA0A7000
192 5466 [unknown (0x101)] expect 150 open_shared: name duda, shared 0x2AC0000 (wanted 0x0), h 0x78
82 5548 [unknown (0x101)] expect 150 memory_init: opening mount table for 'duda' at 0xA010000
94 5642 [unknown (0x101)] expect 150 memory_init: mount table version 31DF at 0x2AC0000
195 5837 [main] expect 150 add_handle: protecting handle 'hMainProc', inherited flag 0
81 5918 [main] expect 150 add_handle: protecting handle 'hMainThread', inherited flag 0
150 6068 [main] expect 150 add_handle: protecting handle 'title_mutex', inherited flag 0
97 6165 [main] expect 150 events_init: windows_system_directory 'D:\WINNT40\System32\', windows_system_directory_length 20
72 6237 [main] expect 150 events_init: cygwin_hmodule 0x61000000
254 6491 [main] expect 150 fork_child: child is running. pid 150, ppid 238, stack here 0x24794B0
79 6570 [main] expect 150 sync_with_parent: signalling parent: after longjmp.
10830 4857386 [main] expect 238 sync_with_child: child signalled me
92 4857478 [main] expect 238 fork_parent: child is alive (but stopped)
308 4857786 [main] expect 238 fork_copy: child handle 0x204, low 0x46E000, high 0x472128, res 1
133 4857919 [main] expect 238 fork_copy: child handle 0x204, low 0x473000, high 0x474C30, res 1
4040 4861959 [main] expect 238 fork_copy: child handle 0x204, low 0xA010000, high 0xA0A7000, res 1
369 4862328 [main] expect 238 fork_copy: child handle 0x204, low 0x24794B8, high 0x2480000, res 1
879 4863207 [main] expect 238 fork_copy: child handle 0x204, low 0x610C7000, high 0x610CA710, res 1
1520 4864727 [main] expect 238 fork_copy: child handle 0x204, low 0x610E7000, high 0x6111F210, res 1
191 4864918 [main] expect 238 fork_copy: done
4858447 4865017 [main] expect 150 sync_with_parent: awake
79 4865096 [main] expect 150 sync_with_parent: no problems
73 4865169 [main] expect 150 fork_child: hParent 0x1F0, child 1 first_dll 0x0, load_dlls 0
171 4865340 [main] expect 150 set_file_api_mode: File APIs set to OEM
88 4865428 [main] expect 150 dtable::fixup_after_fork: fd 0 (/dev/tty0)
88 4865516 [main] expect 150 fhandler_base::fixup_after_fork: inheriting '/dev/tty0' from parent
73 4865589 [main] expect 150 fhandler_base::fork_fixup: handle 0x44 already opened
71 4865660 [main] expect 150 fhandler_base::fork_fixup: handle 0x1C0 already opened
88 4865748 [main] expect 150 fhandler_base::fork_fixup: handle 0x180 already opened
71 4865819 [main] expect 150 fhandler_base::fork_fixup: handle 0x15C already opened
66 4865885 [main] expect 150 fhandler_base::fork_fixup: handle 0x10C already opened
67 4865952 [main] expect 150 fhandler_base::fork_fixup: handle 0x100 already opened
67 4866019 [main] expect 150 fhandler_base::fork_fixup: handle 0xBC already opened
66 4866085 [main] expect 150 fhandler_base::fork_fixup: handle 0x9C already opened
67 4866152 [main] expect 150 fhandler_base::fork_fixup: handle 0x28 already opened
69 4866221 [main] expect 150 dtable::fixup_after_fork: fd 1 (/dev/tty0)
66 4866287 [main] expect 150 fhandler_base::fixup_after_fork: inheriting '/dev/tty0' from parent
68 4866355 [main] expect 150 fhandler_base::fork_fixup: handle 0x140 already opened
66 4866421 [main] expect 150 fhandler_base::fork_fixup: handle 0x48 already opened
67 4866488 [main] expect 150 fhandler_base::fork_fixup: handle 0xA8 already opened
65 4866553 [main] expect 150 fhandler_base::fork_fixup: handle 0xC already opened
1708 4866626 [main] expect 238 resume_child: signalled child
73 4866699 [main] expect 238 sync_with_child: waiting for child. reason: child loading dlls, hang_child 0
440 4866993 [main] expect 150 fhandler_base::fork_fixup: handle 0x16C already opened
80 4867073 [main] expect 150 fhandler_base::fork_fixup: handle 0x11C already opened
73 4867146 [main] expect 150 fhandler_base::fork_fixup: handle 0x13C already opened
68 4867214 [main] expect 150 fhandler_base::fork_fixup: handle 0x1BC already opened
70 4867284 [main] expect 150 fhandler_base::fork_fixup: handle 0x8C already opened
69 4867353 [main] expect 150 dtable::fixup_after_fork: fd 2 (/dev/tty0)
69 4867422 [main] expect 150 fhandler_base::fixup_after_fork: inheriting '/dev/tty0' from parent
68 4867490 [main] expect 150 fhandler_base::fork_fixup: handle 0x120 already opened
70 4867560 [main] expect 150 fhandler_base::fork_fixup: handle 0xC4 already opened
68 4867628 [main] expect 150 fhandler_base::fork_fixup: handle 0x108 already opened
91 4867719 [main] expect 150 fhandler_base::fork_fixup: handle 0x150 already opened
71 4867790 [main] expect 150 fhandler_base::fork_fixup: handle 0x158 already opened
70 4867860 [main] expect 150 fhandler_base::fork_fixup: handle 0x18C already opened
69 4867929 [main] expect 150 fhandler_base::fork_fixup: handle 0x1E0 already opened
69 4867998 [main] expect 150 fhandler_base::fork_fixup: handle 0x104 already opened
68 4868066 [main] expect 150 fhandler_base::fork_fixup: handle 0x154 already opened
79 4868145 [main] expect 150 dtable::fixup_after_fork: fd 5 (/dev/tty0)
73 4868218 [main] expect 150 fhandler_base::fixup_after_fork: inheriting '/dev/tty0' from parent
70 4868288 [main] expect 150 fhandler_base::fork_fixup: handle 0x178 already opened
69 4868357 [main] expect 150 fhandler_base::fork_fixup: handle 0x174 already opened
68 4868425 [main] expect 150 fhandler_base::fork_fixup: handle 0xB8 already opened
68 4868493 [main] expect 150 fhandler_base::fork_fixup: handle 0x14C already opened
69 4868562 [main] expect 150 fhandler_base::fork_fixup: handle 0x164 already opened
68 4868630 [main] expect 150 fhandler_base::fork_fixup: handle 0x110 already opened
68 4868698 [main] expect 150 fhandler_base::fork_fixup: handle 0x1DC already opened
68 4868766 [main] expect 150 fhandler_base::fork_fixup: handle 0xB4 already opened
68 4868834 [main] expect 150 fhandler_base::fork_fixup: handle 0x170 already opened
69 4868903 [main] expect 150 dtable::fixup_after_fork: fd 6 (/cygdrive/j/build/i586-pc-cygwin/gcc/i686-pc-cygwin/libstdc++-v3/testsuite/libstdc++-v3.sum)
79 4868982 [main] expect 150 fhandler_base::fixup_after_fork: inheriting '/cygdrive/j/build/i586-pc-cygwin/gcc/i686-pc-cygwin/libstdc++-v3/testsuite/libstdc++-v3.sum' from parent
89 4869071 [main] expect 150 dtable::fixup_after_fork: fd 7 (/cygdrive/j/build/i586-pc-cygwin/gcc/i686-pc-cygwin/libstdc++-v3/testsuite/libstdc++-v3.log)
74 4869145 [main] expect 150 fhandler_base::fixup_after_fork: inheriting '/cygdrive/j/build/i586-pc-cygwin/gcc/i686-pc-cygwin/libstdc++-v3/testsuite/libstdc++-v3.log' from parent
81 4869226 [main] expect 150 dtable::fixup_after_fork: fd 8 (/dev/ptym)
70 4869296 [main] expect 150 fhandler_base::fixup_after_fork: inheriting '/dev/ptym' from parent
111 4869407 [main] expect 150 add_handle: protecting handle 'hParent', inherited flag 1
101 4869508 [main] expect 150 add_handle: void sigproc_init():563 - multiple attempts to add handle wait_sig_inited<0x210>
99 4869607 [main] expect 150 add_handle: previously allocated by int tty::make_pipes(fhandler_pty_master*):370(to_pty<0x210>) winpid 137
94 4869701 [main] expect 150 add_handle: protecting handle 'signal_arrived', inherited flag 0
350 4870051 [main] expect 150 sigproc_init: process/signal handling enabled(1801)
73 4870124 [main] expect 150 fixup_mmaps_after_fork: recreate_mmaps_after_fork, mmapped_areas 0x0
71 4870195 [main] expect 150 sync_with_parent: signalling parent: performed fork fixup.
3572 4870271 [main] expect 238 sync_with_child: child signalled me
79 4870350 [main] expect 238 delete_handle: nuking handle 'subproc_ready'
75 4870425 [main] expect 238 delete_handle: nuking handle 'pi.hThread'
73 4870498 [main] expect 238 delete_handle: nuking handle 'forker_finished'
76 4870574 [main] expect 238 fork: 150 = fork()
>>CF> Possibly. Are you seeing system_printf output in your failing case?
>>
>>Yes, but it looks that it not full. Actually, pipe hasn't to be filled
>>up. After WriteFile() we call FlushFileBuffers (). Documentation on
>>FlushFileBuffers states that if handle is a pipe then the operation
>>blocks until pipe peer reads _all_ data from pipe. Commenting
>>FlushFileBuffers did helped in my case -- system_printf()s are not
>>blocking process now.
>>
>>Yet i suppose the right way is to always unlock debug muto as fast as
>>possible, i.e., before calling debug_printf() and stuff. As far as i
>>understand, muto is protecting handle list, so we must hold it while
>>and only while we're messing with it. That should be safe.
CF> Possibly. Personally, I'm much more bothered by the fact that there
CF> are system_printfs at all. AFAICT, you only mention this in passing
CF> but a system_printf is an indication of a problem in cygwin.
Agreed. But if we really want process to block whenever it encounters
system_printf, we can possibly do it in less sophisticated (and
confusing) way :)
Egor. mailto:deo AT logos-m DOT ru ICQ 5165414 FidoNet 2:5020/496.19
- Raw text -