https://bugs.winehq.org/show_bug.cgi?id=43728
--- Comment #9 from Panard panard@inzenet.org --- Created attachment 60141 --> https://bugs.winehq.org/attachment.cgi?id=60141 output with WINEDEBUG=+relay with docker image on 2018-01-05
I tried to do some investigation as well, following from your logs. I'm using wine staging 2.20, within the docker image panard/mtgo:2017-11-07 on an up-to-date gentoo (intel graphics card)
First, WINEDEBUG=+relay (output attached) does not give the same output as you, notably I don't seen any recurring exceptions. However, I do see a lot of MsgWaitForMultipleObjectsEx calls. The output is after clicking on the "Collection" tab and waiting for some time.
Counting the identical calls gives the following top scorers: $ sort relay.log |uniq -c|sort -n|tail -n 20 222 0119:Ret user32.PeekMessageW() retval=00000000 ret=7e9be214 443 0119:Call ntdll.NtQueryPerformanceCounter(68eed860,68eed868) ret=7b447412 443 0119:Call ntdll.RtlAllocateHeap(00110000,00000000,00000100) ret=7ed0a37c 443 0119:Call ntdll.RtlFreeHeap(00110000,00000000,0da60be0) ret=7ed0a4ca 443 0119:Call ntdll.RtlIsCriticalSectionLockedByThread(7ee4f3e0) ret=7ed3039e 443 0119:Ret ntdll.RtlAllocateHeap() retval=0da60be0 ret=7ed0a37c 443 0119:Ret ntdll.RtlFreeHeap() retval=00000001 ret=7ed0a4ca 443 0119:Ret ntdll.RtlIsCriticalSectionLockedByThread() retval=00000000 ret=7ed3039e 444 0119:Call ntdll.NtYieldExecution() ret=7ed41e18 444 0119:Call winex11.drv.MsgWaitForMultipleObjectsEx(00000000,00000000,00000000,000004ff,00000000) ret=7ed41dce 444 0119:Ret ntdll.NtYieldExecution() retval=00000000 ret=7ed41e18 444 0119:Ret winex11.drv.MsgWaitForMultipleObjectsEx() retval=00000102 ret=7ed41dce 664 0119:Call KERNEL32.GetTickCount() ret=7ed31ae8 664 0119:Call ntdll.RtlEnterCriticalSection(7ee4f460) ret=7ed31ae0 664 0119:Ret ntdll.RtlEnterCriticalSection() retval=00000000 ret=7ed31ae0 665 0119:Call KERNEL32.TlsGetValue(00000006) ret=7e87a62d 665 0119:Call ntdll.RtlLeaveCriticalSection(7ee4f460) ret=7ed31b2f 665 0119:Ret KERNEL32.TlsGetValue() retval=0c74aac8 ret=7e87a62d 665 0119:Ret ntdll.RtlLeaveCriticalSection() retval=00000000 ret=7ed31b2f 886 0119:Ret ntdll.NtQueryPerformanceCounter() retval=00000000 ret=7b447412
The number of calls is within a very short period of time: I let the output flowed only for a couple of seconds and ended up with a 300Mb file, here the file is just 1MB.
The call winex11.drv.MsgWaitForMultipleObjectsEx(00000000,00000000,00000000,000004ff,00000000) might be a bit suspcious. http://winapi.freetechsecrets.com/win32/WIN32MsgWaitForMultipleObjectsEx_New... According to wine sources, the flag 4ff means QS_ALLINPUT.
Grep-ing in wine sources, I found the following caller candidates:
- dlls/dinput/dinput_main.c/check_dinput_events => the documentation made me raise an eyebrow: "Windows does not do that, but our current implementation of winex11 requires periodic event polling to forward events to the wineserver" ; maybe we should try by de-activating this function and see what happen? - dlls/user32/message.c/check_for_driver_events => triggered only if get_user_thread_info()->message_count > 200, which according to the docs means a lot of messages are in queue, which is a bit unlikely here (the MTGO window was not displayed) - dlls/user32/input.c/check_for_events with flags = QS_ALLINPUT => then greping for check_for_events only lead to call with QS_INPUT, therefore, this is a false positive.
I can give a try to disabling check_dinput_events, to see if it makes any difference, although I'm not sure if it is relevant at all...