[Windows] WASAPI Backend freezes PPSSPP on Startup for some seconds

[julianxhokaxhiu]

HI,

I've found this issue, I hope the details are enough for you, but feel free to let me know if more are required.

Thank you in advance!

What happens?

When you open PPSSPP on Windows with the WASAPI Audio Backend, it freezes for some seconds ( sometimes 5, sometimes 10 or sometimes just a couple ) just after the initial credits and before the main menu when you can pick the game you want to play.

If you set DSound, PPSSPP starts normally without a freeze.

What should happen?

PPSSPP should open fine and continue to the main menu without a freeze effect.

What hardware, operating system, and PPSSPP version? On desktop, GPU matters for graphical issues.

Windows 10 x64 2004 build PPSSPP v1.10.3-747-gb78bb3d92

Attached Logs

40:58:550 core\config.cpp:1417 I[LOADER]: Config saved (got storage permission): '[REDACTED]\ppsspp_win\memstick/PSP/SYSTEM/ppsspp.ini'
40:58:552 core\config.cpp:1430 I[LOADER]: Controller config saved: [REDACTED]\ppsspp_win\memstick/PSP/SYSTEM/controls.ini
40:58:554 vulkan\vulkanloader.cpp:479 I[G3D]: VulkanLoad: Base functions loaded.
40:58:647 vulkan\vulkanloader.cpp:552 I[G3D]: Vulkan instance functions loaded.
40:58:648 vulkan\vulkancontext.cpp:512 I[G3D]: Chose physical device 0: 000001F5C7945910
40:58:648 vulkan\vulkancontext.cpp:548 I[G3D]: Memory Types (12):
40:58:648 vulkan\vulkancontext.cpp:557 I[G3D]:   7: Heap 0; Flags: DEVICE_LOCAL   
40:58:648 vulkan\vulkancontext.cpp:557 I[G3D]:   8: Heap 0; Flags: DEVICE_LOCAL   
40:58:648 vulkan\vulkancontext.cpp:557 I[G3D]:   9: Heap 1; Flags: HOST_VISIBLE HOST_COHERENT   
40:58:648 vulkan\vulkancontext.cpp:557 I[G3D]:   10: Heap 1; Flags: HOST_VISIBLE HOST_CACHED HOST_COHERENT   
40:58:648 vulkan\vulkancontext.cpp:557 I[G3D]:   11: Heap 2; Flags: DEVICE_LOCAL HOST_VISIBLE HOST_COHERENT   
40:58:722 vulkan\vulkanloader.cpp:559 I[G3D]: Vulkan device functions loaded.
40:58:722 vulkan\vulkanloader.cpp:575 I[G3D]: Missing (device): vkGetPhysicalDeviceSparseImageFormatProperties
40:58:722 vulkan\vulkancontext.cpp:669 I[G3D]: Device created.

