Imprecise "Write asset changes to disk" takes 80+ seconds during scene save, how to profile?

I’m debugging a bottleneck in our game’s editor performances and it boiled down to EditorSceneManager.SaveOpenScenes, which underneath it has a profiler entry for “Write asset changes to disk” that often takes well over a minute on my machine:

However, there isn’t any more information available and I’m not sure how to debug this. I’m already using Deep Profile.

Here’s another profile with more depth, but all the time is spent in Self MS, so I have no idea what’s causing this:

What could cause this? Can I get more precise debugging?

Similar reports with no solution:

Like suggested in some of these threads, I:

  • Rebuilt my project library, didn’t fix
  • Disabled sprite packing, didn’t fix

EDIT: This was not the issue, Wwise was.

I think I fixed it.

This seems suspiciously like some sort of file lock / mutex not getting released, and I remember a lot of those happening ever since Unity has had a deeper integration with Plastic SCM after acquiring them. There were multiple recent patch notes about fixing these mutex locks, but apparently this one is another remaining one.

The fix, in my case, seems to have been to put PlasticSCM in Offline Mode from Edit > Project Settings > Version Control > Plastic SCM Settings:

Hi @LazloBonin ,
I’ve pinged the Plastic team about this issue, but I think that helping guide the issue can also speed the fix up. Can you repro this problem AND supply a native stack trace?
I put together a guide on how to do that here: Debugging Editor freezes and hangs [Windows Only]
If the editor is stuck a long time doing something, and there’s no good info from the profiler, the native stack trace could help us figure out if it is indeed a mutex or something else that’s taking a really long time.

Hi Javier, thanks a lot for these instructions!

I will re-enable Plastic SCM and test in the near future.

However, in the mean time, even after disabling, I do regularly get smaller/shorter hangs still (20-30s). Here is the native stack for them:

8728170--1180806--procexp64_4BmPmTD3JW.png

ntdll.dll!NtWaitForSingleObject+0x14
KERNELBASE.dll!WaitForSingleObjectEx+0x8e
Unity.exe!UnityClassic::Baselib_SystemSemaphore_TryTimedAcquire+0x1a
Unity.exe!AutoBackgroundProgressBar::ThreadFunction+0x6c
Unity.exe!Thread::RunThreadWrapper+0x7b6
KERNEL32.DLL!BaseThreadInitThunk+0x14
ntdll.dll!RtlUserThreadStart+0x21

As suspected, it seems to be a semaphore wait that’s taking longer than expected, but I’m not sure what for from that stack.

Again, this is with Plastic SCM in offline mode already, so (presumably?) unrelated to Plastic. I’ll post here again with repros of the Plastic hang later.

Edit: here’s another suspicious stack that caused a 60s+ hang:8728170--1180827--upload_2023-1-13_11-7-22.png

Thanks for sharing this!

The first one with the AutoProgressBar is not very interesting, but the 2nd one is quite interesting.

This is essentially saying that its taking the AssetImportWorkers 60s to stop execution.

There should be a file in the logs folder of your project, which could have some more information about what the workers are doing. The path should be: $Your_ProjectName/Logs/AssetImportWorkerX.log , where X is some number.

Is there anything suspicious in those log files (you can also DM me if you want to share them).

Hi Javier,

I’ll be on the lookout, this second one was harder to reproduce, but the first “not very interesting one” happens a lot more often.

What “suspicious” thing should I be looking for in the worker log files?

1 Like

Hi Javier,

I’ve setup my project on a brand new machine with frankly ridiculous specs (16-core Intel Core i7 13th gen), and the first hang still occurs frequently, locking the editor for ~30s at a time on various operations (scene load, playmode entry, asset database refresh, etc. – it’s hard to tell what exactly causes it). I get exactly the same stack from the debugging tool every time. If that stack is “not interesting” by itself, do I have any other way of profiling what might be going wrong?

Thanks to Javier’s help in DMs, we fixed the issue!

From looking at the asset import worker logs, it turns out the issue was that Wwise (which we use in our project) was trying to initialize on the asset worker thread and failed to do so because asset database operations are not available there, and thus tried to rebuild its entire project data asset from scratch every time. The rebuild took ~60s in our case (big production project) and caused a significant hang on the asset worker thread, which then the main thread waited on in some circumstances (scene save, play mode entry, etc.). This seems related to an issue reported on AudioKinetic’s QA website here: Wwise Unity Unable To load Wwise Data - Community Q&A

I’ll report the issue to AudioKinetic, but in the mean time, the hotfix for us was to add this check:

In AkWwiseWWUBuilder.cs, in the static initializer, prefix the method with this short circuit:

    static AkWwiseWWUBuilder()
    {
        // Fix for hang caused by Wwise trying to load its asset data in the worker process
        if (UnityEditor.AssetDatabase.IsAssetImportWorkerProcess())
        {
            UnityEngine.Debug.Log("Skipping Wwise project data initialization in asset import worker process");
            return;
        }
       
        // This method gets called from InitializeOnLoad and uses the AkWwiseProjectInfo later on so it needs to check if it can run right now
        InitializeWwiseProjectData();

        UnityEditor.EditorApplication.playModeStateChanged += (UnityEditor.PlayModeStateChange playMode) =>
        {
            if (playMode == UnityEditor.PlayModeStateChange.EnteredEditMode)
            {
                RestartWWUWatcher();
            }
        };
    }
1 Like

With regard to the callstack for the AutoProgressBar not being interesting, its because that runs on another thread which is not on the main thread, so even if that’s waiting for a semaphore, the Editor should not get locked up because of it. The interesting one definitely has main thread activity there, which is the one that contains EditorSceneManager_CUSTOM_SaveOpenScenes, as that is guaranteed to be on the main thread (that code cannot run on a thread as it is not marked as thread safe), so if the main thread locks up then the Editor is unresponsive.

One additional way to figure out what’s going on in the workers, which works on 2021.1 and up, is by using the profiler.
This can be done by launching the project with “-profiler-enable” and then you should be able to view the worker on the dropdown list like so:

Once you get the profiler going, you can dig down into where time is being spent and try and debug it that way.