4.3.4 - Hang on Play

Unity Engine
1

This issue have been solved. See last post. It’s not clean, but it works.

We are making an auto-generated game that uses a structure of data to know what to spawn and when.

All that structure is serialized in an Asset file.

Our issue is, when this Asset is loaded in an EditorWindow, Unity hang for a very long time when we press play.

When the structure is NOT loaded in the EditorWindow;

Mono: successfully reloaded assembly
- Completed reload, in  0.914 seconds
System memory in use before: 48.2 MB.
Unloading 149 Unused Serialized files (Serialized files now loaded: 0 / Dirty serialized files: 0)
System memory in use after: 34.8 MB.

Unloading 200 unused Assets to reduce memory usage. Loaded Objects now: 2195.
Total: 15.206539 ms (FindLiveObjects: 0.143984 ms CreateObjectMapping: 0.028978 ms MarkObjects: 2.562143 ms  DeleteObjects: 1.711516 ms)

Completed reload under 1 sec.

When the data structure is loaded in the EditorWindow;

Mono: successfully reloaded assembly
- Completed reload, in 77.812 seconds
System memory in use before: 48.3 MB.
Unloading 150 Unused Serialized files (Serialized files now loaded: 0 / Dirty serialized files: 0)
System memory in use after: 34.9 MB.

Unloading 200 unused Assets to reduce memory usage. Loaded Objects now: 2214.
Total: 1564.175171 ms (FindLiveObjects: 0.121949 ms CreateObjectMapping: 0.027468 ms MarkObjects: 1551.331177 ms  DeleteObjects: 1.980167 ms)

77 sec of reload!!

The .asset is only 34kb on disc. However, when we press play and Unity is doing… whatever it is doing, the RAM climbs over 1Gig, while it claims to only be using 38-48Mb!

This is currently a killer for our project because every times we changes anything, we have to wait over a minutes for the editor to wake up… When it does not crash!

2

BUMP!

3

Where do you get this printout from? I’d be interested to see that data in my game.

4

You’ve not given us a lot to go on. Can you show us the code for your custom asset type?

5

This is from the editor log that can be found here; %localappdata%\Unity\Editor\

I’ll try to sum up the hundred lines of codes;

public class GeneratorContainer : ScriptableObject
{
    public List<LevelDifficulty> levelDifficulties;

    public List<GPIDifficulty> gpiDifficulties;
}

[Serializable]
public class LevelDifficulty
{
    public List<LevelGroup> groups;

    public bool skipped = false;

    public int start = 0;
    public int stop = 100;
}

[Serializable]
public class LevelGroup
{
    private LevelDifficulty difficulty; // filled OnEnable

    public List<LevelSection> sections;

    public int currentWeight = 0;
    public int startWeight = 0;
    public int maximumWeight = 1;

    public int weightReductionOnSpawn = 1;
    public int weightIncrementationOnSpawn = 1;
}

[Serializable]
public class LevelSection
{
    private LevelSection section; // filled OnEnable

    public GameObject prefab;

    public string label;

    public int currentWeight = 0;
    public int startWeight = 0;
    public int maximumWeight = 1;

    public int weightReductionOnSpawn = 1;
    public int weightIncrementationOnSpawn = 1;
}

[Serializable]
public class GPIDifficulty
{
    public List<GPIGroup> groups;

    public bool skipped = false;

    public int start = 0;
    public int stop = 100;
}

[Serializable]
public class GPIGroup
{
    private GPIDifficulty difficulty; // filled OnEnable

    public List<GPISection> sections;

    public int currentWeight = 0;
    public int startWeight = 0;
    public int maximumWeight = 1;

    public int weightReductionOnSpawn = 1;
    public int weightIncrementationOnSpawn = 1;
}

[Serializable]
public class GPISection
{
    private GPIGroup group; // filled OnEnable

    public GameObject prefab;

    public string[] labels;

    public int currentWeight = 0;
    public int startWeight = 0;
    public int maximumWeight = 1;

    public int weightReductionOnSpawn = 1;
    public int weightIncrementationOnSpawn = 1;
}

I removed the methods because they are not important here.