40:58:722 vulkan\vulkancontext.cpp:720 I[G3D]: Creating Vulkan surface for window (00007FF771450000 00000000000406A6)
40:58:724 vulkan\vulkancontext.cpp:888 I[G3D]: swapchain_format: 44 (/3)
40:58:724 vulkan\vulkancontext.cpp:936 I[G3D]: surfCapabilities_.current: 1234x769 min: 1234x769 max: 1234x769 computed: 1234x769
40:58:724 vulkan\vulkancontext.cpp:948 I[G3D]: Supported present modes: FIFO, FIFO_RELAXED, MAILBOX, IMMEDIATE
40:58:724 vulkan\vulkancontext.cpp:982 I[G3D]: Chosen present mode: 2 (FIFO). numSwapChainImages: 3/8
40:58:724 vulkan\vulkancontext.cpp:1024 I[G3D]: Transform supported: IDENTITY  current: IDENTITY  chosen: IDENTITY 
40:58:733 vulkan\vulkancontext.cpp:1075 I[G3D]: Created swapchain: 1234x769
40:58:733 thin3d\vulkanqueuerunner.cpp:12 I[G3D]: VulkanQueueRunner::CreateDeviceObjects
40:58:840 thin3d\vulkanrendermanager.cpp:282 I[G3D]: Starting Vulkan submission thread (threadInitFrame_ = 0)
40:58:840 ui\nativeapp.cpp:818 I[SYSTEM]: NativeInitGraphics
40:58:848 ui\nativeapp.cpp:887 I[SYSTEM]: NativeInitGraphics completed
40:58:848 ui\nativeapp.cpp:1370 I[G3D]: NativeResized - setting flag
40:58:848 windows\emuthread.cpp:232 I[BOOT]: Done.
40:58:890 ui\nativeapp.cpp:1096 I[G3D]: Resized flag set - recalculating bounds
40:58:890 thin3d\vulkanrendermanager.cpp:412 I[G3D]: Running first frame (0)
40:58:991 thin3d\vulkanrendermanager.cpp:305 I[G3D]: Vulkan submission thread joined. Frame=1
40:59:007 vulkan\vulkancontext.cpp:936 I[G3D]: surfCapabilities_.current: 1234x769 min: 1234x769 max: 1234x769 computed: 1234x769
40:59:007 vulkan\vulkancontext.cpp:948 I[G3D]: Supported present modes: FIFO, FIFO_RELAXED, MAILBOX, IMMEDIATE
40:59:007 vulkan\vulkancontext.cpp:982 I[G3D]: Chosen present mode: 2 (FIFO). numSwapChainImages: 3/8
40:59:007 vulkan\vulkancontext.cpp:1024 I[G3D]: Transform supported: IDENTITY  current: IDENTITY  chosen: IDENTITY 
40:59:008 vulkan\vulkancontext.cpp:1075 I[G3D]: Created swapchain: 1234x769
40:59:009 thin3d\vulkanrendermanager.cpp:270 I[G3D]: Updating inflight frames to 2
40:59:009 thin3d\vulkanrendermanager.cpp:282 I[G3D]: Starting Vulkan submission thread (threadInitFrame_ = 1)
40:59:009 ui\screen.cpp:132 I[SYSTEM]: ScreenManager::resized(dp: 1234x769)
40:59:009 thin3d\vulkanrendermanager.cpp:412 I[G3D]: Running first frame (1)
40:59:180 core\config.cpp:1417 I[LOADER]: Config saved (clearFailedGPUBackends): '[REDACTED]\ppsspp_win\memstick/PSP/SYSTEM/ppsspp.ini'
40:59:181 core\config.cpp:1430 I[LOADER]: Controller config saved: [REDACTED]\ppsspp_win\memstick/PSP/SYSTEM/controls.ini
40:59:620 windows\wasapistream.cpp:135 I[SCEAUDIO]: Changed audio device property {1f7d339a-5380-41a5-ad81-e7b6a9a0a802}#1
40:59:620 windows\wasapistream.cpp:135 I[SCEAUDIO]: Changed audio device property {1f7d339a-5380-41a5-ad81-e7b6a9a0a802}#2
40:59:621 windows\wasapistream.cpp:135 I[SCEAUDIO]: Changed audio device property {1f7d339a-5380-41a5-ad81-e7b6a9a0a802}#7
40:59:844 windows\wasapistream.cpp:135 I[SCEAUDIO]: Changed audio device property {1f7d339a-5380-41a5-ad81-e7b6a9a0a802}#1
40:59:845 windows\wasapistream.cpp:135 I[SCEAUDIO]: Changed audio device property {1f7d339a-5380-41a5-ad81-e7b6a9a0a802}#2
40:59:846 windows\wasapistream.cpp:135 I[SCEAUDIO]: Changed audio device property {1f7d339a-5380-41a5-ad81-e7b6a9a0a802}#7
41:25:702 core\config.cpp:1417 I[LOADER]: Config saved (MainScreen::OnExit): '[REDACTED]\ppsspp_win\memstick/PSP/SYSTEM/ppsspp.ini'
41:25:704 core\config.cpp:1430 I[LOADER]: Controller config saved: [REDACTED]\ppsspp_win\memstick/PSP/SYSTEM/controls.ini
41:25:705 ui\nativeapp.cpp:937 I[SYSTEM]: NativeShutdownGraphics
41:25:741 ui\nativeapp.cpp:979 I[SYSTEM]: NativeShutdownGraphics done
41:25:741 thin3d\vulkanrendermanager.cpp:305 I[G3D]: Vulkan submission thread joined. Frame=1
41:25:749 thin3d\vulkanrendermanager.cpp:360 I[G3D]: VulkanRenderManager destructor
41:25:749 thin3d\vulkanrendermanager.cpp:335 I[G3D]: Vulkan submission thread was already stopped.
41:25:749 thin3d\vulkanqueuerunner.cpp:91 I[G3D]: VulkanQueueRunner::DestroyDeviceObjects
41:25:772 vulkan\vulkancontext.cpp:1102 I[G3D]: VulkanContext::DestroyDevice (performing deletes)
41:25:815 core\config.cpp:1417 I[LOADER]: Config saved (NativeShutdown): '[REDACTED]\ppsspp_win\memstick/PSP/SYSTEM/ppsspp.ini'
41:25:816 core\config.cpp:1430 I[LOADER]: Controller config saved: [REDACTED]\ppsspp_win\memstick/PSP/SYSTEM/controls.ini

