https://bugs.winehq.org/show_bug.cgi?id=14697
--- Comment #8 from Anastasius Focht focht@gmx.net --- Hello folks,
still present.
I found another manifestation of the design problem with some native API implemented using APC, now with only a main thread present in debuggee.
Debugger = 32-bit variant of x64_dbg
tid 0x09 = debugger main thread (gui) tid 0x25 = debugger thread (script thread) tid 0x28 = debugger thread (debugger event loop, partially blocking, partially live looping with Sleep)
tid 0x27 = debuggee main thread
Single stepping in debuggee:
--- snip --- 0027: queue_exception_event( first=1, code=80000004, flags=00000000, record=00000000, address=7bc80526, len=0, params={}, context={cpu=x86,eip=7bc80526,esp=0033dca0,ebp=0033dda8,eflags=00200246,cs=0023,ss=002b,ds=002b,es=002b,fs=0063,gs=006b,eax=000000c0,ebx=7bcd3000,ecx=0033dc78,edx=00000000,esi=0033e674,edi=00000000,dr0=00000000,dr1=00000000,dr2=00000000,dr3=00000000,dr6=00004000,dr7=00000000,...}} ) ... 0027: queue_exception_event() = 0 { handle=0070 } ... 0027: select( flags=2, cookie=0033d07c, timeout=infinite, prev_apc=0000, result={}, data={WAIT,handles={0070}} ) 0027: select() = PENDING { timeout=infinite, call={APC_NONE}, apc_handle=0000 } 0028:Ret KERNEL32.ContinueDebugEvent() retval=00000001 ret=0093ed78 0028:Call KERNEL32.WaitForDebugEvent(0099c6d0,ffffffff) ret=0093cb5f 0028: wait_debug_event( get_handle=1 ) 0028: wait_debug_event() = 0 { pid=0026, tid=0027, wait=0000, event={exception,first=1,exc_code=80000004,flags=00000000,record=00000000,address=7bc80526,params={}} } 0028:Ret KERNEL32.WaitForDebugEvent() retval=00000001 ret=0093cb5f ... --- snip ---
Setting softbp in debuggee using GUI (internally using scripting engine).
PAGE_EXECUTE_READWRITE to prepare for patching opcodes which causes execution of APC.
--- snip --- ... 0025:Call KERNEL32.VirtualProtectEx(00000354,7bc8053a,00000001,00000040,09f0d9a4) ret=00952892 0025: queue_apc( handle=0354, call={APC_VIRTUAL_PROTECT,addr=7bc8053a,size=00000001,prot=40} ) 0027: *wakeup* signaled=192 0025: queue_apc() = 0 { handle=039c, self=0 } 0025: select( flags=2, cookie=09f0d55c, timeout=infinite, prev_apc=0000, result={}, data={WAIT_ALL,handles={039c}} ) 0025: select() = PENDING { timeout=infinite, call={APC_NONE}, apc_handle=0000 } 0027: select( flags=2, cookie=0033d07c, timeout=infinite, prev_apc=0000, result={}, data={WAIT,handles={0070}} ) 0027: select() = USER_APC { timeout=infinite, call={APC_VIRTUAL_PROTECT,addr=7bc8053a,size=00000001,prot=40}, apc_handle=0074 } 0027: select( flags=2, cookie=0033d07c, timeout=infinite, prev_apc=0074, result={APC_VIRTUAL_PROTECT,status=0,addr=7bc80000,size=00001000,prot=20}, data={WAIT,handles={0070}} ) 0028:Ret KERNEL32.Sleep() retval=00000000 ret=007c236c 0025: *wakeup* signaled=0 0028:Call KERNEL32.Sleep(00000001) ret=007c236c 0027: select() = PENDING { timeout=infinite, call={APC_NONE}, apc_handle=0000 } 0025: get_apc_result( handle=039c ) 0025: get_apc_result() = 0 { result={APC_VIRTUAL_PROTECT,status=0,addr=7bc80000,size=00001000,prot=20} } 0025:Ret KERNEL32.VirtualProtectEx() retval=00000001 ret=00952892 --- snip ---
Save opcode and write softbp (int 3):
--- snip --- 0025:Call KERNEL32.ReadProcessMemory(00000354,7bc8053a,09f0d9c1,00000001,09f0d9b0) ret=009528b3 0025: read_process_memory( handle=0354, addr=7bc8053a ) 0027: *signal* signal=19 0025: read_process_memory() = 0 { data={74} } 0025:Ret KERNEL32.ReadProcessMemory() retval=00000001 ret=009528b3 0025:Call KERNEL32.WriteProcessMemory(00000354,7bc8053a,009897ea,00000001,09f0d9b0) ret=009528d8 0025: write_process_memory( handle=0354, addr=7bc8053a, data={cc} ) 0027: *signal* signal=19 0025: write_process_memory() = 0 0025:Ret KERNEL32.WriteProcessMemory() retval=00000001 ret=009528d8 --- snip ---
Make code PAGE_EXECUTE_READ again (causes queuing of APC):
--- snip --- 0025:Call KERNEL32.VirtualProtectEx(00000354,7bc8053a,00000001,00000020,09f0d9a4) ret=00952922 0025: queue_apc( handle=0354, call={APC_VIRTUAL_PROTECT,addr=7bc8053a,size=00000001,prot=20} ) 0027: *wakeup* signaled=192 0025: queue_apc() = 0 { handle=039c, self=0 } 0025: select( flags=2, cookie=09f0d55c, timeout=infinite, prev_apc=0000, result={}, data={WAIT_ALL,handles={039c}} ) 0025: select() = PENDING { timeout=infinite, call={APC_NONE}, apc_handle=0000 } 0027: queue_exception_event( first=1, code=80000003, flags=00000000, record=00000000, address=7bc8053a, len=0, params={}, context={cpu=x86,eip=7bc8053b,esp=0033cfa0,ebp=0033d0a8,eflags=00200246,cs=0023,ss=002b,ds=002b,es=002b,fs=0063,gs=006b,eax=00000000,ebx=7bcd3000,ecx=00000024,edx=0033d054,esi=0033d974,edi=00000000,dr0=00000000,dr1=00000000,dr2=00000000,dr3=00000000,dr6=00004000,dr7=00000000,...}} ) 0027: queue_exception_event() = 0 { handle=0074 } 0027: select( flags=2, cookie=0033c37c, timeout=infinite, prev_apc=0000, result={}, data={WAIT,handles={0074}} ) 0027: select() = USER_APC { timeout=infinite, call={APC_VIRTUAL_PROTECT,addr=7bc8053a,size=00000001,prot=20}, apc_handle=0078 } 0027: queue_exception_event( first=1, code=80000003, flags=00000000, record=00000000, address=7bc8053a, len=0, params={}, context={cpu=x86,eip=7bc8053b,esp=0033c2a0,ebp=0033c3a8,eflags=00200246,cs=0023,ss=002b,ds=002b,es=002b,fs=0063,gs=006b,eax=00000000,ebx=7bcd3000,ecx=0033c32c,edx=00000000,esi=0033cc74,edi=00000000,dr0=00000000,dr1=00000000,dr2=00000000,dr3=00000000,dr6=00004000,dr7=00000000,... ... 0028:Ret KERNEL32.Sleep() retval=00000000 ret=007c236c 0027: queue_exception_event() = 0 { handle=007c } 0028:Call KERNEL32.Sleep(00000001) ret=007c236c 0027: select( flags=2, cookie=0033b67c, timeout=infinite, prev_apc=0000, result={}, data={WAIT,handles={007c}} ) 0027: select() = PENDING { timeout=infinite, call={APC_NONE}, apc_handle=0000 } 0028:Ret KERNEL32.Sleep() retval=00000000 ret=007c236c ... 0009:err:ntdll:RtlpWaitForCriticalSection section 0x99d3f0 "?" wait timed out in thread 0009, blocked by 0025, retrying (60 sec) --- snip ---
At this point the debugger and debuggee are stuck.
The problem can be partially attributed to the rather unusual handling of debug events on the debugger side. Instead of having thread 0x28 doing debug event loop continuously using blocking waits, the state machine also has a state where it basically live loops with 'Sleep(1)', polling for variable state changes from other debugger threads until entering the blocking wait again using 'WaitForDebugEvent'.
During execution of APC_VIRTUAL_PROTECT on the debuggee side, the breakpoint is hit (most likely in area/caller of 'server_select') which causes EXCEPTION_DEBUG_EVENT being sent to debugger. The debugger event thread 0x28 is in a state where it live loops using Sleep(1), unable to handle debug events until the opcode patching sequence finishes in script engine thread 0x25 (return from 'VirtualProtectEx') which blocks debug event delivery/completion. This in turn prevents APC_VIRTUAL_PROTECT from being completed on debuggee side.
$ wine --version wine-1.7.37
Regards