Search Unity

  1. Megacity Metro Demo now available. Download now.
    Dismiss Notice
  2. Unity support for visionOS is now available. Learn more in our blog post.
    Dismiss Notice

AssetDatabase ImportAndPostprocessOutOfDateAsset very slow to execute

Discussion in 'Asset Database' started by WBagley, Jan 20, 2022.

  1. WBagley

    WBagley

    Joined:
    Oct 5, 2016
    Posts:
    7
    I have recently been having issues with the AssetDatabase V2 refreshing in editor. In the project I'm working in (which is fairly large), the whole team is getting ~30s+ reload times every time we refocus the Unity editor after coming back from Visual Studio. This issue only seems to be a problem on Windows as well, Mac editor is much better.

    When I deep profile the editor (Unity 2020.3.25f1 LTS), the node AssetDatabase.V2.ImportAndPostprocessOutOfDateAssets takes 19.7s (self ms) of a total 26s second long frame, reporting a "Self" value of 75.4%, so I figure that the issue is not in a child block. This is reproducible every time I come back from Visual studio.

    The closest similar issue I can find, of which @Unity_Javier was closely supporting, seems to get really close to the issue, but doesn't have an exact solution. See: https://forum.unity.com/threads/asset-pipeline-v2-script-reimport-performance.784322/#post-7013539 . The post mentions opening the editor using the -profiler-enable command line arg. When I try that in Unity hub I see a Unity crash window pop up very quickly and then nothing happens. The editor opens fine without the argument.

    What is happening inside ImportAndPostprocessOutOfDateAssets? Is there some way I can dig further into what is causing it to take so long? I suspect maybe it's a plugin(s), but am at a loss as to how to track down which, and why.

    Debugging Unity's startup seems to be key, but my version of Unity seems to not want to allow that. Any help would be greatly appreciated. I also tried updating the project to Unity 2021.2.8f1 as I saw a lot of people talking about AssetDatabase issues in Unity 2020, and the refresh time is cut down to around 5s, but on such a large project I would prefer to avoid such major upgrades if possible.

    I've attached a profiler snapshot of the frame in question.
     

    Attached Files:

    chaostheorygames likes this.
  2. Unity_Javier

    Unity_Javier

    Unity Technologies

    Joined:
    Mar 7, 2018
    Posts:
    188
    Hi @WBagley ,

    Sorry for the delayed reply! I think my e-mail notifications are not setup correctly, so I didn't see this particular issue.

    To try and answer your question, ImportAndPostProcessOutOfDateAssets does a bunch of things:
    1. Compile Scripts
    2. Import Assets
    3. PostProcessAllAssets
    4. Others (that we can skip for now).

    In those 3 first points, there is a possibility to hook into Unity's code execution during user callbacks (i.e.
    CompilationPipeline.assemblyCompilationStarted , AssetPostprocessor.OnPreprocessAsset, AssetPostprocessor.OnPostprocessAllAssets to name a few). and during those callbacks, code is allowed to do "whatever it wants" which can be troublesome, since this is supposed to be a pretty hot path, and if code in any of the callbacks invoked enumerates the entire project using something like AssetDatabase.FindAssets, time spent waiting for a Refresh will increase.

    The way to debug it further is to do a Deep Profile, and see if any of the code reported under ImportAndPostProcessOutOfDateAssets is running inside any of the libraries for which you have source code for and can modify (or upgrade those libraries to a new version, if the address the issue you're seeing). There are naturally some pieces of code that you just can't modify (i.e. Unity's own source code), but many times a long time can be spent in Asset Store plugins, certain packages, etc. which you could modify and optimize. Happy to share some tips, in case you have more data (and you can always DM me in case the info is sensitive).

    Let me know if this helps you move forward, and also, there's another active thread where we acknowledge that this is a big deal that we need to fix across teams within Unity: https://forum.unity.com/threads/improving-iteration-time-on-c-script-changes.1184446/
     
  3. WBagley

    WBagley

    Joined:
    Oct 5, 2016
    Posts:
    7
    Thanks for the response!

    The list of callbacks you mentioned was a good starting point. I found all references to those in the source code (including plugins) and commented them out just to see what sort of an impact they were having. Doing another Deep Profile of the editor with the listed callbacks removed: I have the Time ms of ImportAndPostProcessOutOfDateAssets down to 21s, but that's still pretty long.

    I think my main confusion at the moment is why the value of Self ms of ImportAndPostProcessOutOfDateAssets is so high (19.7 seconds). Does that imply that the function itself is taking all the time, rather than child nodes of ImportAndPostProcessOutOfDateAssets? If it was assemblyComilationStarted, OnPreprocessAsset, OnPostprocessAllAssets etc, wouldn't they show up as their own nodes in the profiler? In the original screenshot I attached I can see PostProcessAllAssets with a Time ms of only 48ms.

    Wondering if there are any other tools I can use to help narrow down the search as well.
     
  4. Unity_Javier

    Unity_Javier

    Unity Technologies

    Joined:
    Mar 7, 2018
    Posts:
    188
    Hey! So, the reason for seeing the Self Time time being so high is that there are potentially not enough profiler markers in the Native Code that can tell the Unity Profiler about what's going on when ImportAndPostProcessOutOfDateAssets. This is because we sort of have to add code inside the Unity source code that can tell the Profiler "this function is now executing" (a sort of Instrumentation Profiler approach), whereas a Sampling Profiler with high enough frequency, like Superluminal can really go under the hood and give you a better understanding of what's going on. They do have a trial, and its totally worth it, so if you want to get more info into what's going on under the hood in ImportAndPostProcessOutOfDateAssets I definitely recommend getting it, and sharing what you find here (or in a DM if you prefer) and we can go from there.

    I'm on holiday from tomorrow until next week, but should be able to come back here and provide some more support before I go, and once I'm back!
     
  5. bjarkeck

    bjarkeck

    Joined:
    Oct 26, 2014
    Posts:
    301
    Superluminal is absolutely amazing, I can second that recomendation. (Support for Unity is coming if it's not out already, reach out to them if not) They'll give you symbol servers for Unity's native code etc.

    Perhaps we're having the same issue @WBagley

    @Unity_Javier
    I have a fairly small project on hand (~6gb), and I'm measuring 1m 11s of ImportAndPostProcessOutOfDateAssets every time I start up Unity. 52s of that is MonoScriptManager::InitializedRegisteredScripts - I've uploaded the superluminal file here: https://ln5.sync.com/dl/b8f56ab60/35v5zakq-s8me5wxs-t7dizw5q-rq9scviv

    Here are some screenshots of the call graphs:
    upload_2022-2-6_17-19-51.png

    upload_2022-2-6_17-20-43.png

    PersistentManager::ReadObject is being incredibly slow, and it is not just slowing down InitializeRegisteredScripts - It is approximetely 75% of the entire 2s+ startup time. See the graph below. I have a NVMe drive, (my PC spec is here: https://www.userbenchmark.com/UserRun/50104266) and I'm using Unity version 2020.3.26f1 on Windows 11

    upload_2022-2-6_17-18-55.png

    No managed custom code seems to be under the callstack of ReadObject.
     
    Last edited: Feb 6, 2022
  6. bjarkeck

    bjarkeck

    Joined:
    Oct 26, 2014
    Posts:
    301
    Update

    I looked into wdFilter.sys from the callstack and it looks related to virus projection, maybe not... but it led me to try disabling all virus protection and the startup time went from 2m to 20s.
     
    Last edited: Feb 6, 2022
    Unity_Javier likes this.
  7. Unity_Javier

    Unity_Javier

    Unity Technologies

    Joined:
    Mar 7, 2018
    Posts:
    188
    Good find @bjarkeck !

    I think the issue for us to solve here is that a lot of file reading is happening, and we might be able to do something about that, especially if its reading the Import Results in the library folder.
    One more tool to try out is Process Monitor from SysInternals as that will tell you the path on disk which is being read by any application, and also give a callstack if you point it to the folder where the .pdb file that ships with the version of the Unity Editor you're using (i.e. C:\Program Files\Unity\Hub\Editor\2021.2.2f1\Editor)
     
    bjarkeck likes this.
  8. bjarkeck

    bjarkeck

    Joined:
    Oct 26, 2014
    Posts:
    301
    Another great tool, thanks! Unsure if you wanted me to test something specific with it. Just let me know.

    What's especially annoying right now is that Windows 11 won't let me permanently disable "Real-time protection", it enables it every time I start up windows.
     
  9. Unity_Javier

    Unity_Javier

    Unity Technologies

    Joined:
    Mar 7, 2018
    Posts:
    188
    There's an experiment that I've been wanting to try, but haven't had a chance yet.

    The hypothesis, is that the more C# scripts in a project, the slower your project will get.
    Now, in order to reduce the amount of C# scripts but keep functionality the same, it would be interesting to try and put all Scripts that are not MonoBehaviours inside a DLL and see how that affects this situation. Monobehaviours should not be placed inside this DLL because Asset references (and GUIDs) could be lost.

    There's plenty of reasons why doing this correctly would be hard, but just as a test, it might be interesting to see what effect putting all your code in a DLL, except for the code actively being developed, would have on your iteration speed.

    This could be applied to code in packages too, since their DLLs are already inside the Library/ScriptAssemblies folder, so changing the manifest.json to have no packages, but keep a number of DLLs as part of the project instead could help support this hypothesis.

    What do you think?
     
  10. WBagley

    WBagley

    Joined:
    Oct 5, 2016
    Posts:
    7
    It's certainly an interesting option. The project that I'm working in has a huge amount of individual scripts. Unfortunately it would probably take a substantial amount of time to split up everything into a DLL.

    At the moment I've moved the project to Unity 2021.2.11 and the refresh time is significantly improved. As originally mentioned: tabbing back into the project from Visual Studio only triggers about 5 seconds of recompiling, which I could improve through assembly definitions I suspect.

    It took a couple of days to do the upgrade in a project this large, but the amount of time saved across the team made it worth the time. I might be interested to go back to 2020.3 with a large project in the future and give the DLL option a go.
     
    Unity_Javier likes this.