[unknownbrackets]

What audio device do you have? Does it change if you switch your primary audio output device?

This doesn't happen to me when using a DualShock 4 controller for audio output, or when using audio through HDMI/DisplayPort with NVIDIA.

-[Unknown]

[julianxhokaxhiu]

Thanks for the reply. This issue at the moment happens with a Realtek Audio card.

Those are my current settings:

I'll try to switch the audio to the Bluetooth headphones and I'll let you know how it goes, as I don't have any other sound card to try out.

//EDIT: Did some tests and it seems to freeze anyway, despite the default audio device being switched. I also did try to switch the default input device, still nothing new. I also noticed that also doesn't matter which is my default audio device on Windows, PPSSPP will always pick my Microphone input from the Realtek Audio card. Could it be that one is the one introducing the lag? Is there a way to disable microphone usage entirely?

[unknownbrackets]

Does the problem happen also on v1.9.3?

https://www.ppsspp.org/files/1_9_3/ppsspp_win.zip

This would be before microphone support was added. The microphone doesn't use WASAPI, it uses Media Foundation, so I don't think it's related - I just want to confirm.

Do you have the latest Realtek drivers and Bluetooth drivers installed?

-[Unknown]

[julianxhokaxhiu]

Does the problem happen also on v1.9.3?

https://www.ppsspp.org/files/1_9_3/ppsspp_win.zip

This would be before microphone support was added. The microphone doesn't use WASAPI, it uses Media Foundation, so I don't think it's related - I just want to confirm.

This version also has the same freeze behavior unfortunately, so you're right, the microphone input has nothing to do. It really seems to be something on the WASAPI backend.

Do you have the latest Realtek drivers and Bluetooth drivers installed?

Yes. Realtek: 6.0.9003.1 Bluetooth: 1.8.1030.3000 ( Realtek chipset )

[unknownbrackets]

Hmm - strange.

Go to Start -> type "Device Manager" (without quotes) and then select Device Manager. From there, expand "Sound, video and game controllers". Look for Realtek(R) Audio, and right click it.

