https://bugs.winehq.org/show_bug.cgi?id=47380
Bug ID: 47380 Summary: GT Legends: Slow graphics and 100% CPU usage Product: Wine Version: 4.10 Hardware: x86-64 OS: Linux Status: UNCONFIRMED Severity: normal Priority: P2 Component: directx-d3d Assignee: wine-bugs@winehq.org Reporter: timschumi@gmx.de Distribution: ---
GT Legends does have a significant graphics slowdown when running in wine, while a single CPU thread is locked at 100%.
When looking at the process in a profiler, most of the time is spent in the function wined3d_cs_mt_finish() (and I guess the wined3d_pause() function within, which doesn't show up in a profiler due to being inline).
This seems to be a regression as well, since there are videos (for Wine 1.9.10, [1]) and AppDB entries (latest entry for Wine 1.7.0, [2]) that claim that the game was running fine on earlier releases of Wine, but I wasn't able to find the exact commit that introduced the regression so far.
Patches from wine-staging don't help either. Please let me know what type of logs would be the most suitable ones to debug this, since a normal +d3d log seems impractical with over 13MB in size.
[1] https://www.youtube.com/watch?v=L80NsdNcVgI [2] https://appdb.winehq.org/objectManager.php?sClass=version&iId=28706
https://bugs.winehq.org/show_bug.cgi?id=47380
leillo1975@gmail.com leillo1975@gmail.com changed:
What |Removed |Added ---------------------------------------------------------------------------- CC| |leillo1975@gmail.com
--- Comment #1 from leillo1975@gmail.com leillo1975@gmail.com --- I have exactly the same problem.
https://bugs.winehq.org/show_bug.cgi?id=47380
--- Comment #2 from leillo1975@gmail.com leillo1975@gmail.com --- I recorded a video to show the problem:
https://bugs.winehq.org/show_bug.cgi?id=47380
Olivier F. R. Dierick o.dierick@piezo-forte.be changed:
What |Removed |Added ---------------------------------------------------------------------------- CC| |o.dierick@piezo-forte.be
--- Comment #3 from Olivier F. R. Dierick o.dierick@piezo-forte.be --- Hello,
Always start with a normal log (no WINEDEBUG).
Regards.
https://bugs.winehq.org/show_bug.cgi?id=47380
--- Comment #4 from Tim Schumacher timschumi@gmx.de --- Created attachment 64715 --> https://bugs.winehq.org/attachment.cgi?id=64715 Wine 4.10 default log
https://bugs.winehq.org/show_bug.cgi?id=47380
Józef Kucia joseph.kucia@gmail.com changed:
What |Removed |Added ---------------------------------------------------------------------------- Ever confirmed|0 |1 Status|UNCONFIRMED |NEW
--- Comment #5 from Józef Kucia joseph.kucia@gmail.com --- It might be worth to test if performance is better when CSMT is disabled: https://wiki.winehq.org/Useful_Registry_Keys
https://bugs.winehq.org/show_bug.cgi?id=47380
--- Comment #6 from Tim Schumacher timschumi@gmx.de --- (In reply to Józef Kucia from comment #5)
It might be worth to test if performance is better when CSMT is disabled: https://wiki.winehq.org/Useful_Registry_Keys
Welp, that fixed it. Is this considered a proper fix or a workaround (I'm assuming the latter)?
https://bugs.winehq.org/show_bug.cgi?id=47380
--- Comment #7 from leillo1975@gmail.com leillo1975@gmail.com --- (In reply to Józef Kucia from comment #5)
It might be worth to test if performance is better when CSMT is disabled: https://wiki.winehq.org/Useful_Registry_Keys
It works, It's great!!!! Thanks a lot!!!
https://bugs.winehq.org/show_bug.cgi?id=47380
Józef Kucia joseph.kucia@gmail.com changed:
What |Removed |Added ---------------------------------------------------------------------------- See Also| |https://bugs.winehq.org/sho | |w_bug.cgi?id=45893
https://bugs.winehq.org/show_bug.cgi?id=47380
Józef Kucia joseph.kucia@gmail.com changed:
What |Removed |Added ---------------------------------------------------------------------------- See Also| |https://bugs.winehq.org/sho | |w_bug.cgi?id=44260
https://bugs.winehq.org/show_bug.cgi?id=47380
--- Comment #8 from Józef Kucia joseph.kucia@gmail.com --- (In reply to Tim Schumacher from comment #6)
Welp, that fixed it. Is this considered a proper fix or a workaround (I'm assuming the latter)?
It's a workaround.
https://bugs.winehq.org/show_bug.cgi?id=47380
--- Comment #9 from Tim Schumacher timschumi@gmx.de --- Created attachment 64727 --> https://bugs.winehq.org/attachment.cgi?id=64727 Log of cs_run_thread and cs_mt_finish calls
I added logging statements to the beginning of the wined3d_cs_run_thread and wined3d_cs_mt_finish functions, logging the thread_id that is started and the thread IDs from where the finish function is called.
It seems like the finish method is constantly called from the wrong thread (thead 9 seems to be the main thread), causing the thread to constantly stall instead of calling the singlethread finish function.
I'll mess around with the debugger for a bit to see if I may find where the issue originates from.
https://bugs.winehq.org/show_bug.cgi?id=47380
--- Comment #10 from Henri Verbeet hverbeet@gmail.com --- (In reply to Tim Schumacher from comment #9)
It seems like the finish method is constantly called from the wrong thread (thead 9 seems to be the main thread), causing the thread to constantly stall instead of calling the singlethread finish function.
That's pretty much expected when csmt is enabled. The more interesting information in that log is "queue_id 1" (WINED3D_CS_QUEUE_MAP), which probably means these are caused by wined3d_cs_map() and wined3d_cs_unmap(). (wined3d_cs_emit_update_sub_resource() is possible too, but less likely.)
This is an area that's known to have room for improvement. In some cases it may be possible to avoid going through the CS for the map, in others it may be possible to avoid mapping the resource at all.
https://bugs.winehq.org/show_bug.cgi?id=47380
--- Comment #11 from Tim Schumacher timschumi@gmx.de --- (In reply to Henri Verbeet from comment #10)
(In reply to Tim Schumacher from comment #9)
It seems like the finish method is constantly called from the wrong thread (thead 9 seems to be the main thread), causing the thread to constantly stall instead of calling the singlethread finish function.
That's pretty much expected when csmt is enabled.
From what I read in the code, wouldn't it at least require one call to finish()
from the correct thread to actually do the finish action? The code looks like the following to me:
if (we are on the thread that was started with run_thread) finish the queue else stall until queue is empty
Am I misunderstanding something here?
The more interesting information in that log is "queue_id 1" (WINED3D_CS_QUEUE_MAP), which probably means these are caused by wined3d_cs_map() and wined3d_cs_unmap(). (wined3d_cs_emit_update_sub_resource() is possible too, but less likely.)
The backtrace in the debugger shows that the calls with queue_id 1 are indeed caused by wined3d_cs_map and wined3d_cs_unmap.
The calls with queue_id 0 in the beginning are caused by swapchain_create.
https://bugs.winehq.org/show_bug.cgi?id=47380
--- Comment #12 from Henri Verbeet hverbeet@gmail.com --- (In reply to Tim Schumacher from comment #11)
(In reply to Henri Verbeet from comment #10)
(In reply to Tim Schumacher from comment #9)
It seems like the finish method is constantly called from the wrong thread (thead 9 seems to be the main thread), causing the thread to constantly stall instead of calling the singlethread finish function.
That's pretty much expected when csmt is enabled.
From what I read in the code, wouldn't it at least require one call to finish() from the correct thread to actually do the finish action? The code looks like the following to me:
if (we are on the thread that was started with run_thread) finish the queue else stall until queue is empty
Am I misunderstanding something here?
Mostly just what the "correct" thread is.
In case wined3d_cs_mt_finish() gets called from wined3d_cs_run(), wined3d_cs_mt_finish() can't just wait for the queue to become empty, because it wouldn't be making any progress. Fortunately, the fact that it gets called at all means all previous commands have already finished, so we can just return.
The *normal* situation is that wined3d_cs_mt_finish() gets called from the application thread, and waits for wined3d_cs_run() to catch up. In particular, in wined3d_cs_map(), it waits for the WINED3D_CS_OP_MAP to get executed, so that "map_desc" contains valid information.
It currently wait by just spinning. That's straightforward, but not always optimal. It may be better to sleep depending on e.g. the distance between the head and the tail. The larger problem is still likely that we're calling wined3d_cs_map() at all.
https://bugs.winehq.org/show_bug.cgi?id=47380
--- Comment #13 from Tim Schumacher timschumi@gmx.de --- (In reply to Henri Verbeet from comment #12)
Mostly just what the "correct" thread is.
In case wined3d_cs_mt_finish() gets called from wined3d_cs_run(), wined3d_cs_mt_finish() can't just wait for the queue to become empty, because it wouldn't be making any progress. Fortunately, the fact that it gets called at all means all previous commands have already finished, so we can just return.
Got it. I also only just now noticed that the singlethreaded finish method is empty, which probably would have cleared up my confusion way earlier.
It currently wait by just spinning. That's straightforward, but not always optimal. It may be better to sleep depending on e.g. the distance between the head and the tail. The larger problem is still likely that we're calling wined3d_cs_map() at all.
Is it "the programs fault" (which it probably shouldn't be, because wine tries to implement things with the same behaviour as on Windows) for doing unusual stuff, or is wine's general implementation of this flawed, so that it maps more often than needed (which is, as far as I understood, quite an expensive operation)? I apparently can't see the full stack trace in the debugger (since it starts with d3d9_vertexbuffer_Lock or d3d9_vertexbuffer_Unlock), I'll try and capture the shortest +d3d,+d3d9 log possible and attach that instead.
https://bugs.winehq.org/show_bug.cgi?id=47380
--- Comment #14 from Tim Schumacher timschumi@gmx.de --- Created attachment 64749 --> https://bugs.winehq.org/attachment.cgi?id=64749 +d3d,+d3d9 log from running the game
This is close to the shortest log possible, originating from about 10 to 15 seconds of running the game, start to exit.
https://bugs.winehq.org/show_bug.cgi?id=47380
--- Comment #15 from Matteo Bruni matteo.mystral@gmail.com --- (In reply to Tim Schumacher from comment #13)
Is it "the programs fault" (which it probably shouldn't be, because wine tries to implement things with the same behaviour as on Windows) for doing unusual stuff, or is wine's general implementation of this flawed, so that it maps more often than needed (which is, as far as I understood, quite an expensive operation)?
More or less the latter: Wine's implementation of maps has room for improvement, it doesn't necessarily have to be so expensive.
https://bugs.winehq.org/show_bug.cgi?id=47380
--- Comment #16 from Andrey Gusev andrey.goosev@gmail.com --- Panzer Elite Action Fields of Glory / Dunes of War are also affected.
-
wine-bugs＠winehq.org -
WineHQ Bugzilla