Levelxxx items are for the track itself while the GPIxxx parts is for the stuff spawned on top of a track. We are working with a random-by-weight system.

Difficulties start are stop at specific spawn count and can overlap.
Each container may have dozen Difficulties.
Each difficulties may have dozen Groups.
And each group may have dozen Sections.
All and all, we may have hundred of nested objects. We did the test, and having no prefab referenced in the prefab field does not change the issue.

The labels field are there to flag on which track piece each GPI can spawn.
And yeah, at some point we may derive Groups and Sections from a common base class.

If the .asset is not loaded in an EditorWindow, the editor works fine.
If the .asset is being edited in the EditorWindow, the editor will take ages to start the game.

6

Hm, can’t find that folder.

Is that a Pro-only thing? Different for Mac/Win?

7

It’s not pro-only, and it’s the Windows path. The log file paths are in the manual.

All I can really suggest is that you convert your various Serializable subclasses into ScriptableObjects in their own right; that way instead of having one large 34kb data asset, you’ll have a bundle of smaller ones, and hopefully the simpler structure will eliminate the behaviour you’re seeing.

8

Come on, 34kb shouldn’t make the RAM bloat to 1Gb and the editor hang for over a minutes. We have lot of advantages in working that way and we used to have different ScriptableObject for each subclass.

9

But it does. So what are you going to do about it?

10

If you really wanted to find out what’s going on, you could try running a C++ profiler (such as Visual Studio’s profiling suite) while the editor is hanging, and look at the callstacks it provides - Unity ship symbols with their releases so you might get a callstack that gives you a clue as to what it’s choking on. I’ve diagnosed hangs in the engine in this way before.

11

That, is actually a very good idea.

12

Inspired by this thread I created a new project where I parse a few CSV files (11 files, approx. 70 KB overall), translate their entries into structs and then use a Update function to randomly grab data, print a bit of it using Debug.Log … And then see where RAM usage goes.

According to Mac OS X’s Activity Monitor, Unity consumes 180-190 MB of RAM when the scene starts (all in Editor). After a few minutes, maybe 16,000 Update cycles, RAM usage is at 250+ MB. The longer the scene runs, the more RAM is occupied. Pretty linear growth.

It doesn’t matter if the DatabaseLoader class is a MonoBehavior, ScriptableObject or a static class. Doesn’t matter if the CSV files are loaded via Resources.Load() or assigned as TextAssets in the inspector (to avoid Resources.Load()).

Unity 4.3.0, CustoMac, OS X.9.1. No Visual Studio profiler here.

Testing the same project folder on a MacBookPro 2007, Mac OS X.8.5, Unity 4.3.0 shows the scene at 140 MB RAM used at the start and 142 MB RAM used after approx. 20,000 Update cycles.

Is this normal?

13

The callstack - pretty much the only thing I manage to extract - looks like this;