In that menu, select "Disable device" (don't worry, you can re-enable it just as easily.) Say OK when it asks if you really want to disable the device. Does the issue still happen?

Afterward, don't forget to re-enable the device (just right click it again.) You should see a Realtek Bluetooth Adapter under Bluetooth, and you can try the same with it.

WASAPI is actually initialized on a separate thread though. I'm not sure why it would block unless the driver was locking up the process for some reason...

-[Unknown]

[julianxhokaxhiu]

Thanks for the continuous support. I did try to disable the Audio device first ( and only ), then I did try to run PPSSPP ( same git version at the beginning of this issue ) and guess what? PPSSPP starts normally. No hang up.

Next, with my main audio device still disabled, I attached my Bluetooth headphones and started PPSSPP. As usual, it hangs up on startup. But if I turn them off and I don't pair any audio device, and I leave my Bluetooth device enabled and turned on ( basically nothing attached to it but the chipset is not disabled ), PPSSPP starts just fine.

It seems that the WASAPI backend is trying to accomplish something as soon as it crosses an audio playback device.

Please note that the freeze I'm talking about is not in the process. I can click the upper window menus while "it's frozen", it's just basically loading the credits and once they fade away, before the main menu appears, it's stays there for 15-30s then it continues as always. My theory is that although you spawn the WASAPI backend on another thread, you're waiting for some reply from it, and this doesn't come until the WASAPI accomplishes something. That something should be the hinch to this issue.

If there's a way to get more debug logging that I've already provided feel free to let me know. Thank you in advance.

[unknownbrackets]

Well, the way the WASAPI backend works should prevent that.

WASAPI runs on a thread, and does everything within that thread:

• Any and all initialization.
• Checks if you switched audio devices.
• Sends sound data to the driver for playback.
• Waits for new data.

Its only interaction with other threads is that it calls a function pointer to ask the UI/emulation for sound data (Win32Mix() in UI/NativeApp.cpp.) If there's not enough data, this callback should return blank data (and "underrun".) This callback runs on the WASAPI thread also, but could lock a mutex and block other threads (which would match what you describe with the Windows menu still working) in BackgroundAudio::Play().

We can validate if that mutex is the issue. After starting PPSSPP, uncheck "Enable Sound" under Game Settings, and then restart it. Does this avoid the hang? Is there a hang when you first check "Enable Sound" afterward, if so?

If the hang goes away, then at least we've eliminated anything about WASAPI initialization or device change checks - that will still happen. But that'd be strange since we shouldn't have any background audio to play until you highlight a game.

-[Unknown]

[julianxhokaxhiu]

Thanks for describing the scenario. I did test also the scenario of `Enable Sound unchecked and yes, as you said, PPSSPP starts just fine, no hang there.

So there must be something done when that option is on, most probably the part of "sending audio and waiting for some reply back". Could this may be done in another thread in order to not lock the one starting the menu? I'd rather prefer to wait while loading a game for Audio to be available, rather than when opening the emulator.

Thank you in advance and I hope you'll find your way out of this :)

[unknownbrackets]

I've made a change that might improve this, although I'm still at a loss for an explanation of what could cause a hang.

This change should prevent any locking during basic start, similar to the situation when "enable sound" is off. However, if you enable UI sounds (in system) or hover over a game, it will still necessarily need to lock when playing those things (the lock is just to add these to the "queue" of things to play.) It'd be very interesting if this delays the hang until that audio plays, or prevents it entirely.

I still can't reproduce any hang, so it's equally possible it won't help at all.

From #14152, if you go to the Checks tab you can download a Windows build and try it (under Artifacts.) If it shows as merged, you can just get the latest git build too.

Whether that helps or not, it'd be useful to know how many CPU cores you have (or if you're on a laptop in a power saving mode.)

-[Unknown]

[julianxhokaxhiu]

Hi,

Thank you very much for still taking care of this issue. The power plan on my own laptop is set to "maximum performance", and I'm attached to the power plug ( so running in AC mode ).

Said that, this is my report on top of this build "v1.11.2-85-g19bd943ad": 1) When Audio Setting is ON, on three cold launches, one is always freezing ( open, wait until the main menu shows, close, repeat ). This is the related log when the freeze happens: ppsspplog-audio-on-with-freeze.txt 2) When Audio Setting is OFF, on three cold launches, one is always freezing as well ( open, wait until the main menu shows, close, repeat ). This is the related log when the freeze happens: ppsspplog-audio-off-with-freeze.txt

So, regarding the patch it seems sometimes it avoids it and sometimes not. I have no idea what it could be causing that but I'll be happy to report and provide more logs if needed.

Thank you in advance and best regards.

[unknownbrackets]

Hm, okay. That it reduced the incidence from "always" to 33% means threading is likely related.

None of those locks happen on startup anymore for background audio, and it no longer seems to depend on the audio setting. I wonder if it was one in three before, and now just this aspect of it is fixed.

I suppose this might be from WASAPI creating another thread and contention from limited thread resources...

-[Unknown]

[julianxhokaxhiu]

Feel free to ping me anytime, if there's a need to test again :) Thanks for attempting to fix this, is really appreciated.

It's weird because this does not happen with any other emulator I use, only with PPSSPP.

[unknownbrackets]

There is another change merged which might help more. Bit of a long shot, but it removes more locks during startup in other places.

-[Unknown]

[julianxhokaxhiu]

Tested "v1.11.2-107-gbe0adc29f Windows 64bit", first cold run with audio ON and it hangs as always on startup: ppsspplog.txt

Unfortunately the PR didn't fix it...yet, but never give up! :)