[Bug 21562] New: Multiple init/deinit of msvcrt (std fd's) causes pluto app installer to hang
http://bugs.winehq.org/show_bug.cgi?id=21562 Summary: Multiple init/deinit of msvcrt (std fd's) causes pluto app installer to hang Product: Wine Version: 1.1.37 Platform: x86 URL: http://pluto.brain-killer.org/download/pluto_FE_w32_en _0036.exe OS/Version: Linux Status: UNCONFIRMED Severity: normal Priority: P2 Component: msvcrt AssignedTo: wine-bugs(a)winehq.org ReportedBy: focht(a)gmx.net Hello, an interesting one... WINEDEBUG=+tid,+seh,+loaddll,+msvcrt,+server,+relay wine ./pluto_FE_w32_en_0036.exe >>log.txt 2>&1 The app installer creates an additional worker (unpack) thread from its main thread: --- snip --- 0009:Call KERNEL32.CreateThread(00000000,00000000,0042b674,00000000,00000000,00436718) ret=0042c3e8 0009: *fd* 6 <- 22 0009: new_thread( access=001f03ff, attributes=00000000, suspend=1, request_fd=6 ) 0009: new_thread() = 0 { tid=001b, handle=0004 } ... 001b:Starting thread proc 0x42b674 (arg=(nil)) ... 0009:Ret KERNEL32.CreateThread() retval=00000004 ret=0042c3e8 --- snip --- The app installer main thread contains a loop to check if the (unpack) worker thread (handle = 0x4) is still alive. While doing so, it pumps messages and delays the next check, illustrated by following code snippet: --- snip --- 0009:Ret KERNEL32.Sleep() retval=00000000 ret=004167e4 0009:Call KERNEL32.GetExitCodeThread(00000004,0032fd9c) ret=0042c40f 0009: get_thread_info( handle=0004, tid_in=0000 ) 0009: get_thread_info() = 0 { pid=0008, tid=001b, teb=7ffd4000, affinity=ffffffffffffffff, creation_time=1caa28d3911cf76 (-0.0285120), exit_time=0, exit_code=259, priority=0, last=0 } 0009:Ret KERNEL32.GetExitCodeThread() retval=00000001 ret=0042c40f 0009:Call user32.PeekMessageA(0032fd0c,00000000,00000000,00000000,00000001) ret=004167d9 ... 0009:Ret user32.PeekMessageA() retval=00000000 ret=004167d9 0009:Call KERNEL32.Sleep(00000001) ret=004167e4 --- snip --- Unfortunately something goes wrong and the app installer refuses to terminate - because the worker checking loop suddenly became a forever loop: --- snip --- ... 0009:Call KERNEL32.Sleep(00000001) ret=004167e4 0009:Ret KERNEL32.Sleep() retval=00000000 ret=004167e4 0009:Call KERNEL32.GetExitCodeThread(00000004,0032fd9c) ret=0042c40f 0009: get_thread_info( handle=0004, tid_in=0000 ) 0009: get_thread_info() = INVALID_HANDLE { pid=0000, tid=0000, teb=00000000, affinity=00000000, creation_time=0, exit_time=0, exit_code=0, priority=0, last=0 } 0009:Ret KERNEL32.GetExitCodeThread() retval=00000000 ret=0042c40f 0009:Call user32.PeekMessageA(0032fd0c,00000000,00000000,00000000,00000001) ret=004167d9 0009: get_message( flags=00000001, get_win=00000000, get_first=00000000, get_last=ffffffff, hw_id=00000000, wake_mask=00000000, changed_mask=00000000 ) 0009: get_message() = PENDING { win=00000000, msg=00000000, wparam=00000000, lparam=00000000, type=0, time=00000000, active_hooks=80000000, total=0, data={} } ... 0009:Ret user32.PeekMessageA() retval=00000000 ret=004167d9 --- snip --- The installer code doesn't evaluate the return code of GetExitCodeThread() but instead accesses the exit code variable directly, comparing it to 0x103 -> STILL_ACTIVE. Because the thread once lived in this state, this variable is never touched by Wine in case the thread handle becomes invalid. GetExitCodeThread() fails but the variable still contains the last known "good" value -> STILL_ACTIVE (the app doesn't reinit it). The app still thinks the worker is alive and goes into forever loop. Now the culprit: the thread handle, delivered to caller upon returning from CreateThread() is _never_ closed by app explicitly -> CloseHandle() so GetExitCodeThread() should be successful in any case. We have to go back in time to unearth the problem ... lets look what happens to this thread handle (0x4). --- snip --- ... 001b:Call KERNEL32.FreeLibrary(10000000) ret=004242bb 001b:Call PE DLL (proc=0x10001148,module=0x10000000 L"unpack.dll",reason=PROCESS_DETACH,res=(nil)) 001b:Ret PE DLL (proc=0x10001148,module=0x10000000 L"unpack.dll",reason=PROCESS_DETACH,res=(nil)) retval=1 001b:Call PE DLL (proc=0x5de0cc9c,module=0x5de00000 L"crtdll.dll",reason=PROCESS_DETACH,res=(nil)) 001b:Ret PE DLL (proc=0x5de0cc9c,module=0x5de00000 L"crtdll.dll",reason=PROCESS_DETACH,res=(nil)) retval=1 001b:Call PE DLL (proc=0x5c7cd8b4,module=0x5c790000 L"msvcrt.dll",reason=PROCESS_DETACH,res=(nil)) ... 001b:trace:msvcrt:DllMain (0x5c790000, DLL_PROCESS_DETACH, (nil)) pid(8), tid(1b), tls(4) 001b:trace:msvcrt:msvcrt_free_mt_locks : uninitializing all mtlocks ... 001b:trace:msvcrt:MSVCRT__close :fd (3) handle (0xfffffff6) 001b:Call KERNEL32.CloseHandle(fffffff6) ret=5c7ad9fc 001b: close_handle( handle=0004 ) 001b: close_handle() = 0 001b:Ret KERNEL32.CloseHandle() retval=00000001 ret=5c7ad9fc 001b:trace:msvcrt:msvcrt_free_fd :fd (3) freed 001b:trace:msvcrt:MSVCRT__close :ok ... 001b:trace:msvcrt:MSVCRT__close :fd (4) handle (0xfffffff5) 001b:Call KERNEL32.CloseHandle(fffffff5) ret=5c7ad9fc 001b: close_handle( handle=0008 ) 001b: close_handle() = 0 001b:Ret KERNEL32.CloseHandle() retval=00000001 ret=5c7ad9fc 001b:trace:msvcrt:msvcrt_free_fd :fd (4) freed 001b:trace:msvcrt:MSVCRT__close :ok ... 001b:trace:msvcrt:MSVCRT__close :fd (5) handle (0xfffffff4) 001b:Call KERNEL32.CloseHandle(fffffff4) ret=5c7ad9fc 001b: close_handle( handle=000c ) 001b: close_handle() = 0 001b:Ret KERNEL32.CloseHandle() retval=00000001 ret=5c7ad9fc 001b:trace:msvcrt:msvcrt_free_fd :fd (5) freed 001b:trace:msvcrt:MSVCRT__close :ok 001b:trace:msvcrt:MSVCRT__fcloseall :closed (3) handles ... 001b:trace:msvcrt:MSVCRT__close :fd (0) handle (0x8) 001b:Call KERNEL32.CloseHandle(00000008) ret=5c7ad9fc 001b: close_handle( handle=0008 ) 001b: close_handle() = INVALID_HANDLE 001b:Ret KERNEL32.CloseHandle() retval=00000000 ret=5c7ad9fc ... 001b:warn:msvcrt:MSVCRT__close :failed-last error (6) ... 001b:trace:msvcrt:MSVCRT__close :ok ... 001b:trace:msvcrt:MSVCRT__close :fd (1) handle (0xc) 001b:Call KERNEL32.CloseHandle(0000000c) ret=5c7ad9fc 001b: close_handle( handle=000c ) 001b: close_handle() = INVALID_HANDLE 001b:Ret KERNEL32.CloseHandle() retval=00000000 ret=5c7ad9fc ... 001b:warn:msvcrt:MSVCRT__close :failed-last error (6) ... 001b:trace:msvcrt:MSVCRT__close :ok ... 001b:trace:msvcrt:MSVCRT__close :fd (2) handle (0x50) 001b:Call KERNEL32.CloseHandle(00000050) ret=5c7ad9fc 001b: close_handle( handle=0050 ) 001b: close_handle() = 0 001b:Ret KERNEL32.CloseHandle() retval=00000001 ret=5c7ad9fc 001b:trace:msvcrt:msvcrt_free_fd :fd (2) freed 001b:Call KERNEL32.GetStdHandle(fffffff4) ret=5c7ac729 001b:Ret KERNEL32.GetStdHandle() retval=0000000c ret=5c7ac729 001b:trace:msvcrt:MSVCRT__close :ok ... 001b:trace:msvcrt:msvcrt_free_console :Closing console handles --- snip --- *eek* ... the thread handle gets closed as part of msvcrt cleanup! PROCESS_DETACH -> msvcrt_free_io() -> MSVCRT__fcloseall() This will close fd(3), fd(4), fd(5) -> stdin,stdout,stderr Corresponding msvcrt init: --- snip --- ... 001b:Call PE DLL (proc=0x5c7cd8b4,module=0x5c790000 L"msvcrt.dll",reason=PROCESS_ATTACH,res=(nil)) ... 001b:trace:msvcrt:DllMain (0x5c790000, DLL_PROCESS_ATTACH, (nil)) pid(8), tid(1b), tls(0) ... 001b:Call KERNEL32.GetStartupInfoA(0096e4b8) ret=5c7acdd6 001b:Ret KERNEL32.GetStartupInfoA() retval=00000011 ret=5c7acdd6 001b:Call KERNEL32.GetStdHandle(fffffff6) ret=5c7acf77 001b:Ret KERNEL32.GetStdHandle() retval=00000004 ret=5c7acf77 001b:Call KERNEL32.DuplicateHandle(ffffffff,00000004,ffffffff,5c7db2e0,00000000,00000001,00000002) ret=5c7acfc0 001b: dup_handle( src_process=ffffffff, src_handle=0004, dst_process=ffffffff, access=00000000, attributes=00000002, options=00000002 ) 001b: dup_handle() = 0 { handle=0008, self=1, closed=0 } 001b:Ret KERNEL32.DuplicateHandle() retval=00000001 ret=5c7acfc0 001b:Call KERNEL32.GetStdHandle(fffffff5) ret=5c7acff6 001b:Ret KERNEL32.GetStdHandle() retval=00000008 ret=5c7acff6 001b:Call KERNEL32.DuplicateHandle(ffffffff,00000008,ffffffff,5c7db304,00000000,00000001,00000002) ret=5c7ad03f 001b: dup_handle( src_process=ffffffff, src_handle=0008, dst_process=ffffffff, access=00000000, attributes=00000002, options=00000002 ) 001b: dup_handle() = 0 { handle=000c, self=1, closed=0 } 001b:Ret KERNEL32.DuplicateHandle() retval=00000001 ret=5c7ad03f 001b:Call KERNEL32.GetStdHandle(fffffff4) ret=5c7ad075 001b:Ret KERNEL32.GetStdHandle() retval=0000000c ret=5c7ad075 001b:Call KERNEL32.DuplicateHandle(ffffffff,0000000c,ffffffff,5c7db328,00000000,00000001,00000002) ret=5c7ad0be 001b: dup_handle( src_process=ffffffff, src_handle=000c, dst_process=ffffffff, access=00000000, attributes=00000002, options=00000002 ) 001b: dup_handle() = 0 { handle=0050, self=1, closed=0 } 001b:Ret KERNEL32.DuplicateHandle() retval=00000001 ret=5c7ad0be 001b:trace:msvcrt:msvcrt_init_io :handles (0x8)(0xc)(0x50) --- snip --- The culprit: msvcrt is actually loaded and unloaded _two_ times! Upon the first unload sequence all std/fd handles are teared down (including handle 0x4) - this makes the handle values available in server again. When the worker thread is created it gets the unused handle 0x4 assigned from wineserver. This is the handle which is then polled by installers GetExitCodeThread() loop. When msvcrt is loaded a second time, GetStdHandle( STD_XXX) will still deliver its original value from PEB (0x4, 0x8, 0xC). Upon second msvcrt unload, fd(3), fd(4), fd(5) are closed again but this time they close something completely different (indication are also fd close errors following), leaving the app installer in forever loop. Regards -- Configure bugmail: http://bugs.winehq.org/userprefs.cgi?tab=email Do not reply to this email, post in Bugzilla using the above URL to reply. ------- You are receiving this mail because: ------- You are watching all bug changes.
http://bugs.winehq.org/show_bug.cgi?id=21562 Anastasius Focht <focht(a)gmx.net> changed: What |Removed |Added ---------------------------------------------------------------------------- Keywords| |download, Installer -- Configure bugmail: http://bugs.winehq.org/userprefs.cgi?tab=email Do not reply to this email, post in Bugzilla using the above URL to reply. ------- You are receiving this mail because: ------- You are watching all bug changes.
http://bugs.winehq.org/show_bug.cgi?id=21562 Alexandre Julliard <julliard(a)winehq.org> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|UNCONFIRMED |RESOLVED Resolution| |FIXED --- Comment #1 from Alexandre Julliard <julliard(a)winehq.org> 2010-05-27 11:39:56 --- Should be fixed by 775e5f7b3e2d4c87035b5fabf436bdea0586913f. -- Configure bugmail: http://bugs.winehq.org/userprefs.cgi?tab=email Do not reply to this email, post in Bugzilla using the above URL to reply. ------- You are receiving this mail because: ------- You are watching all bug changes.
http://bugs.winehq.org/show_bug.cgi?id=21562 Alexandre Julliard <julliard(a)winehq.org> changed: What |Removed |Added ---------------------------------------------------------------------------- CC| |lukasz.wojnilowicz(a)gmail.co | |m --- Comment #2 from Alexandre Julliard <julliard(a)winehq.org> 2010-05-27 11:47:26 --- *** Bug 22176 has been marked as a duplicate of this bug. *** -- Configure bugmail: http://bugs.winehq.org/userprefs.cgi?tab=email Do not reply to this email, post in Bugzilla using the above URL to reply. ------- You are receiving this mail because: ------- You are watching all bug changes.
http://bugs.winehq.org/show_bug.cgi?id=21562 Alexandre Julliard <julliard(a)winehq.org> changed: What |Removed |Added ---------------------------------------------------------------------------- CC| |ariafan(a)mail.ru --- Comment #3 from Alexandre Julliard <julliard(a)winehq.org> 2010-05-27 11:48:50 --- *** Bug 21930 has been marked as a duplicate of this bug. *** -- Configure bugmail: http://bugs.winehq.org/userprefs.cgi?tab=email Do not reply to this email, post in Bugzilla using the above URL to reply. ------- You are receiving this mail because: ------- You are watching all bug changes.
http://bugs.winehq.org/show_bug.cgi?id=21562 Alexandre Julliard <julliard(a)winehq.org> changed: What |Removed |Added ---------------------------------------------------------------------------- Status|RESOLVED |CLOSED --- Comment #4 from Alexandre Julliard <julliard(a)winehq.org> 2010-05-28 12:51:16 --- Closing bugs fixed in 1.2-rc2. -- Configure bugmail: http://bugs.winehq.org/userprefs.cgi?tab=email Do not reply to this email, post in Bugzilla using the above URL to reply. ------- You are receiving this mail because: ------- You are watching all bug changes.
http://bugs.winehq.org/show_bug.cgi?id=21562 Anastasius Focht <focht(a)gmx.net> changed: What |Removed |Added ---------------------------------------------------------------------------- Fixed by SHA1| |775e5f7b3e2d4c87035b5fabf43 | |6bdea0586913f --- Comment #5 from Anastasius Focht <focht(a)gmx.net> 2011-10-11 15:11:21 CDT --- Hello, filling/correcting fields ... Regards -- Configure bugmail: http://bugs.winehq.org/userprefs.cgi?tab=email Do not reply to this email, post in Bugzilla using the above URL to reply. ------- You are receiving this mail because: ------- You are watching all bug changes.
https://bugs.winehq.org/show_bug.cgi?id=21562 Anastasius Focht <focht(a)gmx.net> changed: What |Removed |Added ---------------------------------------------------------------------------- URL|http://pluto.brain-killer.o |https://web.archive.org/web |rg/download/pluto_FE_w32_en |/20210724075356/http://plut |_0036.exe |o.brainkiller.org/download/ | |pluto_FE_w32_en_0036.exe --- Comment #6 from Anastasius Focht <focht(a)gmx.net> --- Hello folks, adding stable download via Internet Archive: https://web.archive.org/web/20210724075356/http://pluto.brainkiller.org/down... $ sha1sum pluto_FE_w32_en_0036.exe c7b8d58a43f4ba95c772a9684bac791b8694081b pluto_FE_w32_en_0036.exe $ du -sh pluto_FE_w32_en_0036.exe 2.6M pluto_FE_w32_en_0036.exe Regards -- Do not reply to this email, post in Bugzilla using the above URL to reply. You are receiving this mail because: You are watching all bug changes.
participants (2)
-
wine-bugs＠winehq.org -
WineHQ Bugzilla