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

Unity Engine
1

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 shit 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:

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.

3075463--231380--unityReloadAssembliesSlow.PNG
3075463--231380--unityReloadAssembliesSlow.PNG990×257 41.4 KB

1 Like
2

Bump, and also:

Is this it? Did I find the same issue I’m having?

3

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

Sure, here’s everything I could expand under CreateAndSetChildDomain. Let me know if you’d like anything else.

3077712--231608--unityReloadAssembliesFull.PNG

5

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

Thanks for the follow up steps, here’s what I got for ya. Sorry it took a bit, we’ve been traveling. :slight_smile:

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.

3079870–231830–UnityProfileResults.zip (244 KB)

7

Hopeful bump

8

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

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

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

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

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

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

Bumparooni

15

Same issue here.

16

Bump, same problem, I’m also on Windows 7

17

Same on Windows 10 and Unity 2017.2.0f3

18

Unity 5.6.4f1. Same issue.
Happens often but randomly. In my case, it takes about 300 sec to ReloadAssemblies.

19

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.

3339269--260643--upload_2018-1-2_15-31-30.png
3339269--260643--upload_2018-1-2_15-31-30.png1825×1188 250 KB

20

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.

2 Likes