search

gonetz / GLideN64

A new generation, open-source graphics plugin for N64 emulators.
Other
773 stars 180 forks source link

Certain games start off slow but then become fullspeed #2649

Open quicksilver7837 opened 2 years ago

quicksilver7837 commented 2 years ago

Testing on my raspberry pi 4 I noticed that certain games (Killer instinct, Excite bike, New tetris, quake 2 to list a few) all have really bad stuttering when you first start the game. After about 10-20 seconds of playing, the games smooth out and will run fullspeed for the rest of the play session. If the game is closed and then restarted the initial stuttering returns.

My limited understanding is that the stuttering is caused by something to do with the shader cache (pardon my ignorance). However, I thought that once the shaders were generated that they would be stored for subsequent play sessions and loaded when the game was launched? Is it normal for the game to stutter each time you start the game?

dankcushions commented 2 years ago

i believe the RPI’s version of gles doesn’t support shader storage (glProgramBinary?), however i think a fallback was implemented involving combiner keys that should work. I wonder if it’s working correctly? can you try a verbose log (have a look in mupen64plus.cfg for log settings IIRC)?

quicksilver7837 commented 2 years ago

I dont see anything about verbose logging in the mupen64plus.cfg. Here is a standard log though it doesnt look very informative.

Parameters: 
Executing: /opt/retropie/emulators/mupen64plus/bin/mupen64plus.sh mupen64plus-video-GLideN64 "/home/pi/RetroPie/roms/n64/Excitebike 64 (USA).z64" 1920x1080 0 --set Video-GLideN64[UseNativeResolutionFactor]\=1
 __  __                         __   _  _   ____  _             
|  \/  |_   _ _ __   ___ _ __  / /_ | || | |  _ \| |_   _ ___ 
| |\/| | | | | '_ \ / _ \ '_ \| '_ \| || |_| |_) | | | | / __|  
| |  | | |_| | |_) |  __/ | | | (_) |__   _|  __/| | |_| \__ \  
|_|  |_|\__,_| .__/ \___|_| |_|\___/   |_| |_|   |_|\__,_|___/  
             |_|         https://mupen64plus.org/               
Mupen64Plus Console User-Interface Version 2.5.9

UI-Console: attached to core library 'Mupen64Plus Core' version 2.5.9
UI-Console:             Includes support for Dynamic Recompiler.
Core: Using full mem base
Core: Goodname: Excitebike 64 (U) (V1.0) [!]
Core: Name: EXCITEBIKE64        
Core: MD5: 7200D1C1CF489FAFFF767729F215E6E6
Core: CRC: 07861842 A12EBC9F
Core: Imagetype: .z64 (native)
Core: Rom size: 16777216 bytes (or 16 Mb or 128 Megabits)
Core: Version: 1448
Core: Manufacturer: Nintendo
Core: Country: USA
UI-Console Status: Cheat codes disabled.
UI-Console: using Video plugin: 'GLideN64 rev.7417144' v2.0.0
UI-Console: using Audio plugin: 'Mupen64Plus SDL Audio Plugin' v2.5.9
Input: Using auto-config file at: '/opt/retropie/configs/n64/InputAutoCfg.ini'
UI-Console: using Input plugin: 'Mupen64Plus SDL Input Plugin' v2.5.9
UI-Console: using RSP plugin: 'Hacktarux/Azimer High-Level Emulation RSP Plugin' v2.5.9
Core: input plugin did not specify a render callback; there will be no on screen display by the input plugin.
Input: 1 SDL joysticks were found.
Input: Using auto-config file at: '/opt/retropie/configs/n64/InputAutoCfg.ini'
Input: N64 Controller #1: Using auto-config with SDL joystick 0 ('Xbox 360 Wireless Receiver (XBOX)')
Input: 1 controller(s) found, 1 plugged in and usable in the emulator
Input: Rumble activated on N64 joystick #1
Input Warning: Couldn't open rumble support for joystick #2
Input Warning: Couldn't open rumble support for joystick #3
Input Warning: Couldn't open rumble support for joystick #4
Input: Mupen64Plus SDL Input Plugin version 2.5.9 initialized.
RSP: RSP Fallback disabled !
Core: Using video capture backend: dummy
Core: Game controller 0 (Standard controller) has a Memory pak plugged in
Core: Game controller 1 (Standard controller) has a Memory pak plugged in
Core: Game controller 2 (Standard controller) has a Memory pak plugged in
Core: Game controller 3 (Standard controller) has a Memory pak plugged in
Core: Using CIC type X103
Core: Setting video mode: 1920x1080
Audio: Using resampler trivial
Audio: Initializing SDL audio subsystem...
Input: Rumble activated on N64 joystick #1
Input Warning: Couldn't open rumble support for joystick #2
Input Warning: Couldn't open rumble support for joystick #3
Input Warning: Couldn't open rumble support for joystick #4
Core: Initializing 4 RDRAM modules for a total of 8 MB
Core: Starting R4300 emulator: Dynamic Recompiler
Core: Init new dynarec
Core: ARM CPU Features:, Half, Thumb, FastMult, VFP, ESDP, NEON, VFPv3, TLS, VFPv4, IDIVa, IDIVt
Audio: Initializing SDL audio subsystem...
Core Status: Stopping emulation.
Core: R4300 emulator finished.
Core Status: Rom closed.

