Hi all,
with great help of Ove and Eric & Co., I discovered a fatal Wine
architecture issue today.
The BattleCom server (freely downloadable on the net) does a timeSetEvent().
That timeSetEvent will let the service thread send timer notifications to
the calling thread.
Unfortunately I never get *any* timer callback invokation (timeGetTime()
really gets called by the program, of course !).
The program enters a WaitForSingleObject() (WFSO) on the event created with
CreateEvent() that is supposed to get set to signalled within the
timer callback function.
And that WFSO() deadlocks !
Why ?
Because the service thread does a SendMessage() (*not* a PostMessage !)
of a WM_NCPAINT to the very same thread that listens to the timer
notifications.
Unfortunately that thread now already waits for the timer msgs to arrive,
so the WM_NCPAINT SendMessage() doesn't succeed in transmitting its info
to this thread.
And as SendMessage() doesn't return, the service thread is blocked and
can't do the timer callback invokation any more, so the WFSO()
can never return.
--> Deadlock !
Possible solutions are:
1. Create a separate thread solely for MM timers. Baaad IMHO.
This doesn't really solve the deadlock problem (might happen again for
other service thread tasks).
2. Move the draw handling out of the service thread, as it tends to block
due to use of SendMessage(). (Ove's suggestion)
3. ??
What to do ?
The status at deadlock time is:
Service thread:
(gdb) bt
#0 0x403d2634 in read () from /lib/libc.so.6
#1 0x402b3138 in __DTOR_END__ () from /usr/local/src/wine/libwine.so
#2 0x4014ce67 in server_call_noerr (req=REQ_SELECT) at client.c:271
#3 0x401524ca in WaitForMultipleObjectsEx (count=1, handles=0x40f268ec,
wait_all=0, timeout=4294967295, alertable=0) at ../include/server.h:1336
#4 0x401523d0 in WaitForSingleObject (handle=1414155715, timeout=4294967295)
at synchro.c:65
#5 0x40188beb in QUEUE_WaitBits (bits=32768, timeout=4294967295)
at queue.c:721
#6 0x4017b1e8 in MSG_SendMessageInterThread (hDestQueue=703, hwnd=496,
msg=133, wParam=5850, lParam=0, timeout=4294967295, flags=4096,
pRes=0x40f26a00) at message.c:876
#7 0x4017c9c8 in MSG_SendMessage (hwnd=496, msg=133, wParam=5850, lParam=0,
timeout=4294967295, flags=4096, pRes=0x40f26a00) at message.c:1772
#8 0x4017cafe in SendMessageA (hwnd=496, msg=133, wParam=5850, lParam=0)
at message.c:1819
#9 0x401848a8 in WIN_UpdateNCRgn (wnd=0x4043f620, hRgn=0, uncFlags=5)
at painting.c:246
#10 0x401856e5 in RDW_Paint (wndPtr=0x4043f620, hrgn=0, flags=1669, ex=0)
at painting.c:762
#11 0x40185cc1 in PAINT_RedrawWindow (hwnd=496, rectUpdate=0x40f26c38,
hrgnUpdate=0, flags=1669, ex=0) at painting.c:956
#12 0x40185d25 in RedrawWindow (hwnd=496, rectUpdate=0x40f26c38, hrgnUpdate=0,
flags=1669) at painting.c:972
#13 0x4014a3cf in RELAY_CallFrom32 (ret_addr=1084333293) at relay386.c:242
#14 0x405e781d in exports () from /usr/local/src/wine/dlls/libuser32.so
#15 0x40a1965b in EVENT_ProcessEvent (event=0x40f26d48) at event.c:415
#16 0x40a19150 in EVENT_ProcessAllEvents (arg=0) at event.c:198
#17 0x40151d4f in SERVICE_Loop (service=0x4043eaac) at services.c:80
---Type <return> to continue, or q <return> to quit---
#18 0x40153692 in THREAD_Start () at thread.c:269
#19 0x40152698 in SYSDEPS_StartThread (teb=0x40f37000) at sysdeps.c:136
Program thread:
(gdb) bt
#0 0x403d2634 in read () from /lib/libc.so.6
#1 0x402b3138 in __DTOR_END__ () from /usr/local/src/wine/libwine.so
#2 0x4014ce67 in server_call_noerr (req=REQ_SELECT) at client.c:271
#3 0x401524ca in WaitForMultipleObjectsEx (count=1, handles=0x408c6b44,
wait_all=0, timeout=4294967295, alertable=0) at ../include/server.h:1336
#4 0x401523d0 in WaitForSingleObject (handle=HTIMEREVENT, timeout=INFINITE)
at synchro.c:65
#5 0x4014a3aa in RELAY_CallFrom32 (ret_addr=1577748549) at relay386.c:240
The relay things are:
Call kernel32.174: CreateSemaphoreA(00000000,00000000,0000ffff,00000000) ret=5e0a86d2
fs=008f
08060d38: create_semaphore( initial=00000000, max=0000ffff, inherit=0, name=L""
)
08060d38: create_semaphore() = 0 { handle=172 }
Ret kernel32.174: CreateSemaphoreA() retval=000000ac ret=5e0a86d2 fs=008f
Call kernel32.156: CreateEventA(00000000,00000000,00000000,00000000) ret=5e0a86e1
fs=008f
08060d38: create_event( manual_reset=0, initial_state=0, inherit=0, name=L"" )
08060d38: create_event() = 0 { handle=176 }
Ret kernel32.156: CreateEventA() retval=HTIMEREVENT ret=5e0a86e1 fs=008f
.
.
.
Call winmm.144: timeSetEvent(00000014,00000014,5e0a82d4,00000000,00000001)
ret=5e0a8731 fs=008f
^^^^^^^^ this callback is supposed to
SetEvent() the event, I guess
trace:mmtime:timeSetEventInternal (20, 20, 0x5e0a82d4, 00000000, 0081);
trace:mmtime:MULTIMEDIA_MMTimeStart installing main timer.
08060d38: create_timer( inherit=0, manual=0, name=L"" )
08060d38: create_timer() = 0 { handle=180 }
08060d38: set_timer( handle=180, sec=0, usec=0, period=10, callback=(nil), arg=(nil) )
08060d38: set_timer() = 0
08060d38: queue_apc( handle=32, func=(nil), param=(nil) )
08060d38: queue_apc() = 0
trace:mmtime:timeSetEventInternal => 1
Ret winmm.144: timeSetEvent() retval=00000001 ret=5e0a8731 fs=008f
.
.
.
Call winmm.142: timeGetTime() ret=5e0a8568 fs=008f
Ret winmm.142: timeGetTime() retval=18c06c32 ret=5e0a8568 fs=008f
.
.
.
(no timer callback invokations in here)
.
.
.
Call kernel32.723: WaitForSingleObject(HTIMEREVENT,INFINITE) ret=5e0a8845 fs=008f
08060d38: select( count=1, flags=0, timeout=-1, handles={176} )
[HUNG]
Andreas Mohr
