Search Unity

Unity entering play mode slowly due to spending 10-20 seconds in ReloadAssemblies?

Discussion in 'Editor & General Support' started by chrysocollus, May 19, 2017.

  1. chrysocollus

    chrysocollus

    Joined:
    Jan 1, 2014
    Posts:
    9
    My issue is that entering play mode takes forever. I've been having this issue... I want to say since I upgraded to Unity 5, but I'm not actually sure because that was like two years ago. I have spent a lot of time just living with it because I had school projects I needed to do to graduate.

    Up to this point, I've updated Unity to the latest version as of today (5.6.1f1) and did a full reinstall, including clearing out any residual Unity references in my AppData folder (to the best of my ability). I also updated my graphics card drivers. For what it's worth, I've been running Unity on this computer for about 4 years now. Edit: I've also tried disabling my antivirus.

    I don't think the specs for my laptop are necessarily relevant, but here they are - it's an Alienware I got about four years ago, but it's still pretty good IMO:

    Windows 7
    Processor: Intel i7-4700MQ CPU @ 2.40 GHz
    RAM: 16 GB
    GPU: Nvidia GeForce GTX 770M (Drivers are up to date as of earlier this week)

    I have an integrated graphics card and a GPU and I've made sure Unity's running on the GPU, most notably by making it run like even slower S*** on the integrated card.

    I can repro it in an empty project, so let's just talk about that.

    In a project I've just opened, when I go to enter Play Mode, it takes maybe 2-3 seconds. This is long, but not too big of a deal. In subsequent attempts, even if I immediately close and re-enter Play Mode, it will spike up to anywhere between 10-20 seconds. I have developed a game in these circumstances, but it sucks and I'd like to figure out how to fix it. So I pulled out the Unity Profiler and ran it on the editor.

    See the attached picture for what that looked like.

    So, I see that there's a major spike in EnterPlaymode -> ReloadAssemblies (18600 ms!). Here's the record of me entering and exiting Play Mode a few times, according to the engine log's time to reload assemblies:

    - Completed reload, in 3.189 seconds
    - Completed reload, in 15.761 seconds
    - Completed reload, in 16.191 seconds
    - Completed reload, in 14.970 seconds
    - Completed reload, in 14.906 seconds

    And I've done my research! Here's the most relevant stuff I could find on it:

    https://forum.unity3d.com/threads/r...-gets-exponentially-slower-and-slower.274452/
    https://forum.unity3d.com/threads/speeding-up-monomanager-reloadassembly.274133/
    http://answers.unity3d.com/questions/1195279/reload-assemblies-making-enterplaymode-take-long.html

    That last one doesn't even have an answer, haha. The other two are very symptomatically similar, with the long Reload Assemblies calls. However, those are both with BIG projects. Not projects that literally were just made with Unity. So, I'd love to go compress all my assets into asset bundles in my fuller projects, but I don't think it would actually help anything because I still get this problem in a project that has NO ASSETS.

    So that's why I'm here. Please help.

    Even if you guys can just tell me what Reload Assemblies is going through and doing, that might be helpful because maybe it's just paging? But that wouldn't explain the faster load time the first load in.
     

    Attached Files:

    Last edited: May 19, 2017
    AdmiralThrawn likes this.
  2. chrysocollus

    chrysocollus

    Joined:
    Jan 1, 2014
    Posts:
    9
  3. RichardFine

    RichardFine

    Unity Technologies

    Joined:
    Nov 11, 2014
    Posts:
    13
    Could you share a version of that screenshot which isn't cut off? I'd like to see the child entries it's reporting for CreateAndSetChildDomain.
     
  4. chrysocollus

    chrysocollus

    Joined:
    Jan 1, 2014
    Posts:
    9
    Sure, here's everything I could expand under CreateAndSetChildDomain. Let me know if you'd like anything else.
     

    Attached Files:

  5. RichardFine

    RichardFine

    Unity Technologies

    Joined:
    Nov 11, 2014
    Posts:
    13
    OK. I don't have a full picture of what is happening here yet, but here's some more information.

    All .NET code executes within the context of an AppDomain. Loading an assembly loads it into a particular AppDomain. Assemblies cannot be individually unloaded once loaded - the only way to unload them is to trash the whole AppDomain and recreate it. So, that's what we do whenever we want to reload your code after compilation, or whenever we want to 'reset state' (e.g. when entering play mode).

    There's two AppDomains in effect in Unity - the 'root' domain (which we never use), and the 'child' domain, which is where everything actually happens.

    So here's a pseudocode walkthrough of CreateAndSetChildDomain. This is from current trunk, rather than 5.6.1f1, but I do not think there have been major changes in this area.

    CreateAndSetChildDomain:
    * Unload the old child domain:
    ** Issue the global "beforeDomainUnload" C++ callback
    ** Clear the global "logCallback" C++ callback.
    ** Change the currently active domain back to the root domain
    ** Unload the child domain.
    ** Run the GC.
    ** Issue the global "domainUnloadComplete" C++ callback.
    * Create the new child domain.
    * Point the new domain at the appropriate config data on disk.
    * Set the new domain as the active domain.

    Looking at the profiler capture, I can attribute the AppDomain.DoDomainUnload bit to "Unload the child domain" - though that will not include e.g. time spent waiting for threads in the domain to stop - and I think the various .ctor() calls are part of "create the new child domain." Unfortunately, that does not tell you much about which step(s) are responsible for the other 16688ms...

    I can see about adding more profiler instrumentation into Unity 5.6.2 (or even a 5.6.1 patch release) to help narrow it down, but it's going to be a couple of weeks before I can do that. If you want to make progress in the meantime - and probably in a more conclusive way than me just adding more profiler hooks - then your best shot will be to use a native profiler (such as Very Sleepy) to capture a domain reload. We ship symbols with the Editor, so a native profiler should be able to give readable callstacks, even if it can't show actual source. Then we can take a look at the dominant callstacks and go from there.
     
  6. chrysocollus

    chrysocollus

    Joined:
    Jan 1, 2014
    Posts:
    9
    Thanks for the follow up steps, here's what I got for ya. Sorry it took a bit, we've been traveling. :)

    So I booted up VerySleepy and profiled it around Unity entering play mode. See "unityProfileEnterPlayMode.csv" in the zip. It showed a lot of time in WaitForSingleObjectEx, but that's maybe just threads waiting on a thing. We found that there were about 30s worth of calls to RegFlushKey.

    Thinking that was weird, I grabbed Process Monitor and used it to monitor the Registry events. See "unityRegistryFails.csv" in the zip. It shows several iterations of the following sequence: A call to RegQueryKey followed by RegCreateKey followed by RegQueryKey which fails twice with a buffer overflow, before finally expanding the buffer and succeeding. It does this sequence several times, which may explain the extra time it takes to enter play mode.

    If this information is lacking in any way, please let me know, I'll happily update with more data. I hope this is useful.
     

    Attached Files:

  7. chrysocollus

    chrysocollus

    Joined:
    Jan 1, 2014
    Posts:
    9
    Hopeful bump
     
  8. superpig

    superpig

    Quis aedificabit ipsos aedificatores? Unity Technologies

    Joined:
    Jan 16, 2011
    Posts:
    4,158
    Hey, sorry, Hackweek happened and I forgot about this for a bit.

    Exactly what period does that unityRegistryFails.csv cover? From the events, it looks like it actually starts with project opening? Or did you just start the Process Monitor trace while Unity was already running, then alt-tab back to Unity, hit play, wait, then alt-tab back to PM and stop it?

    There's one very distant bell ringing: I have seen weird hanging behaviour in the region of wininet/ConnectionSettings stuff before, a while ago, when there is a network adapter on the system that is behaving strangely. In my case, I had a VPN client installed which had created a virtual adapter, but the credentials I'd given it were wrong, so it couldn't connect to the VPN properly... this left it in a semi-disabled state where querying it for connection information would take a very long time. Do you have any unusual network adapters on your system? Perhaps try disabling them and see if the problem persists?
     
  9. chrysocollus

    chrysocollus

    Joined:
    Jan 1, 2014
    Posts:
    9
    > Do you have any unusual network adapters on your system? Perhaps try disabling them and see if the problem persists?

    I don't think I do. I've gone through and disabled all of the network devices in Device Manage and re-tested by reopening Unity and entering play mode multiple times, with the same result. ipconfig yielded nothing unusual but a "tunnel adapter isatap", which I disabled and re-tested to no avail as well.

    I did have a VPN through Avast, maybe two years ago. It's entirely possible I removed Avast and its VPN right around the time this issue started - unfortunately, it's long enough ago that I truly don't know. All I know is that I'm reasonably sure this has been a problem since you guys shipped (and I upgraded to) Unity 5, which was about the same period of time.

    > Exactly what period does that unityRegistryFails.csv cover? From the events, it looks like it actually starts with project opening? Or did you just start the Process Monitor trace while Unity was already running, then alt-tab back to Unity, hit play, wait, then alt-tab back to PM and stop it?

    I started the trace while Unity was running, alt-tabbed, then started play mode. Once it had finished, I alt-tabbed back, stopped the trace, then stopped play mode in Unity. I repeated the same process for the registry capture.

    Please let me know if you'd like me to capture other data, I'd be more than happy to. And, thanks so much for helping with this.
     
  10. superpig

    superpig

    Quis aedificabit ipsos aedificatores? Unity Technologies

    Joined:
    Jan 16, 2011
    Posts:
    4,158
    It's possible that Avast left something behind that is interacting with the version of Chromium Embedded Framework (CEF) that we use for the launcher / asset store / etc - though that did not actually ship until 5.1. I don't suppose you have any other machines to hand on which you could try opening the same project, and see if you have the same problem, so we can establish whether the problem is specific to your machine?

    Ah, ok, that's interesting. I have a theory that this is still CEF's doing, and that there's something we are doing during the domain reload that is causing CEF to reload as well, which seems unnecessary (unless you have the Services window open, or something like that?).

    Bear with me for a bit - I think we are going to need to do more captures, but I want to do a little research on exactly what to capture and what we should expect it to look like, first.
     
  11. chrysocollus

    chrysocollus

    Joined:
    Jan 1, 2014
    Posts:
    9
    I'd be willing to bet it's just my machine, I can repro this with an empty project and I've asked around a bit, none of my cohort seem to have a similar problem unless their project is huge or something.

    Especially since the CEF shipped with 5.1, that lines up with when I started having this problem, too.

    The CEF - is that cleaned when Unity is uninstalled / reinstalled? That's one of the things I've tried to fix this, and it didn't work. But maybe you can point me to something I can do to make sure it gets reset when Unity is reinstalled?

    Uh, I don't think so. I haven't used Services for anything, so I don't think that's the case. The stuff I've been working on is really simple game logic, sprites, and using the profiler sometimes.
     
  12. superpig

    superpig

    Quis aedificabit ipsos aedificatores? Unity Technologies

    Joined:
    Jan 16, 2011
    Posts:
    4,158
    Alright.

    Yeah, it's part of Unity - libcef.dll, you'll see it in the same folder as Unity.exe. It should be totally removed when you uninstall Unity. To be clear, I'm not saying that your copy of CEF has become corrupted, or anything like that - I just think there's some kind of behaviour in it which is interacting with something on your machine to cause the big delays.

    OK, and you don't have the Asset Store window open in the background, or anything like that? Perhaps even as an inactive tab? You could try resetting to the 'Default' layout, then closing the Asset Store tab, then see if the problem persists - just to rule out this being because of a window being recreated (which we do, even for windows that are not active tabs right now).
     
  13. chrysocollus

    chrysocollus

    Joined:
    Jan 1, 2014
    Posts:
    9
    Nope, I don't generally use the Asset Store for much anything, I mostly prefer writing my own tools.

    Anyways, reset Unity to the default layout, then closed the Asset Store tab, then entered play mode repeatedly, every entry into play mode after the first one took >10 seconds. So I don't think that was the problem either.

    If I alt-tab, then enter play mode, it takes maybe 4-5 seconds. If I enter play mode again, then it usually takes upwards of 15-20. Very weird.
     
  14. chrysocollus

    chrysocollus

    Joined:
    Jan 1, 2014
    Posts:
    9
    Bumparooni
     
  15. Bubagent86

    Bubagent86

    Joined:
    Jan 3, 2014
    Posts:
    10
    Same issue here.
     
  16. blurdot

    blurdot

    Joined:
    Jan 26, 2014
    Posts:
    20
    Bump, same problem, I'm also on Windows 7
     
  17. Major-Idea

    Major-Idea

    Joined:
    Jul 26, 2012
    Posts:
    12
    Same on Windows 10 and Unity 2017.2.0f3
     
  18. mmortall

    mmortall

    Joined:
    Dec 28, 2010
    Posts:
    80
    Unity 5.6.4f1. Same issue.
    Happens often but randomly. In my case, it takes about 300 sec to ReloadAssemblies.
     
  19. AdmiralThrawn

    AdmiralThrawn

    Joined:
    Dec 1, 2013
    Posts:
    18
    Happy new year, everyone!

    After spending a lot of time refactoring our lengthy singleton managers scripts into many small and much easier manageable ScriptableObjects, we are now facing serious loading time when pressing the play button.
    Interestingly, when we used singleton manager scripts throughout everywhere we had the play mode starting up with no noticeable delay. Also, with more eventing (via GameEvent + EventListeners) going on between many instances using our SOs we encounter more frequent freezes on starting play mode and crashes when Unity performs internal code updates after changing code in VS.

    We're using Unity 2017.3.0f3. In case any Unity dev is interested in investigating this, I'd be willing to share a snapshot of our current development.

    upload_2018-1-2_15-31-30.png
     
  20. Peter77

    Peter77

    Joined:
    Jun 12, 2013
    Posts:
    3,745
    Have you enabled "Deep Profiling" already and checked what's beneath "PostInitializeOnLoadAttributes"? It could be code from your project that is causing this issue, such as code that runs when callbacks like RuntimeInitializeOnLoadMethod, InitializeOnLoad, etc are triggered.

    In most cases, Unity staff isn't looking for bug-reports on the forum. If you believe you found an issue in Unity, I recommend to submit a bug-report following the advice given in this document.
     
    AdmiralThrawn likes this.
  21. AdmiralThrawn

    AdmiralThrawn

    Joined:
    Dec 1, 2013
    Posts:
    18
    Yeah I used Deep Profiling: The whole system hung up for several minutes until Unity finally crashed.

    But, your tip is gold worth: I checked which code uses either RuntimeInitializeOnLoadMethod or InitializeOnLoad and I found the plugin 'Async Await Support' (which I imported a few days ago to try out) uses the first annotation and causes the play mode to take so long. Thanks a lot, Peter! :beer:
     
    superpig and Peter77 like this.
  22. jschroyen

    jschroyen

    Joined:
    Aug 19, 2015
    Posts:
    22
    I have long (11s) EnterPlayMode times, with ReloadAssemblies taking 6.4s.
     
  23. DeusExMachina1993

    DeusExMachina1993

    Joined:
    Aug 9, 2015
    Posts:
    1
    I have 10s enter play mode, in 2018.1.3f1
    any update ?!
    any advice ?!
     
  24. eladleb4

    eladleb4

    Joined:
    Apr 25, 2016
    Posts:
    16
    I have 46 seconds :(
    My colleague is working on the same project with a same-spec machine and he enters play-mode in 10 secs... What can we do? Screen Shot 2018-06-13 at 10.54.41.png
     
  25. PsyKaw

    PsyKaw

    Joined:
    Aug 16, 2012
    Posts:
    99
    0.76Gb of GCAlloc on ReloadAssemblies() is a lot.
    Do you have a lot of [InitializeOnLoad] ?
    Can you expand ReloadAssemblies node please, to see what is allocating ?
     
  26. eladleb4

    eladleb4

    Joined:
    Apr 25, 2016
    Posts:
    16
    @PsyKaw
    We have less than 10 InitializeOnLoad, most of them from Anima2D...

    I ended up updating from 2018.1.02f to 2018.1.04f and now the enter play time is back to normal. I didn't save the profiler state so I can't reproduce anymore.
    I doubt the update was what really resolved the issue though so I'm keeping my fingers crossed to not bump into it again, it was a very unproductive day :(
     
  27. 8Shade

    8Shade

    Joined:
    Jun 14, 2014
    Posts:
    9
    Hi, @superpig

    No idea since when, but I have a trouble loading my scene by SceneManager.LoadScene call in Editor (on Android it works without problems).
    It takes OVER 2 MINUTES to LOAD every time! (150+- seconds)

    Happens only in Editor and only if I load my main scene from a different scene using that call. If I play the scene directly, it works well (few seconds to play the editor). I tried to delete all InitializeOnLoad from my project, it is still happening. I was profiling this for last two days and Once i saw Loading:lockPersistentManager() being the last thing that takes that much time in profiler. After that i never saw this one.

    Below is a deep profile (editor profile enabled) loading of the scene which takes so much time. Also i added a profiling file to google drive as it was too big:

    https://drive.google.com/open?id=12hXVzxCZ_lOVIs-h0G53P3JSlqsFG_B7

    Unity version 2018.2.6f1 (64bit), Windows 10

    Is this known issue? Any ideas what else I could try?


    EDIT:
    Additional findings see in comments below
     

    Attached Files:

    Last edited: Oct 30, 2018
  28. Peter77

    Peter77

    Joined:
    Jun 12, 2013
    Posts:
    3,745
    Do you load several additive scenes in parallel / at the same time?

    This was causing the editor to trigger lockPersistentManager and get really slow with my project. I then changed the loading code to load each scene after another, rather than all at once, and this improved performance significantly.
     
  29. 8Shade

    8Shade

    Joined:
    Jun 14, 2014
    Posts:
    9
    Hey Peter, no, just one scene (which generates whole dungeon in Start method). It is possible that I saw the lockPersistentManager when I was loading via async method, but I changed to sync to debug this issue. Happens with both. Game is called Dungeon Ward if you want to see what I mean.
     
  30. 8Shade

    8Shade

    Joined:
    Jun 14, 2014
    Posts:
    9
    Additional findings to my 2 minutes+ play issue:
    Today i was testing some more and one time this showed up in the profiler:
    PluginImporterInspector.OnEnable() -131+ seconds

    I noticed it seems to run in some cycle with DefaultPluginImporterExtension.RefreshProperties() inside, screenshot below.

    Profiler save:
    https://drive.google.com/open?id=1Nsn3REkmRyoQMCZ7qvMzdTrB5JYPH9gR

    EDIT: hmm when i think about it, could have been because i had plugin inspector opened... so maybe just coincidence (because i have editor profiler enabled)
     

    Attached Files:

    Last edited: Oct 30, 2018
  31. 8Shade

    8Shade

    Joined:
    Jun 14, 2014
    Posts:
    9
    So I was investigating for like 3 full days and I believe I know the ROOT CAUSE.
    https://forum.unity.com/threads/ext...-loading-checkconsistency-editor-only.507693/

    I loaded an older version of the project and found that loading times are around 40seconds after clicking play, but if I click one specific prefab in editor, the unity hangs for a moment doing Loading.CheckConsistency on that prefab for 30+ seconds. After that If I hit play, the game starts in editor after 10 s instead of 40s, so it seems that PLAY BUTTON is doing the consistency check too for all prefabs it is using!

    Sadly with newer version of my project i have more problematic prefabs which have this issue and the consistency "cache" is cleared before i click all my prefabs (seems like there is some limit of what can be in this cache and if you click more prefabs, the former are cleared), so this Click FIX doesnt work for it! (currently in Unity 2018.2.14f)

    SOLUTION: (or workaround still unknown), I believe this is could be a bug in Unity Editor.
     
  32. Peter77

    Peter77

    Joined:
    Jun 12, 2013
    Posts:
    3,745
    Indeed, it sounds like a bug.

    Could you please submit a bug-report, as explained in this document:
    https://unity3d.com/unity/qa/bug-reporting

    This allows Unity Technologies to reproduce the issue, take a look at the problem and hopefully fix it.
     
  33. 8Shade

    8Shade

    Joined:
    Jun 14, 2014
    Posts:
    9
    SOLUTION which FIXED THE ISSUE for me :
    Open all animators in your project in animator window one by one. Some of them took very long to load (30+ seconds), some of them were instant. Those who took long were the original problematic prefabs that were using them.
    After you load them like this, you should be able to click on them without any delays, try hit Play - issue doesnt happen anymore, probably the consistency check was fixed by this. Restart unity, the issue is no longer there. (but old bug with black lighting in next scenes after first one was reintroduced for some reason)

    Thank god after so many days of work on this....

    Bug report was sent.
     
    Last edited: Nov 5, 2018
    Yamada_t likes this.
  34. huulong

    huulong

    Joined:
    Jul 1, 2013
    Posts:
    48
    After removing all unused Unity packages from the Package Manager, I could reduce Enter play mode time from 23s (!) to to 17s (on Windows), even without recompiling anything. But still too long for me to iterate efficiently.
    I tried Unity on Linux and now I can enter Play mode in 5s.

    Note that both systems are running on SSD. Unity on Windows is running on SSD too, whereas Unity on Linux is running on HDD, so that doesn't seem to impact so much. Both projects were on HDD.

    ReloadAssemblies on start is much faster on Linux Unity 2018.2.7f1.png
     
  35. thepigeonfighter

    thepigeonfighter

    Joined:
    Nov 7, 2017
    Posts:
    3
    I am having the same issue(Possibly for a different reason not sure). It just started all the sudden. My project is not large at all but took 26 seconds to load. Cant figure out why. Takes forever going into and exiting play-mode. Using version 2018.3.0f2
     

    Attached Files:

  36. thepigeonfighter

    thepigeonfighter

    Joined:
    Nov 7, 2017
    Posts:
    3
    So this problem persisted. I ended up making a new scene and copying the contents of the old scene into the new scene. That seemed to have fixed my problem. Idk why it was so slow.
     
  37. c_v

    c_v

    Joined:
    Nov 12, 2013
    Posts:
    4
    Had the same problem. Editor was entering playmode for about 45 seconds in deep profile mode, and about 10 seconds normally. I've removed all occurrences of attribute [InitializeOnLoad] and now it only takes 4 and 2 seconds accordingly. Hope that will help someone!

    Some [InitializeOnLoad] may be hidden inside some managed plugins, so for experiment's sake you can try remove suspicious plugins (*.dll)
     
  38. neshius108

    neshius108

    Joined:
    Nov 19, 2015
    Posts:
    70
    Hey there!

    Joining the gang to complain about very slow "Assembly Reload Time".
    Here is my benchmark:



    Now, after having moved things into the `Standard Assets` folder, I get less stuff compiling but that's all thrown out of the window if I keep on having ~8s of reload time for absolutely any tiny change.

    I also went through and removed lots of `[InitializeOnLoad]` but still the same.

    What can be done for this?


    UPDATE:

    For future readers, after lots of tests, here is what I did to manage to go from 9-10s to 6-7s in the compile/reload times:

    1. Moved imported assets and general tools into the "Standard Assets" folder (name has to be that)
    2. Removed as many files as possible (I went through and deleted all the Docs/Example/Demo folders from the assets I was using), their size is not necessarily important
    3. Removed default packages which I didn't need: Ads, IAP, Analytics, Multiplayer, XR Legacy, Memory Profiler (you can always bring them back whenever you actually need them)

    Notes: if, for some crazy reason, someone doesn't use the attach debugger feature in VS-Unity, disabling the "Editor Attaching" from the preferences, actually makes the reloading quicker (about 0.3-0.5s for me).

    Other crazy stuff I found:

    Unity seems to spam registry calls for certain player prefs, if they are not found, it will still try and try and try. Using process monitor, you can actually find the key and create an empty one in the registry. Little bit of a hack but worked and it stopped wasting time there.

    As a side note: it turns out Unity loads the verdana(b) fonts every single compilation, it only takes 0.003s but yeah it adds up :p

    And now, I can finally go back to develop in peace :rolleyes:

    upload_2019-5-8_1-11-8.png
     
    Last edited: May 7, 2019
  39. macagu

    macagu

    Joined:
    Sep 30, 2012
    Posts:
    4
    Hi all, i want to share my recent experience with the Assembly Reload time on my project.

    After changing a line of code, the Assembly Reload time was around 8 seconds.
    I had the same project checked out on another folder, and was measuring an Assembly Reload of 2 seconds after changing a line of code.
    Both folders contained the same assets and source.

    I did a REIMPORT ALL on the original project, then restarted Unity.
    Now the Assembly Reload time is 2 seconds.

    I guess something was wrongly catched on the first project folder. I was using the first one to develop, and the second one only for automated builds. The first folder was struggling with lots of changes on the day by day modifications.

    Hope this helps someone, and have a nice day!