Gliden64 log file of the last two days:

2022/02/07,00:09:39.810,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,00:09:39.811,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,00:30:02.010,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,00:30:02.011,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,12:26:31.023,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,12:26:31.026,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,12:27:31.476,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,12:27:31.476,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,12:33:04.121,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,12:33:04.122,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,12:33:45.643,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,12:33:45.643,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,12:35:19.482,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,12:35:19.482,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,12:50:25.361,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,12:50:25.361,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,12:52:18.893,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,12:52:18.893,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,13:58:04.371,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,13:58:04.371,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,13:58:08.889,Textures.cpp:1163,ERROR, "AERO FIGHTERS ASSAUL wrong texture size. width: 256, height: 128, size: 2, bytes: 65536"
2022/02/07,13:58:08.889,Textures.cpp:1163,ERROR, "AERO FIGHTERS ASSAUL wrong texture size. width: 200, height: 128, size: 2, bytes: 51200"
2022/02/07,13:58:17.100,Textures.cpp:1163,ERROR, "AERO FIGHTERS ASSAUL wrong texture size. width: 328, height: 128, size: 1, bytes: 41984"
2022/02/07,13:58:17.100,Textures.cpp:1163,ERROR, "AERO FIGHTERS ASSAUL wrong texture size. width: 288, height: 128, size: 1, bytes: 36864"
2022/02/07,13:58:17.100,Textures.cpp:1163,ERROR, "AERO FIGHTERS ASSAUL wrong texture size. width: 328, height: 128, size: 1, bytes: 41984"
2022/02/07,13:58:46.043,Textures.cpp:1163,ERROR, "AERO FIGHTERS ASSAUL wrong texture size. width: 200, height: 128, size: 2, bytes: 51200"
2022/02/07,13:58:50.791,Textures.cpp:1163,ERROR, "AERO FIGHTERS ASSAUL wrong texture size. width: 288, height: 128, size: 1, bytes: 36864"
2022/02/07,13:58:50.796,Textures.cpp:1163,ERROR, "AERO FIGHTERS ASSAUL wrong texture size. width: 400, height: 128, size: 1, bytes: 51200"
2022/02/07,13:58:56.938,Textures.cpp:1163,ERROR, "AERO FIGHTERS ASSAUL wrong texture size. width: 120, height: 128, size: 1, bytes: 15360"
2022/02/07,13:59:00.370,Textures.cpp:1163,ERROR, "AERO FIGHTERS ASSAUL wrong texture size. width: 80, height: 128, size: 0, bytes: 5120"
2022/02/07,13:59:28.744,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,13:59:28.744,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,13:59:33.852,Textures.cpp:1163,ERROR, "AERO FIGHTERS ASSAUL wrong texture size. width: 256, height: 128, size: 2, bytes: 65536"
2022/02/07,13:59:33.862,Textures.cpp:1163,ERROR, "AERO FIGHTERS ASSAUL wrong texture size. width: 200, height: 128, size: 2, bytes: 51200"
2022/02/07,13:59:41.118,Textures.cpp:1163,ERROR, "AERO FIGHTERS ASSAUL wrong texture size. width: 328, height: 128, size: 1, bytes: 41984"
2022/02/07,13:59:41.118,Textures.cpp:1163,ERROR, "AERO FIGHTERS ASSAUL wrong texture size. width: 288, height: 128, size: 1, bytes: 36864"
2022/02/07,13:59:41.118,Textures.cpp:1163,ERROR, "AERO FIGHTERS ASSAUL wrong texture size. width: 328, height: 128, size: 1, bytes: 41984"
2022/02/07,13:59:42.548,Textures.cpp:1163,ERROR, "AERO FIGHTERS ASSAUL wrong texture size. width: 120, height: 128, size: 1, bytes: 15360"
2022/02/07,13:59:42.548,Textures.cpp:1163,ERROR, "AERO FIGHTERS ASSAUL wrong texture size. width: 80, height: 128, size: 0, bytes: 5120"
2022/02/07,14:08:32.231,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,14:08:32.231,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,14:08:37.144,Textures.cpp:1163,ERROR, "AERO FIGHTERS ASSAUL wrong texture size. width: 256, height: 128, size: 2, bytes: 65536"
2022/02/07,14:08:37.155,Textures.cpp:1163,ERROR, "AERO FIGHTERS ASSAUL wrong texture size. width: 200, height: 128, size: 2, bytes: 51200"
2022/02/07,14:08:45.146,Textures.cpp:1163,ERROR, "AERO FIGHTERS ASSAUL wrong texture size. width: 328, height: 128, size: 1, bytes: 41984"
2022/02/07,14:08:45.146,Textures.cpp:1163,ERROR, "AERO FIGHTERS ASSAUL wrong texture size. width: 288, height: 128, size: 1, bytes: 36864"
2022/02/07,14:08:45.147,Textures.cpp:1163,ERROR, "AERO FIGHTERS ASSAUL wrong texture size. width: 328, height: 128, size: 1, bytes: 41984"
2022/02/07,14:17:28.511,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,14:17:28.511,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,14:24:43.084,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,14:24:43.084,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,14:35:04.911,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,14:35:04.912,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,18:42:07.481,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,18:42:07.482,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,18:52:33.195,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,18:52:33.195,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,22:35:31.601,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,22:35:31.602,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,22:38:04.631,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,22:38:04.632,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,22:41:42.162,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,22:41:42.163,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,22:42:35.223,Textures.cpp:1163,ERROR, "Battle for Naboo wrong texture size. width: 16, height: 1024, size: 0, bytes: 8192"
2022/02/07,22:42:35.689,Textures.cpp:1163,ERROR, "Battle for Naboo wrong texture size. width: 16, height: 1024, size: 0, bytes: 8192"
2022/02/07,22:42:36.689,Textures.cpp:1163,ERROR, "Battle for Naboo wrong texture size. width: 16, height: 1024, size: 0, bytes: 8192"
2022/02/07,22:42:36.855,Textures.cpp:1163,ERROR, "Battle for Naboo wrong texture size. width: 16, height: 1024, size: 0, bytes: 8192"
2022/02/07,22:42:36.857,Textures.cpp:1163,ERROR, "Battle for Naboo wrong texture size. width: 16, height: 1024, size: 0, bytes: 8192"
2022/02/07,22:42:51.556,Textures.cpp:1163,ERROR, "Battle for Naboo wrong texture size. width: 16, height: 1024, size: 0, bytes: 8192"
2022/02/07,22:42:51.557,Textures.cpp:1163,ERROR, "Battle for Naboo wrong texture size. width: 16, height: 1024, size: 0, bytes: 8192"
2022/02/07,22:43:08.323,Textures.cpp:1163,ERROR, "Battle for Naboo wrong texture size. width: 16, height: 1024, size: 0, bytes: 8192"
2022/02/07,22:43:08.390,Textures.cpp:1163,ERROR, "Battle for Naboo wrong texture size. width: 16, height: 1024, size: 0, bytes: 8192"
2022/02/07,22:43:08.391,Textures.cpp:1163,ERROR, "Battle for Naboo wrong texture size. width: 16, height: 1024, size: 0, bytes: 8192"
2022/02/07,22:50:17.325,Textures.cpp:1163,ERROR, "Battle for Naboo wrong texture size. width: 16, height: 1024, size: 0, bytes: 8192"
2022/02/07,22:50:17.332,Textures.cpp:1163,ERROR, "Battle for Naboo wrong texture size. width: 16, height: 1024, size: 0, bytes: 8192"
2022/02/07,22:50:22.001,Textures.cpp:1163,ERROR, "Battle for Naboo wrong texture size. width: 16, height: 1024, size: 0, bytes: 8192"
2022/02/07,22:50:22.595,Textures.cpp:1163,ERROR, "Battle for Naboo wrong texture size. width: 16, height: 1024, size: 0, bytes: 8192"
2022/02/07,22:50:23.595,Textures.cpp:1163,ERROR, "Battle for Naboo wrong texture size. width: 16, height: 1024, size: 0, bytes: 8192"
2022/02/07,22:50:23.611,Textures.cpp:1163,ERROR, "Battle for Naboo wrong texture size. width: 16, height: 1024, size: 0, bytes: 8192"
2022/02/07,22:50:23.612,Textures.cpp:1163,ERROR, "Battle for Naboo wrong texture size. width: 16, height: 1024, size: 0, bytes: 8192"
2022/02/07,22:50:36.844,Textures.cpp:1163,ERROR, "Battle for Naboo wrong texture size. width: 16, height: 1024, size: 0, bytes: 8192"
2022/02/07,22:52:42.109,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/07,22:52:42.109,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/08,13:29:09.534,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/08,13:29:09.534,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/08,14:47:35.552,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/08,14:47:35.552,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
quicksilver7837 commented 2 years ago