>	mono.dll!calloc(unsigned int num, unsigned int size) Line 46	C
 	mono.dll!g_list_alloc(...) Line 35	C
 	mono.dll!new_node(_GList * prev, void * data, _GList * next) Line 42	C
 	mono.dll!g_list_prepend(_GList * list, void * data) Line 65	C
 	mono.dll!mono_custom_attrs_from_index(_MonoImage * image, unsigned int idx) Line 8279	C
 	mono.dll!mono_custom_attrs_from_field(_MonoClass * klass, _MonoClassField * field) Line 8451	C
 	Unity.exe!TransferScriptData<SafeBinaryRead>(TransferScriptInstance  info, SafeBinaryRead  transfer) Line 444	C++
 	Unity.exe!SafeBinaryRead::TransferWithTypeString<TransferScriptInstance>(TransferScriptInstance  data, const char * name, const char * typeName, TransferMetaFlags __formal) Line 246	C++
 	Unity.exe!TransferScriptData<SafeBinaryRead>(TransferScriptInstance  info, SafeBinaryRead  transfer) Line 636	C++
 	Unity.exe!SafeBinaryRead::TransferSTLStyleArray<TransferArrayScriptInstance>(TransferArrayScriptInstance  data, TransferMetaFlags __formal) Line 204	C++
 	Unity.exe!SafeBinaryRead::TransferWithTypeString<TransferArrayScriptInstance>(TransferArrayScriptInstance  data, const char * name, const char * typeName, TransferMetaFlags __formal) Line 264	C++
 	Unity.exe!TransferFieldOfTypeArray<SafeBinaryRead>(MonoObject * instance, MonoClass * klass, MonoClassField * field, const char * name, TransferScriptInstance  info, SafeBinaryRead  transfer, MonoType * monoType, int type, TransferMetaFlags metaFlags) Line 580	C++
 	Unity.exe!TransferScriptData<SafeBinaryRead>(TransferScriptInstance  info, SafeBinaryRead  transfer) Line 641	C++
 	Unity.exe!SafeBinaryRead::TransferWithTypeString<TransferScriptInstance>(TransferScriptInstance  data, const char * name, const char * typeName, TransferMetaFlags __formal) Line 246	C++
 	Unity.exe!TransferScriptData<SafeBinaryRead>(TransferScriptInstance  info, SafeBinaryRead  transfer) Line 636	C++
 	Unity.exe!SafeBinaryRead::TransferWithTypeString<TransferScriptInstance>(TransferScriptInstance  data, const char * name, const char * typeName, TransferMetaFlags __formal) Line 246	C++
 	Unity.exe!TransferScriptData<SafeBinaryRead>(TransferScriptInstance  info, SafeBinaryRead  transfer) Line 636	C++
 	Unity.exe!SafeBinaryRead::TransferSTLStyleArray<TransferArrayScriptInstance>(TransferArrayScriptInstance  data, TransferMetaFlags __formal) Line 204	C++
 	Unity.exe!SafeBinaryRead::TransferWithTypeString<TransferArrayScriptInstance>(TransferArrayScriptInstance  data, const char * name, const char * typeName, TransferMetaFlags __formal) Line 264	C++
 	Unity.exe!TransferFieldOfTypeArray<SafeBinaryRead>(MonoObject * instance, MonoClass * klass, MonoClassField * field, const char * name, TransferScriptInstance  info, SafeBinaryRead  transfer, MonoType * monoType, int type, TransferMetaFlags metaFlags) Line 580	C++
 	Unity.exe!TransferScriptData<SafeBinaryRead>(TransferScriptInstance  info, SafeBinaryRead  transfer) Line 641	C++
 	Unity.exe!SafeBinaryRead::TransferWithTypeString<TransferScriptInstance>(TransferScriptInstance  data, const char * name, const char * typeName, TransferMetaFlags __formal) Line 246	C++
 	Unity.exe!TransferScriptData<SafeBinaryRead>(TransferScriptInstance  info, SafeBinaryRead  transfer) Line 636	C++
 	Unity.exe!SafeBinaryRead::TransferSTLStyleArray<TransferArrayScriptInstance>(TransferArrayScriptInstance  data, TransferMetaFlags __formal) Line 204	C++
 	Unity.exe!SafeBinaryRead::TransferWithTypeString<TransferArrayScriptInstance>(TransferArrayScriptInstance  data, const char * name, const char * typeName, TransferMetaFlags __formal) Line 264	C++
 	Unity.exe!TransferFieldOfTypeArray<SafeBinaryRead>(MonoObject * instance, MonoClass * klass, MonoClassField * field, const char * name, TransferScriptInstance  info, SafeBinaryRead  transfer, MonoType * monoType, int type, TransferMetaFlags metaFlags) Line 580	C++
 	Unity.exe!TransferScriptData<SafeBinaryRead>(TransferScriptInstance  info, SafeBinaryRead  transfer) Line 641	C++
 	Unity.exe!MonoBehaviour::TransferWithInstance<SafeBinaryRead>(SafeBinaryRead  transfer, MonoObject * instance, MonoClass * klass) Line 720	C++
 	Unity.exe!MonoBehaviour::TransferSafeBinaryInstanceOnly(dynamic_array<unsigned char,1,53>  data, const TypeTree  typeTree, int options) Line 1150	C++
 	Unity.exe!MonoBehaviour::RestoreInstanceStateFromBackup(BackupState  backup, int flags) Line 1139	C++
 	Unity.exe!MonoManager::EndReloadAssembly(const DomainReloadingData  savedData, dynamic_bitset allAssembliesMask) Line 1348	C++
 	Unity.exe!MonoManager::ReloadAssembly(dynamic_bitset allAssembliesMask) Line 1115	C++
 	Unity.exe!ReloadAllUsedAssemblies() Line 976	C++
 	Unity.exe!Application::SetIsPlaying(bool isPlaying) Line 2435	C++
 	Unity.exe!Application::TickTimer() Line 1363	C++
 	Unity.exe!MainMessageLoop() Line 336	C++
 	Unity.exe!WinMain(HINSTANCE__ * hInst, HINSTANCE__ * hPrev, char * szCmdLine, int nCmdShow) Line 848	C++
 	Unity.exe!__tmainCRTStartup() Line 275	C
 	kernel32.dll!74e7336a()	Unknown
 	[Frames below may be incorrect and/or missing, no symbols loaded for kernel32.dll]	
 	ntdll.dll!77099f72()	Unknown
 	ntdll.dll!77099f45()	Unknown

