[Bug 43728] Magic: The Gathering Online intensive CPU usage when idle

wine-bugs at winehq.org wine-bugs at winehq.org
Fri Jan 5 05:40:44 CST 2018


https://bugs.winehq.org/show_bug.cgi?id=43728

--- Comment #9 from Panard <panard at 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_.htm
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...

-- 
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.



More information about the wine-bugs mailing list