i believe the RPI’s version of gles doesn’t support shader storage (glProgramBinary?), however i think a fallback was implemented involving combiner keys that should work.

Isn't the pi 4 fully gles 3.1 compliant? Or does this function not fall under that?

dankcushions commented 2 years ago

you may have to rebuild/launch gliden64/mupen64plus with debug enabled to get the right logs, can't remember

quicksilver7837 commented 2 years ago

Ill have to give that a shot. Hopefully I can see what's going on "under the hood". After researching how shader storage works in gliden64 I'm fairly confident it's not functioning on my pi 4.

gonetz commented 2 years ago

i believe the RPI’s version of gles doesn’t support shader storage (glProgramBinary?), however i think a fallback was implemented involving combiner keys that should work.

True:

bool ShaderStorage::loadShadersStorage(graphics::Combiners & _combiners)
{
    if (!graphics::Context::ShaderProgramBinary)
        // Shaders storage is not supported, load from combiners keys.
        return _loadFromCombinerKeys(_combiners);

So, even if the hardware does not support save/restore shaders in binary form, shaders still can be built using information from .keys file. You still need to enable shader storage option for that. If you played a game once, on the next run you should see "LOAD COMBINER SHADERS .." message. If it does not appear, that means that .keys file is not found. It can be because emulator was not closed properly, since the plugin saves .keys on exit. Also, path to "shaders" folder can be not accessible for write. You may add a log message to ShaderStorage::_saveCombinerKeys to be sure that it was called, smth like this:

LOG(LOG_WARNING, "Enter _saveCombinerKeys ");
if (!keysOut) {
LOG(LOG_ERROR, "_saveCombinerKeys failed");
return false;
}
quicksilver7837 commented 2 years ago

So, even if the hardware does not support save/restore shaders in binary form, shaders still can be built using information from .keys file. You still need to enable shader storage option for that.

I can confirm shader storage is turned on. And key files do appear in the shader folder.

If you played a game once, on the next run you should see "LOAD COMBINER SHADERS .." message.

I tested several dozen random games (running them twice to be sure a shader key was generated). Only one of them flashed the message load combiner shaders. The rest just said init noise textures or something like that.

If it does not appear, that means that .keys file is not found. It can be because emulator was not closed properly, since the plugin saves .keys on exit. Also, path to "shaders" folder can be not accessible for write.

Since the key files do seem to appear in the shader folder I would assume this is not the case? Perhaps for some reason it's having a hard time reading them?

You may add a log message to ShaderStorage::_saveCombinerKeys to be sure that it was called, smth like this:

LOG(LOG_WARNING, "Enter _saveCombinerKeys ");
if (!keysOut) {
LOG(LOG_ERROR, "_saveCombinerKeys failed");
return false;
}

I'm not sure how to add the log message. Where exactly am I placing it?

quicksilver7837 commented 2 years ago

So I was wrong, the LOAD COMBINER SHADERS message is popping up for each game. Its just so fast I was missing it. So the question is then, why are certain games still getting shader stuttering on subsequent playthroughs?

For example ExciteBike starts off very choppy (monitoring with htop I can see ram usage increasing). About halfway through 1 lap of the race and the game becomes fullspeed (ram usage stops increasing). For the rest of that play session the game is fullspeed. If I quit and reload I have to go through all the initial stuttering again.

This only seems to happen with particular games. I know nothing about how shaders work but is it possible the game is creating infinitely unique shaders each time the game is run such that the shader key for the game changes each time the game is run?

gonetz commented 2 years ago

I'm not sure how to add the log message. Where exactly am I placing it?

Add this message to the source code. src\Graphics\OpenGLContext\GLSL\glsl_ShaderStorage.cpp Function ShaderStorage::_saveCombinerKeys Replace

if (!keysOut)
    return false;

by

LOG(LOG_WARNING, "Enter _saveCombinerKeys ");
if (!keysOut) {
LOG(LOG_ERROR, "_saveCombinerKeys failed");
return false;
}

So I was wrong, the LOAD COMBINER SHADERS message is popping up for each game. Its just so fast I was missing it.

This is strange. Any game uses dozens combiners, their compilation usually takes seconds, hard not to notice. You may also add log messages to ShaderStorage::_loadFromCombinerKeys Replace

    u32 szCombiners;
    fin >> std::hex >> szCombiners;

by

    u32 szCombiners;
    fin >> std::hex >> szCombiners;
    LOG(LOG_WARNING, "Load %d combiner shaders from keys", szCombiners);
quicksilver7837 commented 2 years ago

Here is the log after I made the changes:

2022/02/25,11:03:07.559,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/25,11:03:07.560,opengl_Utils.cpp:60,WARNING, "Could not query EGL extensions on this device"
2022/02/25,11:03:07.664,glsl_ShaderStorage.cpp:267,WARNING, "Load 20 combiner shaders from keys"

So based on that I would assume its loading the shaders from keys properly? So if its not the shaders causing issues could it be texture caching that is causing the temporary slow down? How does the texture cache work? I see that I have 

# Save texture cache to hard disk.
txSaveCache = True

However I never see any texture files in the cache directory (its always empty). Is the above setting designed so that textures are loaded from hard disk into the cache when the game is started the second time to avoid stuttering?