http://bugs.winehq.org/show_bug.cgi?id=12948
Summary: zmud does not run under Ubuntu 8.04 (...turn off system debuggers) Product: Wine Version: 0.9.60 Platform: PC OS/Version: Linux Status: UNCONFIRMED Severity: major Priority: P2 Component: -unknown AssignedTo: wine-bugs@winehq.org ReportedBy: martym.de.lagos@gmail.com
Created an attachment (id=12688) --> (http://bugs.winehq.org/attachment.cgi?id=12688) terminal output while running zmud
Upon launchiung zMud.exe a message appears:
"For security purposes, this program will not run while system debuggers are active. Please remove or disable the system debugger before trying to run this program again."
The app worked fine with the 2.6.24-15-generif kernel but not under 2.6.24-16 so it looks like it is a problem with the latest kernel update?
http://bugs.winehq.org/show_bug.cgi?id=12948
--- Comment #1 from Austin English austinenglish@gmail.com 2008-05-03 22:52:52 --- Does http://wiki.winehq.org/PreloaderPageZeroProblem help?
http://bugs.winehq.org/show_bug.cgi?id=12948
scguy318 nodisgod@yahoo.com changed:
What |Removed |Added ---------------------------------------------------------------------------- CC| |nodisgod@yahoo.com
--- Comment #2 from scguy318 nodisgod@yahoo.com 2008-05-04 04:25:22 --- For me, using Zmud.exe from installer (http://forums.zuggsoft.com/index.php?page=4&action=file&file_id=65) yielded the same problem even with the suggested workaround. I am also running 2.6.24-16:
Linux ubuntu-desktop 2.6.24-16-generic #1 SMP Thu Apr 10 13:23:42 UTC 2008 i686 GNU/Linux
http://bugs.winehq.org/show_bug.cgi?id=12948
Vitaliy Margolen vitaliy@kievinfo.com changed:
What |Removed |Added ---------------------------------------------------------------------------- Attachment #12688|application/octet-stream |text/plain mime type| |
http://bugs.winehq.org/show_bug.cgi?id=12948
Martym martym.de.lagos@gmail.com changed:
What |Removed |Added ---------------------------------------------------------------------------- Version|0.9.60 |0.9.61.
--- Comment #3 from Martym martym.de.lagos@gmail.com 2008-05-05 06:17:39 --- (In reply to comment #0) (In reply to comment #1)
No it does not, interestingly I updated to .61 and the program ran for a little bit. I started it up and realised my settings were not there so I exited, moved the folder for my game over from a save restarted and received the same message again
http://bugs.winehq.org/show_bug.cgi?id=12948
Lei Zhang thestig@google.com changed:
What |Removed |Added ---------------------------------------------------------------------------- URL| |http://www.zuggsoft.com/zmud | |/zmudinfo.htm Severity|major |normal Keywords| |download
http://bugs.winehq.org/show_bug.cgi?id=12948
--- Comment #4 from Martym martym.de.lagos@gmail.com 2008-07-26 09:08:09 --- So, with every update that comes my way I hope and pray that this time it will be fixed. Each time I am disappointed. Is there no way to identify and/or remove these "system debuggers"? Is it even Wine or the OS?
http://bugs.winehq.org/show_bug.cgi?id=12948
Anastasius Focht focht@gmx.net changed:
What |Removed |Added ---------------------------------------------------------------------------- CC| |focht@gmx.net
--- Comment #5 from Anastasius Focht focht@gmx.net 2008-07-27 04:26:24 --- Hello,
I downloaded v7.21 26-Sep-2005 (PUBLIC release) and ran it using wine-1.1.2. Apart from gui bugs it runs fine.
Their changelog doesn't reveal something serious ...
--- snip --- 7.20a 13-Sep-2005 (PUBLIC release)
* Removed eLicense copy protection and replaced with custom copy protection.
6.06 13-Sep-00 (Beta version)
* Removed old zMUD copy protection. zMUD no longer contacts server and no longer sends any user information to zuggsoft.com. --- snip ---
A quick scan of executables revealed following:
--- snip --- C:\Program Files\zMUD\elicen40.dll - ASPack 2.12 C:\Program Files\zMUD\zsConvert.exe - ASPack 2.12 C:\Program Files\zMUD\Zmud.exe - Armadillo 1.xx - 2.xx --- snip ---
In conjunction with your error message:
--- quote --- "For security purposes, this program will not run while system debuggers are active. Please remove or disable the system debugger before trying to run this program again." --- quote ---
I've reversed several Armadillo versions and can think of following scenario:
Armadillo consists of two processes (same executable) where the father acts as debugger, controlling the child process. The child is actually the app code to be executed (encrypted). Whenever code is executed in child, page faults are caused on purpose (guard pages). The father (debugger) decrypts and re-encrypts the code on the fly, writing back to child (debuggee) process memory. Usually only a certain amount of child pages stay unencrypted while the others remain encrypted.
If the father stays - for whatever reason - in memory on exit, even for few seconds and you attempt to restart the app, the protector mistakenly identifies the father process as debugger (because it acts as one) and fails.
You could simulate this behaviour by trying to start the app twice. There should be the same error message.
I'm afraid but such behaviour is not fixable. All Armadillo protected apps are susceptible to this problem because of design.
Just make sure there are no lingering processes of the app in memory before you start it (e.g. wineserver -k).
Regards
http://bugs.winehq.org/show_bug.cgi?id=12948
--- Comment #6 from Anastasius Focht focht@gmx.net 2008-07-27 05:20:15 --- Hello again,
*gee* ... just retested myself on that target and I stand corrected :|
--- quote --- You could simulate this behaviour by trying to start the app twice. There should be the same error message. --- quote ---
My assumption was not correct, one needs several tries to accomplish that. Multiple consoles, start, stop, restart the app (CTRL+C) fast enough you get this behaviour. You never get this with 'fresh' wineserver (first time).
Already running and initialized process pairs (father and child) seem unaffected, both processes use unique mutexes to detect on which "side" they are (pid+num).
The reason is most likely a race condition/timing issue which needs further investigation.
Regards
http://bugs.winehq.org/show_bug.cgi?id=12948
--- Comment #7 from Anastasius Focht focht@gmx.net 2008-07-27 09:01:25 --- Hello,
I found the problem ... prepare for journey into debuggers and race conditions ;-) In short: it's a bug in the software protection code which the application is bundled with - not fixable in Wine.
Prerequisite:
- enable wineserver tracing which slows it down sufficiently to observe and log the behaviour - "pre-start" wineserver with a console program (cmd.exe) just to let it sit and wait
Following are relevant process/thread ids to follow snippets:
--- snip --- process tid prio (all id:s are in hex) .. 00000017 0000001b 2 'Zmud.exe' (father, acting as debugger) 00000018 1 'Zmud.exe' (father, acting as debugger) 00000019 0000001a 1 'Zmud.exe' (child, debuggee) .. --- snip ---
The father - which will act as debugger later - creates the child process. The child is created as "suspended" (hence the CREATE_SUSPENDED flags):
--- snip --- 0018: new_process( inherit_all=1, create_flags=00000004, socket_fd=16, exe_file=0x44, hstdin=0x4, hstdout=0x8, hstderr=0xc, process_access=001f0fff, process_attr=00000000, thread_access=001f03ff, thread_attr=00000000, info={AllocationSize=1000,Size=5e4,Flags=0,DebugFlags=0,ConsoleHandle=(nil),ConsoleFlags=0,hStdInput=0x4,hStdOutput=0x8,hStdError=0xc,CurrentDirectory.Handle=(nil),dwX=0,dwY=0,dwXSize=0,dwYSize=0,dwXCountChars=0,dwYCountChars=0,dwFillAttribute=0,dwFlags=0,wShowWindow=1,CurrentDirectory.DosPath=L"C:\Program Files\zMUD\",DllPath=L"C:\Program Files\zMUD;.;C:\windows\system32;C:\windows\system;C:\windows;C:\windows\system32;C:\windows",ImagePathName=L"C:\Program Files\zMUD\Zmud.exe",CommandLine=L"./Zmud.exe",WindowTitle=L"",Desktop=L"",ShellInfo=L"",RuntimeInfo=L""}, ... 0018: new_process() = 0 { info=0x48, pid=0019, phandle=0x4c, tid=001a, thandle=0x50 } --- snip ---
The main thread of the child gets created and process init is done:
--- snip --- 001a: init_thread( unix_pid=17405, unix_tid=17405, debug_level=0, teb=0x7ffd8000, peb=0x7ffdf000, entry=(nil), ldt_copy=0x601239e0, reply_fd=5, wait_fd=7 ) 001a: init_thread() = 0 { pid=0019, tid=001a, info_size=7598, server_start=1c8efe01f98c966 (-3.6957770), version=341 } ... 001a: init_process_done( module=0x400000, entry=0x94ef73, gui=1 ) 0018: *wakeup* signaled=0 cookie=0x16dd154 001a: *sent signal* signal=10 001a: init_process_done() = 0 --- snip ---
After the create process call returns, the father rewrites entry point in the child with an 0xEB, 0xFE opcode sequence which is basically a jump to itself. Remember: PE entry point is not executed yet due to suspended creation. This opcode sequence will let the child enter an endless loop when the main thread of the child process is resumed and the location is hit.
--- snip --- 0018: get_new_process_info( info=0x48 ) 0018: get_new_process_info() = 0 { success=1, exit_code=259 } .. 0018: read_process_memory( handle=0x4c, addr=0x94ef73 ) .. 0018: write_process_memory( handle=0x4c, addr=0x94ef73, data={eb,fe} ) .. 0018: resume_thread( handle=0x50 ) 0018: resume_thread() = 0 { count=1 } --- snip ---
The father continuously suspends child's main thread, fetching thread context and resumes it again until the EIP of rewritten code is reached:
--- snip --- 0018: suspend_thread( handle=0x50 ) 001a: *sent signal* signal=10 0018: suspend_thread() = 0 { count=0 } 0018: get_thread_context( handle=0x50, flags=00010001, suspend=0 ) 0018: get_thread_context() = PENDING { self=0, context={} } 001a: set_thread_context( .. 001a: set_thread_context() = 0 { self=1 } 0018: suspend_thread( handle=0x50 ) 0018: suspend_thread() = 0 { count=1 } 0018: get_thread_context( handle=0x50, flags=00010001, suspend=0 ) 0018: get_thread_context() = 0 { ... } 001a: select( flags=4, cookie=0x7ffdb7b4, signal=(nil), prev_apc=(nil), timeout=0, result={}, handles={} ) 001a: select() = PENDING { apc_handle=(nil), timeout=1c8efe0224574ac (+0.0000000), call={APC_NONE} } 0018: resume_thread( handle=0x50 ) 0018: resume_thread() = 0 { count=2 } 0018: resume_thread( handle=0x50 ) 001a: *wakeup* signaled=258 cookie=0x7ffdb7b4 0018: resume_thread() = 0 { count=1 } .. --- snip ---
When the child entered the endless loop, the father will attach to the child process to receive debug events.
From now on, the father acts as debugger.
--- snip --- 0018: debug_process( pid=0019, attach=1 ) 001a: *signal* signal=19 0018: debug_process() = 0 --- snip ---
Next, the father restores the overwritten sequence with original code and resumes the child:
--- snip --- 001a: get_thread_context( handle=0xfffffffe, flags=00010007, suspend=1 ) 001a: get_thread_context() = 0 { self=1, context= .. 0018: suspend_thread( handle=0x50 ) 0018: suspend_thread() = 0 { count=0 } 0018: write_process_memory( handle=0x4c, addr=0x94ef73, data={55,8b} ) 001a: *signal* signal=19 0018: write_process_memory() = 0 0018: new_thread( access=001f03ff, attributes=00000000, suspend=1, request_fd=14 ) 0018: *fd* 14 <- 71 0018: new_thread() = 0 { tid=001b, handle=0x5c } ... 0018: resume_thread( handle=0x5c ) 001b: *wakeup* signaled=258 cookie=0x7ffd77b4 0018: resume_thread() = 0 { count=1 } --- snip ---
The child begins to execute entry code, this is the problematic section (explanation later):
--- snip --- 001a: open_mutex( access=001f0001, attributes=00000000, rootdir=0x24, name=L"19::DA0D2092E0" ) 001a: open_mutex() = OBJECT_NAME_NOT_FOUND { handle=(nil) } 001a: open_mutex( access=001f0001, attributes=00000000, rootdir=0x24, name=L"19::DA0D2092E0" ) 001a: open_mutex() = OBJECT_NAME_NOT_FOUND { handle=(nil) } 001a: set_thread_info( handle=0xfffffffe, mask=1, priority=1, affinity=00000000, token=(nil) ) 001a: set_thread_info() = 0 001a: create_mutex( access=001f0001, attributes=00000080, owned=0, objattr={rootdir=0x24,sd={},name=L"19:DAF"} ) 001a: create_mutex() = 0 { handle=0x40 } --- snip ---
The father enters its debugger loop and receives first debug events:
--- snip --- 0018: get_process_info( handle=0x4c ) 0018: get_process_info() = 0 { pid=0019, ppid=0017, exit_code=259, priority=2, affinity=ffffffff, peb=0x7ffdf000, start_time=1c8efe021cc4f50 (-0.8118270), end_time=0 } 0018: wait_debug_event( get_handle=1 ) 0018: wait_debug_event() = 0 { pid=0019, tid=001a, wait=(nil), event={create_process,file=0x54,process=0x44,thread=0x48,base=0x400000,offset=0,size=0,teb=0x7ffd8000,start=(nil),name=0x110618,unicode=1} } --- snip ---
After receiving the "create process" event, the father creates some mutexes (the child will look for it):
--- snip --- 0018: create_mutex( access=001f0001, attributes=00000080, owned=0, objattr={rootdir=0x14,sd={},name=L"19::DA0D2092E0"} ) 0018: create_mutex() = 0 { handle=0x64 } 0018: resume_thread( handle=0x50 ) 0018: resume_thread() = 0 { count=1 } 0018: create_mutex( access=001f0001, attributes=00000080, owned=0, objattr={rootdir=0x14,sd={},name=L"DILLOCREATE"} ) 0018: create_mutex() = 0 { handle=0x68 } 0018: close_handle( handle=0x68 ) 0018: close_handle() = 0 0018: create_mutex( access=001f0001, attributes=00000080, owned=0, objattr={rootdir=0x14,sd={},name=L"DILLOOEP"} ) 0018: create_mutex() = 0 { handle=0x68 } --- snip ---
Some time later in child process code:
--- snip --- 001a: open_mutex( access=001f0001, attributes=00000000, rootdir=0x24, name=L"19:DAF" ) 001a: open_mutex() = 0 { handle=0x74 } .. 001a: set_window_text( handle=0x10028, text=L"Error!" ) 001a: set_window_text() = 0 --- snip ---
Well, what happens? The mutexes are the critical point, they serve to synchronize father and child startup phases.
Unfortunately there is a race condition which allows the child to create a mutex which it is not allowed to (due to absence of certain father-created mutexes) which leads to this error.
Remember the point when the father attached to the child and restores the original entry point code? As soon as the father resumes the execution of the child's main thread, the child begins to execute further. At the same time the father enters it's main debugging loop, waiting to receive first debug events. This is actually the race: the "process creation" event might be a bit too late when the child already executed some chunk of code.
The problem can be prevented by not resuming child's main thread before entering debugger event loop/creating mutexes. Another solution whould be to guard the page at restored opcode location to let any execution immediately cause page guard exception which would ideally suspend the child thread again (like the protector does for the rest of code to decrypt/encrypt code pages on the fly). When the debugger loop is entered it would receive process creation and page guard exception event serialized and coulde handle it appropriately.
Regards
http://bugs.winehq.org/show_bug.cgi?id=12948
--- Comment #8 from Martym martym.de.lagos@gmail.com 2008-07-27 23:41:12 --- Odd since I have been using it for quite some time in Wine without any issues. I am using the same exact install file I downloaded when zMud 7.21 came out and yet today it does not work.
It did work in v9.6 of Wine and once, around v 1.0 for a couple minutes, that is, I updated and launched the app and it worked, once I realised that all my settings were not in place I exited out, moved the folder over, restarted and got the same old message again.
The things that have changed are my kernel and Wine. Zmud has not so how can it be the application when it is the only constant in the equation?
M
(In reply to comment #7)
Hello,
I found the problem ... prepare for journey into debuggers and race conditions ;-) In short: it's a bug in the software protection code which the application is bundled with - not fixable in Wine.
Prerequisite:
- enable wineserver tracing which slows it down sufficiently to observe and log
the behaviour
- "pre-start" wineserver with a console program (cmd.exe) just to let it sit
and wait
Following are relevant process/thread ids to follow snippets:
--- snip --- process tid prio (all id:s are in hex) .. 00000017 0000001b 2 'Zmud.exe' (father, acting as debugger) 00000018 1 'Zmud.exe' (father, acting as debugger) 00000019 0000001a 1 'Zmud.exe' (child, debuggee) .. --- snip ---
The father - which will act as debugger later - creates the child process. The child is created as "suspended" (hence the CREATE_SUSPENDED flags):
--- snip --- 0018: new_process( inherit_all=1, create_flags=00000004, socket_fd=16, exe_file=0x44, hstdin=0x4, hstdout=0x8, hstderr=0xc, process_access=001f0fff, process_attr=00000000, thread_access=001f03ff, thread_attr=00000000, info={AllocationSize=1000,Size=5e4,Flags=0,DebugFlags=0,ConsoleHandle=(nil),ConsoleFlags=0,hStdInput=0x4,hStdOutput=0x8,hStdError=0xc,CurrentDirectory.Handle=(nil),dwX=0,dwY=0,dwXSize=0,dwYSize=0,dwXCountChars=0,dwYCountChars=0,dwFillAttribute=0,dwFlags=0,wShowWindow=1,CurrentDirectory.DosPath=L"C:\Program Files\zMUD\",DllPath=L"C:\Program Files\zMUD;.;C:\windows\system32;C:\windows\system;C:\windows;C:\windows\system32;C:\windows",ImagePathName=L"C:\Program Files\zMUD\Zmud.exe",CommandLine=L"./Zmud.exe",WindowTitle=L"",Desktop=L"",ShellInfo=L"",RuntimeInfo=L""}, ... 0018: new_process() = 0 { info=0x48, pid=0019, phandle=0x4c, tid=001a, thandle=0x50 } --- snip ---
The main thread of the child gets created and process init is done:
--- snip --- 001a: init_thread( unix_pid=17405, unix_tid=17405, debug_level=0, teb=0x7ffd8000, peb=0x7ffdf000, entry=(nil), ldt_copy=0x601239e0, reply_fd=5, wait_fd=7 ) 001a: init_thread() = 0 { pid=0019, tid=001a, info_size=7598, server_start=1c8efe01f98c966 (-3.6957770), version=341 } ... 001a: init_process_done( module=0x400000, entry=0x94ef73, gui=1 ) 0018: *wakeup* signaled=0 cookie=0x16dd154 001a: *sent signal* signal=10 001a: init_process_done() = 0 --- snip ---
After the create process call returns, the father rewrites entry point in the child with an 0xEB, 0xFE opcode sequence which is basically a jump to itself. Remember: PE entry point is not executed yet due to suspended creation. This opcode sequence will let the child enter an endless loop when the main thread of the child process is resumed and the location is hit.
--- snip --- 0018: get_new_process_info( info=0x48 ) 0018: get_new_process_info() = 0 { success=1, exit_code=259 } .. 0018: read_process_memory( handle=0x4c, addr=0x94ef73 ) .. 0018: write_process_memory( handle=0x4c, addr=0x94ef73, data={eb,fe} ) .. 0018: resume_thread( handle=0x50 ) 0018: resume_thread() = 0 { count=1 } --- snip ---
The father continuously suspends child's main thread, fetching thread context and resumes it again until the EIP of rewritten code is reached:
--- snip --- 0018: suspend_thread( handle=0x50 ) 001a: *sent signal* signal=10 0018: suspend_thread() = 0 { count=0 } 0018: get_thread_context( handle=0x50, flags=00010001, suspend=0 ) 0018: get_thread_context() = PENDING { self=0, context={} } 001a: set_thread_context( .. 001a: set_thread_context() = 0 { self=1 } 0018: suspend_thread( handle=0x50 ) 0018: suspend_thread() = 0 { count=1 } 0018: get_thread_context( handle=0x50, flags=00010001, suspend=0 ) 0018: get_thread_context() = 0 { ... } 001a: select( flags=4, cookie=0x7ffdb7b4, signal=(nil), prev_apc=(nil), timeout=0, result={}, handles={} ) 001a: select() = PENDING { apc_handle=(nil), timeout=1c8efe0224574ac (+0.0000000), call={APC_NONE} } 0018: resume_thread( handle=0x50 ) 0018: resume_thread() = 0 { count=2 } 0018: resume_thread( handle=0x50 ) 001a: *wakeup* signaled=258 cookie=0x7ffdb7b4 0018: resume_thread() = 0 { count=1 } .. --- snip ---
When the child entered the endless loop, the father will attach to the child process to receive debug events. From now on, the father acts as debugger.
--- snip --- 0018: debug_process( pid=0019, attach=1 ) 001a: *signal* signal=19 0018: debug_process() = 0 --- snip ---
Next, the father restores the overwritten sequence with original code and resumes the child:
--- snip --- 001a: get_thread_context( handle=0xfffffffe, flags=00010007, suspend=1 ) 001a: get_thread_context() = 0 { self=1, context= .. 0018: suspend_thread( handle=0x50 ) 0018: suspend_thread() = 0 { count=0 } 0018: write_process_memory( handle=0x4c, addr=0x94ef73, data={55,8b} ) 001a: *signal* signal=19 0018: write_process_memory() = 0 0018: new_thread( access=001f03ff, attributes=00000000, suspend=1, request_fd=14 ) 0018: *fd* 14 <- 71 0018: new_thread() = 0 { tid=001b, handle=0x5c } ... 0018: resume_thread( handle=0x5c ) 001b: *wakeup* signaled=258 cookie=0x7ffd77b4 0018: resume_thread() = 0 { count=1 } --- snip ---
The child begins to execute entry code, this is the problematic section (explanation later):
--- snip --- 001a: open_mutex( access=001f0001, attributes=00000000, rootdir=0x24, name=L"19::DA0D2092E0" ) 001a: open_mutex() = OBJECT_NAME_NOT_FOUND { handle=(nil) } 001a: open_mutex( access=001f0001, attributes=00000000, rootdir=0x24, name=L"19::DA0D2092E0" ) 001a: open_mutex() = OBJECT_NAME_NOT_FOUND { handle=(nil) } 001a: set_thread_info( handle=0xfffffffe, mask=1, priority=1, affinity=00000000, token=(nil) ) 001a: set_thread_info() = 0 001a: create_mutex( access=001f0001, attributes=00000080, owned=0, objattr={rootdir=0x24,sd={},name=L"19:DAF"} ) 001a: create_mutex() = 0 { handle=0x40 } --- snip ---
The father enters its debugger loop and receives first debug events:
--- snip --- 0018: get_process_info( handle=0x4c ) 0018: get_process_info() = 0 { pid=0019, ppid=0017, exit_code=259, priority=2, affinity=ffffffff, peb=0x7ffdf000, start_time=1c8efe021cc4f50 (-0.8118270), end_time=0 } 0018: wait_debug_event( get_handle=1 ) 0018: wait_debug_event() = 0 { pid=0019, tid=001a, wait=(nil), event={create_process,file=0x54,process=0x44,thread=0x48,base=0x400000,offset=0,size=0,teb=0x7ffd8000,start=(nil),name=0x110618,unicode=1} } --- snip ---
After receiving the "create process" event, the father creates some mutexes (the child will look for it):
--- snip --- 0018: create_mutex( access=001f0001, attributes=00000080, owned=0, objattr={rootdir=0x14,sd={},name=L"19::DA0D2092E0"} ) 0018: create_mutex() = 0 { handle=0x64 } 0018: resume_thread( handle=0x50 ) 0018: resume_thread() = 0 { count=1 } 0018: create_mutex( access=001f0001, attributes=00000080, owned=0, objattr={rootdir=0x14,sd={},name=L"DILLOCREATE"} ) 0018: create_mutex() = 0 { handle=0x68 } 0018: close_handle( handle=0x68 ) 0018: close_handle() = 0 0018: create_mutex( access=001f0001, attributes=00000080, owned=0, objattr={rootdir=0x14,sd={},name=L"DILLOOEP"} ) 0018: create_mutex() = 0 { handle=0x68 } --- snip ---
Some time later in child process code:
--- snip --- 001a: open_mutex( access=001f0001, attributes=00000000, rootdir=0x24, name=L"19:DAF" ) 001a: open_mutex() = 0 { handle=0x74 } .. 001a: set_window_text( handle=0x10028, text=L"Error!" ) 001a: set_window_text() = 0 --- snip ---
Well, what happens? The mutexes are the critical point, they serve to synchronize father and child startup phases.
Unfortunately there is a race condition which allows the child to create a mutex which it is not allowed to (due to absence of certain father-created mutexes) which leads to this error.
Remember the point when the father attached to the child and restores the original entry point code? As soon as the father resumes the execution of the child's main thread, the child begins to execute further. At the same time the father enters it's main debugging loop, waiting to receive first debug events. This is actually the race: the "process creation" event might be a bit too late when the child already executed some chunk of code.
The problem can be prevented by not resuming child's main thread before entering debugger event loop/creating mutexes. Another solution whould be to guard the page at restored opcode location to let any execution immediately cause page guard exception which would ideally suspend the child thread again (like the protector does for the rest of code to decrypt/encrypt code pages on the fly). When the debugger loop is entered it would receive process creation and page guard exception event serialized and coulde handle it appropriately.
Regards
http://bugs.winehq.org/show_bug.cgi?id=12948
--- Comment #9 from Anastasius Focht focht@gmx.net 2008-07-28 01:17:28 --- Created an attachment (id=15131) --> (http://bugs.winehq.org/attachment.cgi?id=15131) +tid,+server tracelogs for successful and failing run
Hello,
such race conditions do not manifest every time (by nature). Everything in system can change timing behaviour. There is only a small time frame where this problem manifests (milliseconds range).
I did my analysis and came to this conclusion. Attached are the server traces from failing and successful run.
You can grep the files for all mutexes, remove wine builtin ones and compare both files regarding order of mutex creation (by thread id). The key one is "<pid>:DAF".
For me this case is closed.
Regards
http://bugs.winehq.org/show_bug.cgi?id=12948
Austin English austinenglish@gmail.com changed:
What |Removed |Added ---------------------------------------------------------------------------- CC| |MattFinn@gmail.com
--- Comment #10 from Austin English austinenglish@gmail.com 2008-10-18 16:06:34 --- *** Bug 3998 has been marked as a duplicate of this bug. ***
http://bugs.winehq.org/show_bug.cgi?id=12948
--- Comment #11 from Anastasius Focht focht@gmx.net 2008-10-19 07:02:43 --- Hello,
revisiting... some unsatisfying stuff never leaves my mind ;-)
After reanalyzing the logs I came to conclusion this might be a Linux 2.6 kernel bug. The main problem is that the child thread wakes up - creating mutexes before the father (debugger) - when it isn't supposed to. After debug_process() the child should be left in stopped state until the debug events are handled in father debugger loop (see log, child main thread received SIGSTOP).
The father restores the child's entry point to original state using WriteProcessMemory(). Wine(server) uses ptrace() facility to carry out the task of writing process memory.
1. ptrace PTRACE_ATTACH which should generate SIGSTOP. 2. waits until target is stopped (SIGSTOP seen). 3. carries out the memory write. 4. ptrace PTRACE_DETACH to continue in normal untraced mode (resume execution, depending on state)
The last step should leave the child in stopped state because as it was already with earlier debug_process() and the father (debugger) loop didn't handle the initial debug events yet.
What happens is that sometimes the child main thread is unconditionally woken up so I think ptrace() is to blame here. As quickfix I looked at thread state before the ptrace sequence and doing PTRACE_DETACH( ... SIGSTOP) if the target was in stopped state before to prevent spurious wakeup after detach. But even that doesn't seem to work reliably .. sucks.
At least the problem seems to be harder to reproduce in my late 2.6.26 kernels.
Regards
http://bugs.winehq.org/show_bug.cgi?id=12948
Scott Ritchie scott@open-vote.org changed:
What |Removed |Added ---------------------------------------------------------------------------- Status|UNCONFIRMED |RESOLVED CC| |scott@open-vote.org Resolution| |WORKSFORME
--- Comment #12 from Scott Ritchie scott@open-vote.org 2009-07-16 03:57:06 --- This seems to work fine on Ubuntu 9.04 using kernel 2.6.28-11-generic and latest Wine -- I'm going to resolve this worksforme since it seems like it was an old kernel bug. Wine did have some problems with ptrace in the past.
http://bugs.winehq.org/show_bug.cgi?id=12948
Dmitry Timoshkov dmitry@codeweavers.com changed:
What |Removed |Added ---------------------------------------------------------------------------- Resolution|WORKSFORME |INVALID
--- Comment #13 from Dmitry Timoshkov dmitry@codeweavers.com 2009-07-16 03:59:49 --- Then it's invalid.
http://bugs.winehq.org/show_bug.cgi?id=12948
Dmitry Timoshkov dmitry@codeweavers.com changed:
What |Removed |Added ---------------------------------------------------------------------------- Status|RESOLVED |CLOSED
--- Comment #14 from Dmitry Timoshkov dmitry@codeweavers.com 2009-07-16 04:01:33 --- Closing invalid.
http://bugs.winehq.org/show_bug.cgi?id=12948
--- Comment #15 from Martym martym.de.lagos@gmail.com 2009-07-16 09:40:47 ---
I am still getting the same error on 2.6.28-11 kernel and the latest version of WINE (1.01)
http://bugs.winehq.org/show_bug.cgi?id=12948
--- Comment #16 from Austin English austinenglish@gmail.com 2009-07-16 11:03:14 --- (In reply to comment #15)
I am still getting the same error on 2.6.28-11 kernel and the latest version of WINE (1.01)
1.0.1 is not the latest wine. 1.1.25 is (1.1.26 due out tomorrow).
http://bugs.winehq.org/show_bug.cgi?id=12948
--- Comment #17 from Martym martym.de.lagos@gmail.com 2009-07-18 16:38:43 --- Well I updated to the latest kernel 2.6.28-13-generic and did a clean install of version 1.1.26 of Wine with, as expected, the same results.
http://bugs.winehq.org/show_bug.cgi?id=12948
Austin English austinenglish@gmail.com changed:
What |Removed |Added ---------------------------------------------------------------------------- CC| |feydreva@lsu.fr
--- Comment #18 from Austin English austinenglish@gmail.com 2009-09-08 11:27:22 --- *** Bug 13178 has been marked as a duplicate of this bug. ***
http://bugs.winehq.org/show_bug.cgi?id=12948
--- Comment #19 from Anastasius Focht focht@gmx.net 2010-08-19 16:19:20 --- *** Bug 11821 has been marked as a duplicate of this bug. ***
http://bugs.winehq.org/show_bug.cgi?id=12948
Anastasius Focht focht@gmx.net changed:
What |Removed |Added ---------------------------------------------------------------------------- Keywords| |obfuscation Summary|zmud does not run under |zmud does not run under |Ubuntu 8.04 (...turn off |Ubuntu 8.04 (armadillo |system debuggers) |software protection, ptrace | |spurious wakeup)