It stays in that kind of recursive methods the whole time, often calling allocation method. The memory goes from 200Mb to about 1Gb over a minute of process. Really wonder why 34kb of data can make Unity loses its shit like that.

Frankly, I have no idea why Unity is doing any of that when I press play. I think it’s trying to transfer all the loaded data into C++ while it’s reloading the assemblies… But why is it taking so long and why is the memory bloating like that?

Screenshot of our editor; Imgur: The magic of the Internet

14

I’ve profiled Unity using Very Sleepy to get how long Unity stay in specific methods…

It appear to mostly follow two expensive path;

  • MonoBehaviour::ExtractBackupFromInstance : 26.39s
  • MonoManager::BeginReloadAssembly: 27.04s
  • MonoManager::ReloadAssembly : 80.52s
  • ReloadAllUsedAssmeblies : 80.52s - root call

And;

  • MonoBehaviour::TransferSafeBinaryInstanceOnly : 52.62s
  • MonoBehaviour::RestoreInstanceStateFromBackup : 52.62s
  • MonoManager::EndReloadAssembly : 53.47s
  • MonoManager::ReloadAssembly : 80.52s
  • ReloadAllUsedAssmeblies : 80.52s - root call

Here’s a longer list of the time spent in the different methods;

If only I could find what data is being processed and why…

15

When reloading assemblies, Unity serializes all loaded objects, then reloads the assemblies, then deserializes them again - this is what allows recompile-in-playmode to work. ExtractBackupFromInstance will be the serialise step, while RestoreInstanceStateFromBackup will be the deserialize.

Why they’re taking so long I’m not sure…

16

And like I said, it takes that long ONLY when an EditorWindow have a .asset loaded. The same EditorWindow can be opened, without data loaded, and Unity is fine (<1s startup). And if you do it a few times in a row, Unity may even crash when the RAM consumed get over 1.4-1.6Gb.

It’s very very strange, and somehow I think I got my feet caught in some kind of edge-case… Maybe people at Unity didn’t think people would make multiple nested object lists? Or they did, but never really tested that kind of 4+ levels depth case?

Before that, we had the same issue in reverse, when stopping the engine! It happened if our MonoBehaviour were to use directly the loaded ScriptableObject. If we loaded it, instantiated it and used the clone instead, and cut all reference to the original, it was all fine. If we used directly the loaded object, Unity would hang for minutes when we would stop the engine.

However, we did try the “clone” technique with the EditorWindow, and it didn’t solve our issue, sadly. Hell, it’s 34kb of data! Serializing that should be counted in milliseconds!

Frankly, it’s killing our designers’ productivity big time. Every tweak or change means minutes wasted.

17

Hey,

Could you please send a bug report and post the case number here? That way I can check it out as soon as possible.

Best wishes,
Ugnius
Unity QA Team

18

Sure, the case number if 593979

19

http://forum.unity3d.com/threads/233793-List-recursion-serialization-long

Similar to the above, but within a MonoBehaviour and on a Script reload.

20

The bug is still very much open and is still very much a problem - and a growing problem as our game development move forward and has more data input in it.

We would really like to know if someone has any kind of alternative?