When testing our game on the PS4, we are noticing some poor performance issues, which can be pinpointed to our main thread halting and waiting for the FMOD update thread running in the background (entering critical sections).
Our own custom audio obstruction systems does a lot of FMOD_Studio_EventInstance_GetVolume and FMOD_Studio_EventInstance_SetVolume, and on each one of them, the main thread seems to have to wait for the FMOD update thread (see profiling data & callstack: Imgur: The magic of the Internet ). This does not only happen to these calls, but also to many other FMOD API calls unrelated to our audio obstruction system.
I’ve seen in this thread ( [Solved] Severe Performance Issue ) that it might have to do with the command queue being full. So I’ve checked that as well, but it seems that the command queue is never full, at least when I looked at the BufferUsage on a separate occasion (currentUsage not too high, stallcount and stalltime both 0) . Our command queue is already set pretty big at 4194304.
When looking into the profiling data, it’s obviously true that all our cores are pretty busy such that the FMOD thread doesn’t have a chance to update straight away after calling the GetVolume. However I would love to make it so that the main thread can run completely async from the FMOD update thread, even when calling FMOD functions.
We’re currently using Unity version 2019.4.10f1 with FMOD integration version 2.00.07. I’ve also tried upgrading FMOD to version 2.01.09, which didn’t seem to solve this problem.
Firstly, you should probably take down the Razor capture image as posting it will likely violate your PS4 NDA. We have a PS4 forum where you can post with images however you will need to have your account verified as a registered PS4 developer, see our permissions page.
If you could send us the Razor capture that would help identify what’s going on, you can upload the files on your profile page. I’m interesting in seeing exactly what is holding the other end of the async command lock and for how long.
Thanks for sending through the Razor capture, it looks like the stalls indicated are due to an Event Callback. When the Studio update thread executes a registered callback, we take the command queue lock to prevent conflicts with any FMOD calls made on your other threads. This is the same lock you’d encounter if you call FMOD APIs from two of your own threads to prevent any race conditions.
Any slow operations being executed in your Event callbacks will block API commands issued on other threads.
Thank you for your help, It’s greatly appreciated!
I’ve had a deep look again at the profiling data, where I include profiling tags for the complete duration of the event callbacks that we use in our game (that is via the FMOD_Studio_EventInstance_SetCallback call). I’ve uploaded the profiling data again to my profile page for your reference (see ‘ProfileData_FMODThreadWait_2’).
In a few occasions the Event callback did seem to halt the main thread, example at frame 262 @ t = 8.935 sec. But most of the time, there was no callback going on during the time where the main thread was stalled. Example of this at frame 232 @ t = 7.676 sec - 7.681 sec.
I do realize that in most of these cases the FMOD thread has very little CPU time to do its update, which is why that thread is idle much of the time during this main thread stall, but I’m at a loss to explain the Critical section if it isn’t for the event callbacks or the command queue buffer being full.
Are there possibly other reasons for this Critical section?
Maybe of interest, but this version of the FMOD library uses libfmodstudioL (debug lib?), while for release builds it would be using libfmodstudio, but I have no profiling data for that.
I can see at the point in question you are calling EventInstance::getVolume, retrieving the volume value is fine, however retrieving the finalVolume is taking a lock against the Core API update. The Core API update happens as part of the Studio update, on the Studio thread. This thread is being heavily starved of resources causing the wait time for the crit to be excessive.
I believe we can unblock that particular API call in a patch, are there any other APIs affecting you?
We do get these stalls at other FMOD calls (setParameter, set3DAttributes, setVolume, getRecordDriverInfo, getProperty etc.), but most of those seem to coincide with an FMOD Event callback, which is something we can further optimize on our side.
From our code I can see we only call FMOD_Studio_EventInstance_GetVolume to get the volume and do not care about the finalVolume. So a patch to just be able to get the volume would already be useful in that regard (assuming a stall won’t just be moved to the next setVolume call after that).
We do a lot of getVolume and setVolume for our custom audio obstruction, and much of the stall time occurs during getVolume.
If it’s a matter of optimizing our code to make sure that the FMOD Studio thread has more CPU time, then that’s what we’ve got to do. We tend to focus more on our main thread performance, as it’s usually the bottleneck to retain the framerate.
Maybe also relevant, we are using Unity Integration version 2.00.07 currently, and hopefully updating to version 2.01.09 in the future.
From our code I can see we only call FMOD_Studio_EventInstance_GetVolume to get the volume and do not care about the finalVolume.
This makes things a lot easier, a simple change to the fmod_studio.cs should be sufficient to avoid the stalls with GetVolume then.
In fmod_studio.cs, find the single parameter version of the function EventInstance::getVolume, it looks like this:
public RESULT getVolume(out float volume)
{
float finalVolume;
return getVolume(out volume, out finalVolume);
}
Update it to look like this:
public RESULT getVolume(out float volume)
{
return FMOD_Studio_EventInstance_GetVolume(this.handle, out volume, IntPtr.Zero);
}
Now find where we DllImport the native function FMOD_Studio_EventInstance_GetVolume in fmod_studio.cs. In addition to that existing implementation, add this additional one below:
private static extern RESULT FMOD_Studio_EventInstance_GetVolume(IntPtr _event, out float volume, IntPtr zero);
[DllImport(STUDIO_VERSION.dll)]
So what we are doing here is when you call EventInstance::getVolume with only one parameter, it should now call into our native code passing zero for the finalVolume. The native code is already set up to ignore calculating this value if you don’t want it (avoiding the required crit).
This change will appear in a future patch of 2.01.xx, I’ll make the same changes for GetPitch also. Additionally I’ve scheduled work to unblock the finalVolume and finalPitch values on the native side so even you if do want those values it won’t block.
Thanks! That worked like a charm. This fix, along with some optimizations to our EventCallback code, has almost completely removed any wait time for our main thread caused by Critical sections.