Bug 108893

Summary: Slow redrawing of menu in Gothic 2 under wine
Product: Mesa Reporter: supercoolemail
Component: Drivers/Gallium/radeonsiAssignee: Default DRI bug account <dri-devel>
Status: RESOLVED MOVED QA Contact: Default DRI bug account <dri-devel>
Severity: normal    
Priority: medium    
Version: 19.0   
Hardware: x86-64 (AMD64)   
OS: Linux (All)   
Whiteboard:
i915 platform: i915 features:
Attachments: Trace of Gothic 2 menu
Latest trace of Gothic 2 menu
sysprof of Gothic 2 menu
sysprof of Gothic 2 menu with LIBGL_ALWAYS_SOFTWARE=1

Description supercoolemail 2018-11-29 08:53:57 UTC
Created attachment 142657 [details]
Trace of Gothic 2 menu

Menu navigation in Gothic 2 under wine 3.21 and mesa 18.2.5 is very slow. After each action it takes 3-6 seconds to redraw. LIGL_ALWAYS_SOFTWARE=1 workarounds it, so I report it here instead to wine. This slowness was present in earlier version too, but it is sometimes faster (3 seconds per action) which I attributed to wine, but now I have noticed, that settings are totally unusable.
Atached apitrace was created this way: when menu items show up, I quickly press arrow down 3 times, arrow up 1 times and then enter without waiting for redraws. Then I wait maybe 15 seconds for game game to catch up. This key sequence goes to exit and confirms it.
Comment 1 supercoolemail 2019-02-04 16:41:19 UTC
Suprisingly, enabling GALLIUM_HUD="GPU-load;fps;cpu" workarounds this too and lowers the delay to HUD update step.
Comment 2 supercoolemail 2019-02-04 16:46:37 UTC
(In reply to supercoolemail from comment #1)
> Suprisingly, enabling GALLIUM_HUD="GPU-load;fps;cpu" workarounds this too
> and lowers the delay to HUD update step.

Ok, it does not. The delay just varies for some reason and multple tests confirming HUD influence were just product of random chance.
Comment 3 supercoolemail 2019-02-04 16:50:43 UTC
This led me to another round of testing with LIGL_ALWAYS_SOFTWARE=0. Not so surprisingly, this is also product of random chance, so this is after all probably Wine bug.
Comment 4 supercoolemail 2019-04-27 09:20:59 UTC
Sigh, this is actually real problem. Maybe now it's different problem but behavior is exactly the same. 
With LIBGL_ALWAYS_SOFTWARE=1 redrawing is instant, otherwise moving to different items of same menu takes 5-6 seconds and going to different menu takes even longer.

Might be related: performance in game is very bad. I get 3-4 FPS with LIBGL_ALWAYS_SOFTWARE=1 in one place and only 8 FPS without. However, when I pin game to single core, then I get 1 FPS without LIBGL_ALWAYS_SOFTWARE=1 but it won't even past loadscreen with it.
This is not only game that suffers from low FPS due to "fake" CPU bottleneck. The other is Sacred, which also happens to use Direct3D/DDraw, runs better with LIBGL_ALWAYS_SOFTWARE=1 than without. Without it, I get around 5 FPS in one city and 100 % one core usage, with it it is at least playable (Gallium HUD does not work with LIBGL_ALWAYS_SOFTWARE=1, so I don't know numbers).

Hardware: Ryzen 7 1700, RX 580
Comment 5 supercoolemail 2019-04-27 09:35:05 UTC
Created attachment 144101 [details]
Latest trace of Gothic 2 menu

New trace with latest everything showing more menus.
Comment 6 andrew.m.mcmahon 2019-04-29 14:04:50 UTC
I can't replicate any performance issues with Gothic 2 Gold on my setup.

I'm using the latest installer provided by GOG:
> setup_gothic_2_gold_2.7_(14553).exe
I'm installing the game into a clean wine 4.7-devel prefix by using:
> WINEPREFIX=~/.wineprefix/gothic2 wine setup_gothic_2_gold_2.7_(14553).exe
The game will crash at the main menu without directmusic. 
Latest winetricks (github) can handle that:
> WINEPREFIX=~/.wineprefix/gothic2 winetricks directmusic
Then I'm just running the game normally via the desktop shortcut that's automatically created.

I've recorded a video with SimpleScreenRecorder of the game running @ 1440x900 in wine's virtual desktop. I've got MESA_HUD enabled so you can see my framerate and other info:
https://drive.google.com/file/d/11t2akNusJh0hvaNEftV_oLbLd9lnozYX/view?usp=sharing

Phenom II x4 955
Debian Testing
OpenGL renderer string: AMD Radeon R9 200 Series (TONGA, DRM 3.30.0, 5.1.0-rc7-mainline-amd64, LLVM 8.0.0)
OpenGL core profile version string: 4.5 (Core Profile) Mesa 19.1.0-devel (git-812288bf0f)
Wine-devel 4.7
Comment 7 Timothy Arceri 2019-05-03 04:28:15 UTC
The trace runs perfectly fast. What is the most recent version you have tested this with? If you are still using 18.2 I would recommend updating to at least 19.0.
Comment 8 Michel Dänzer 2019-05-03 07:31:46 UTC
(In reply to andrew.m.mcmahon from comment #6)
> I can't replicate any performance issues with Gothic 2 Gold on my setup.
> 
> [...]
> 
> I've recorded a video with SimpleScreenRecorder of the game running @
> 1440x900 in wine's virtual desktop. I've got MESA_HUD enabled so you can see
> my framerate and other info:

The video shows very low frame-rate and GPU load in the menu, but high CPU load. Maybe there's a CPU bottleneck which affects the reporter even more badly. A CPU profile from sysprof or perf might give a clue.
Comment 9 supercoolemail 2019-05-03 16:17:27 UTC
I am on 19.0.3.
The game used to run quite well from what I remeber and I could navigate the menu. Now it's horrible and when I want to change something in menu, I need LIBGL_ALWAYS_SOFTWARE=1, otherwise I might not even live long enough to change it :-)

Output of perf (if you want anything more, e.g. full perf.data or something, I'll deliver):

perf report --stdio
    32.26%  Gothic2.exe      wined3d.dll.so            [.] wined3d_resource_map
    20.34%  Gothic2.exe      radeonsi_dri.so           [.] 0x000000000053c222
     4.05%  Gothic2.exe      wined3d.dll.so            [.] 0x000000000008c809
     3.95%  Gothic2.exe      radeonsi_dri.so           [.] 0x000000000053c227
     3.67%  Gothic2.exe      ntdll.dll.so              [.] RtlAllocateHeap
     2.41%  Gothic2.exe      perf-24471.map            [.] 0x0000000001426faa
     2.02%  Gothic2.exe      radeonsi_dri.so           [.] 0x000000000053c224
     1.20%  Gothic2.exe      ntdll.dll.so              [.] 0x0000000000088207
     1.19%  Gothic2.exe      radeonsi_dri.so           [.] 0x000000000053bf2a
     1.17%  Gothic2.exe      ntdll.dll.so              [.] 0x0000000000088373
     0.92%  Gothic2.exe      wined3d.dll.so            [.] 0x000000000008b282


perf report --stdio --sort comm,dso
    40.56%  Gothic2.exe      wined3d.dll.so          
    30.73%  Gothic2.exe      radeonsi_dri.so         
    11.74%  Gothic2.exe      ntdll.dll.so            
     8.61%  Gothic2.exe      perf-24471.map          
     3.65%  Gothic2.exe      Gothic2.exe             
     1.59%  Gothic2.exe      dsound.dll.so           
     0.71%  Gothic2.exe      libGLX_mesa.so.0.0.0
Comment 10 Michel Dänzer 2019-05-03 16:32:24 UTC
(In reply to supercoolemail from comment #9)
> Output of perf (if you want anything more, e.g. full perf.data or something,
> I'll deliver):

AFAIK perf.data generally won't be useful outside of your system.


> perf report --stdio
>     32.26%  Gothic2.exe      wined3d.dll.so            [.]
> wined3d_resource_map
>     20.34%  Gothic2.exe      radeonsi_dri.so           [.] 0x000000000053c222

Can you redo this with debugging symbols available for radeonsi_dri.so?

BTW, just to be clear, make sure you only collect profiling data while the game is showing the slow menu, not before or after.
Comment 11 supercoolemail 2019-05-03 17:06:34 UTC
Ok, so I started the game and attached perf to it by PID, waited a minute and stopped perf with CTRL+C. Here it is:

perf report --stdio
    45.80%  Gothic2.exe     wined3d.dll.so          [.] wined3d_resource_map
    42.80%  Gothic2.exe     radeonsi_dri.so         [.] _mesa_unpack_depth_span
     4.82%  Gothic2.exe     wined3d.dll.so          [.] 0x000000000008c809
     0.94%  Gothic2.exe     wined3d.dll.so          [.] 0x00000000000f4a93

perf report --stdio --sort comm,dso
    55.15%  Gothic2.exe     wined3d.dll.so        
    42.91%  Gothic2.exe     radeonsi_dri.so       
     0.93%  Gothic2.exe     dsound.dll.so
Comment 12 andrew.m.mcmahon 2019-05-03 22:10:48 UTC
(In reply to Michel Dänzer from comment #8)
> The video shows very low frame-rate and GPU load in the menu, but high CPU
> load. Maybe there's a CPU bottleneck which affects the reporter even more
> badly. A CPU profile from sysprof or perf might give a clue.
The heavy CPU usage in that particular video is entirely down to SimpleScreenRecorder. When I'm running the game and NOT recording the screen at the same time, CPU usage is around 30-50%:
https://imgur.com/a/AlhVLZp

That doesn't seem abnormal; the Phenom II is ancient plus it's going through Wine. I also assume that the main menu ~10 fps cap is a quirk of the game but perhaps I'm wrong?
https://pcgamingwiki.com/wiki/Gothic_II#Low_frame_rate_in_fullscreen_mode

I've compiled Mesa (git-8987152ac1) inside an amd64 & i386 chroot (debootstrap) 
Adding --buildtype=debug into my usual script:
https://pastebin.com/6uP6d7kL

I've done two recordings with sysprof:
- A 1 minute recording starting once the game reaches the main menu
- A 5 minute recording starting the game, running around in the starting area and then exiting the game

Hopefully those files are of use:
https://drive.google.com/file/d/16s2OfDKIAhbnqrs8gwWicmP7RaJw28L-/view?usp=sharing

Just out of interest there's an unofficial D3D11 renderer plus an unfinished open source remake - love to see the latter finished:
https://github.com/ataulien/GD3D11
https://github.com/REGoth-project/REGoth
Comment 13 supercoolemail 2019-05-03 23:50:25 UTC
You are lucky. I have this:
https://imgur.com/a/YTDyAXv
Notice, that this is with vastly limited object rendering distance, which makes fights rather difficult - I can't even see who is shooting at me with a bow. And there are places like forests that cause massive FPS drops. With higher object rendering distance I get around 15 FPS, but dropping below that in city and farms.

Then there is that problem with software rendering giving better performance than RX 580. That does not seem right to me (and is main reason why I report this here and not to wine).

And that I have to wait 5 seconds after each menu action to see what is highlighted or shown. It takes even more time in more complex menus, such as keybiding. And this is workaroundable by LIBGL_ALWAYS_SOFTWARE=1.
Comment 14 andrew.m.mcmahon 2019-05-04 11:07:49 UTC
(In reply to supercoolemail from comment #13)
> You are lucky. I have this:
> https://imgur.com/a/YTDyAXv
Yes that is horrible :(
Your Ryzen + RX580 should blow my old Phenom II + R9 285 out of the water.

The only way I'm able to intentionally destroy the performance of Gothic 2 is to do the following:
export LIBGL_ALWAYS_SOFTWARE=1
export GALLIUM_DRIVER=llvmpipe
WINEDEBUG=+fps  WINEPREFIX=~/.wineprefix/gothic2gold/ wine ~/.wineprefix/gothic2gold/drive_c/Gothic2Gold/system/Gothic2.exe 
https://imgur.com/a/rldthLI

Or I can use softpipe which is even worse plus I get the laggy main menu:
https://imgur.com/a/JwCnegN

I'm sure you've already enabled 32 bit support in your distro:
https://wiki.debian.org/Multiarch/HOWTO
https://wiki.archlinux.org/index.php/Official_repositories#Enabling_multilib

And installed all x64 and x86 Mesa related packages and firmware i.e:
https://www.archlinux.org/packages/multilib/x86_64/lib32-mesa/
https://packages.debian.org/buster/firmware-amd-graphics

Maybe you've exported some funny settings that you might have forgotten about? Here's my /etc/environment file:
https://pastebin.com/vqMfCTVm
Comment 15 supercoolemail 2019-05-05 20:20:13 UTC
(In reply to andrew.m.mcmahon from comment #14)

> Or I can use softpipe which is even worse plus I get the laggy main menu:
> https://imgur.com/a/JwCnegN
Well, menu with softpipe is waay slower than RX 580 (which is slower than llvmpipe - ~5 seconds per menu move vs. what feels instant; ~30 seconds with softpipe).

> I'm sure you've already enabled 32 bit support in your distro:
Yes, and other 32-bit games work ok (except Sacred; and Fallout new Vegas is not totally ok, but close enough, probably due to crappy engine).

> And installed all x64 and x86 Mesa related packages and firmware i.e:
Indeed. It should be good, because other 32-bit games work well (except Sacred).

> Maybe you've exported some funny settings that you might have forgotten
Checked and my /etc/environment contains just distro-provided comments (nothing else). I also don't have any relevant environment variables set (checked with "set" command). I don't set environment variables globally unless it's absolutely necessary, instead, I write scripts that set envvar using "env" and that's it.
Comment 16 Michel Dänzer 2019-05-06 08:47:27 UTC
(In reply to supercoolemail from comment #11)
>     42.80%  Gothic2.exe     radeonsi_dri.so         [.]
> _mesa_unpack_depth_span

It would be interesting to know where _mesa_unpack_depth_span is getting called from. Can you enable call graphs for the perf data gathering and reporting? (It might be easier to use sysprof and attach the profile data saved from that)
Comment 17 supercoolemail 2019-05-06 10:00:54 UTC
Created attachment 144173 [details]
sysprof of Gothic 2 menu
Comment 18 supercoolemail 2019-05-06 10:01:55 UTC
Created attachment 144174 [details]
sysprof of Gothic 2 menu with LIBGL_ALWAYS_SOFTWARE=1
Comment 19 Timothy Arceri 2019-05-07 01:35:54 UTC
I installed the game via Proton. Seems it is still very buggy in wine. I had to follow the instructions here [1] to get it to load without crashing or constantly changing the screen between windowed and fullscreen. Once I got it working the menu was working fine, no lag.

I'm suspecting you are either experiencing a wine bug or you have some bad settings somewhere rather than a Mesa bug.

[1] https://www.protondb.com/app/39510
Comment 20 supercoolemail 2019-05-07 08:37:32 UTC
(In reply to Timothy Arceri from comment #19)
> I installed the game via Proton. Seems it is still very buggy in wine. I had
> to follow the instructions here [1] to get it to load without crashing or
> constantly changing the screen between windowed and fullscreen. Once I got
> it working the menu was working fine, no lag.
SystemPack for Gothic fixes everything except crash with music enabled, for which native dmusic helps.
> I'm suspecting you are either experiencing a wine bug or you have some bad
> settings somewhere rather than a Mesa bug.
But how does LIBGL_ALWAYS_SOFTWARE=1 (with llvmpipe) help with laggy menu and why it sometimes give more FPS than radeonsi?

I don't have any relevant environment variables set, and only X configuration I have is

Section "Device"
        Identifier "AMDgpu"
        Driver "amdgpu"
        Option "VariableRefresh" "true"
EndSection

but laggy menu was there before VRR support arrived.
Comment 21 GitLab Migration User 2019-09-25 18:31:06 UTC
-- GitLab Migration Automatic Message --

This bug has been migrated to freedesktop.org's GitLab instance and has been closed from further activity.

You can subscribe and participate further through the new bug through this link to our GitLab instance: https://gitlab.freedesktop.org/mesa/mesa/issues/1342.

Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.