4.3.4 - Hang on Play

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;

Code (csharp):

1.  
2. Mono: successfully reloaded assembly
3. - Completed reload, in  0.914 seconds
4. System memory in use before: 48.2 MB.
5. Unloading 149 Unused Serialized files (Serialized files now loaded: 0 / Dirty serialized files: 0)
6. System memory in use after: 34.8 MB.
7.  
8. Unloading 200 unused Assets to reduce memory usage. Loaded Objects now: 2195.
9. Total: 15.206539 ms (FindLiveObjects: 0.143984 ms CreateObjectMapping: 0.028978 ms MarkObjects: 2.562143 ms  DeleteObjects: 1.711516 ms)
10.  

Completed reload under 1 sec.

When the data structure is loaded in the EditorWindow;

Code (csharp):

1.  
2. Mono: successfully reloaded assembly
3. - Completed reload, in 77.812 seconds
4. System memory in use before: 48.3 MB.
5. Unloading 150 Unused Serialized files (Serialized files now loaded: 0 / Dirty serialized files: 0)
6. System memory in use after: 34.9 MB.
7.  
8. Unloading 200 unused Assets to reduce memory usage. Loaded Objects now: 2214.
9. Total: 1564.175171 ms (FindLiveObjects: 0.121949 ms CreateObjectMapping: 0.027468 ms MarkObjects: 1551.331177 ms  DeleteObjects: 1.980167 ms)
10.  

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!

 

BUMP!

 

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

 

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;

Code (csharp):

1.  
2. public class GeneratorContainer : ScriptableObject
3. {
4.     public List<LevelDifficulty> levelDifficulties;
5.  
6.     public List<GPIDifficulty> gpiDifficulties;
7. }
8.  
9. [Serializable]
10. public class LevelDifficulty
11. {
12.     public List<LevelGroup> groups;
13.  
14.     public bool skipped = false;
15.  
16.     public int start = 0;
17.     public int stop = 100;
18. }
19.  
20. [Serializable]
21. public class LevelGroup
22. {
23.     private LevelDifficulty difficulty; // filled OnEnable
24.  
25.     public List<LevelSection> sections;
26.  
27.     public int currentWeight = 0;
28.     public int startWeight = 0;
29.     public int maximumWeight = 1;
30.  
31.     public int weightReductionOnSpawn = 1;
32.     public int weightIncrementationOnSpawn = 1;
33. }
34.  
35. [Serializable]
36. public class LevelSection
37. {
38.     private LevelSection section; // filled OnEnable
39.  
40.     public GameObject prefab;
41.  
42.     public string label;
43.  
44.     public int currentWeight = 0;
45.     public int startWeight = 0;
46.     public int maximumWeight = 1;
47.  
48.     public int weightReductionOnSpawn = 1;
49.     public int weightIncrementationOnSpawn = 1;
50. }
51.  
52. [Serializable]
53. public class GPIDifficulty
54. {
55.     public List<GPIGroup> groups;
56.  
57.     public bool skipped = false;
58.  
59.     public int start = 0;
60.     public int stop = 100;
61. }
62.  
63. [Serializable]
64. public class GPIGroup
65. {
66.     private GPIDifficulty difficulty; // filled OnEnable
67.  
68.     public List<GPISection> sections;
69.  
70.     public int currentWeight = 0;
71.     public int startWeight = 0;
72.     public int maximumWeight = 1;
73.  
74.     public int weightReductionOnSpawn = 1;
75.     public int weightIncrementationOnSpawn = 1;
76. }
77.  
78. [Serializable]
79. public class GPISection
80. {
81.     private GPIGroup group; // filled OnEnable
82.  
83.     public GameObject prefab;
84.  
85.     public string[] labels;
86.  
87.     public int currentWeight = 0;
88.     public int startWeight = 0;
89.     public int maximumWeight = 1;
90.  
91.     public int weightReductionOnSpawn = 1;
92.     public int weightIncrementationOnSpawn = 1;
93. }
94.  

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.

 

Hm, can't find that folder.

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

 

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.

 

That, is actually a very good idea.

 

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?

 

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

Code (csharp):

1.  
2. >   mono.dll!calloc(unsigned int num, unsigned int size) Line 46    C
3.     mono.dll!g_list_alloc(...) Line 35  C
4.     mono.dll!new_node(_GList * prev, void * data, _GList * next) Line 42    C
5.     mono.dll!g_list_prepend(_GList * list, void * data) Line 65 C
6.     mono.dll!mono_custom_attrs_from_index(_MonoImage * image, unsigned int idx) Line 8279   C
7.     mono.dll!mono_custom_attrs_from_field(_MonoClass * klass, _MonoClassField * field) Line 8451    C
8.     Unity.exe!TransferScriptData<SafeBinaryRead>(TransferScriptInstance  info, SafeBinaryRead  transfer) Line 444   C++
9.     Unity.exe!SafeBinaryRead::TransferWithTypeString<TransferScriptInstance>(TransferScriptInstance  data, const char * name, const char * typeName, TransferMetaFlags __formal) Line 246   C++
10.     Unity.exe!TransferScriptData<SafeBinaryRead>(TransferScriptInstance  info, SafeBinaryRead  transfer) Line 636   C++
11.     Unity.exe!SafeBinaryRead::TransferSTLStyleArray<TransferArrayScriptInstance>(TransferArrayScriptInstance  data, TransferMetaFlags __formal) Line 204    C++
12.     Unity.exe!SafeBinaryRead::TransferWithTypeString<TransferArrayScriptInstance>(TransferArrayScriptInstance  data, const char * name, const char * typeName, TransferMetaFlags __formal) Line 264 C++
13.     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++
14.     Unity.exe!TransferScriptData<SafeBinaryRead>(TransferScriptInstance  info, SafeBinaryRead  transfer) Line 641   C++
15.     Unity.exe!SafeBinaryRead::TransferWithTypeString<TransferScriptInstance>(TransferScriptInstance  data, const char * name, const char * typeName, TransferMetaFlags __formal) Line 246   C++
16.     Unity.exe!TransferScriptData<SafeBinaryRead>(TransferScriptInstance  info, SafeBinaryRead  transfer) Line 636   C++
17.     Unity.exe!SafeBinaryRead::TransferWithTypeString<TransferScriptInstance>(TransferScriptInstance  data, const char * name, const char * typeName, TransferMetaFlags __formal) Line 246   C++
18.     Unity.exe!TransferScriptData<SafeBinaryRead>(TransferScriptInstance  info, SafeBinaryRead  transfer) Line 636   C++
19.     Unity.exe!SafeBinaryRead::TransferSTLStyleArray<TransferArrayScriptInstance>(TransferArrayScriptInstance  data, TransferMetaFlags __formal) Line 204    C++
20.     Unity.exe!SafeBinaryRead::TransferWithTypeString<TransferArrayScriptInstance>(TransferArrayScriptInstance  data, const char * name, const char * typeName, TransferMetaFlags __formal) Line 264 C++
21.     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++
22.     Unity.exe!TransferScriptData<SafeBinaryRead>(TransferScriptInstance  info, SafeBinaryRead  transfer) Line 641   C++
23.     Unity.exe!SafeBinaryRead::TransferWithTypeString<TransferScriptInstance>(TransferScriptInstance  data, const char * name, const char * typeName, TransferMetaFlags __formal) Line 246   C++
24.     Unity.exe!TransferScriptData<SafeBinaryRead>(TransferScriptInstance  info, SafeBinaryRead  transfer) Line 636   C++
25.     Unity.exe!SafeBinaryRead::TransferSTLStyleArray<TransferArrayScriptInstance>(TransferArrayScriptInstance  data, TransferMetaFlags __formal) Line 204    C++
26.     Unity.exe!SafeBinaryRead::TransferWithTypeString<TransferArrayScriptInstance>(TransferArrayScriptInstance  data, const char * name, const char * typeName, TransferMetaFlags __formal) Line 264 C++
27.     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++
28.     Unity.exe!TransferScriptData<SafeBinaryRead>(TransferScriptInstance  info, SafeBinaryRead  transfer) Line 641   C++
29.     Unity.exe!MonoBehaviour::TransferWithInstance<SafeBinaryRead>(SafeBinaryRead  transfer, MonoObject * instance, MonoClass * klass) Line 720  C++
30.     Unity.exe!MonoBehaviour::TransferSafeBinaryInstanceOnly(dynamic_array<unsigned char,1,53>  data, const TypeTree  typeTree, int options) Line 1150   C++
31.     Unity.exe!MonoBehaviour::RestoreInstanceStateFromBackup(BackupState  backup, int flags) Line 1139   C++
32.     Unity.exe!MonoManager::EndReloadAssembly(const DomainReloadingData  savedData, dynamic_bitset allAssembliesMask) Line 1348  C++
33.     Unity.exe!MonoManager::ReloadAssembly(dynamic_bitset allAssembliesMask) Line 1115   C++
34.     Unity.exe!ReloadAllUsedAssemblies() Line 976    C++
35.     Unity.exe!Application::SetIsPlaying(bool isPlaying) Line 2435   C++
36.     Unity.exe!Application::TickTimer() Line 1363    C++
37.     Unity.exe!MainMessageLoop() Line 336    C++
38.     Unity.exe!WinMain(HINSTANCE__ * hInst, HINSTANCE__ * hPrev, char * szCmdLine, int nCmdShow) Line 848    C++
39.     Unity.exe!__tmainCRTStartup() Line 275  C
40.     kernel32.dll!74e7336a() Unknown
41.     [Frames below may be incorrect and/or missing, no symbols loaded for kernel32.dll] 
42.     ntdll.dll!77099f72()    Unknown
43.     ntdll.dll!77099f45()    Unknown
44.  

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 S*** 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; http://i.imgur.com/5Vz1oln.png

 

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;

http://i.imgur.com/9CKZQsH.png

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

 

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.

 

Sure, the case number if 593979

 

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

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

 

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?

 

Same here, we have multiple bundles loaded at runtime and the longer we work, the worse it gets, the editor get to a 1.6+ GB memory consumption never releasing any of its ressources, we are at 4.3.4.

There is also serious lag when selecting custom asset files in the editor. A HP Pavillion i3 4GB ram with a standard shader 3 card with 1GB ram has a really hard time working in a game that runs fine and fast on a Nexus 5 tablet, this is really an Editor serialization problem, if your interested, we can send you our entire code base which hovers around 800MB for testing.

 

Only if you have a solution in your code... Otherwise, our own code is just fine for me to experience the issue.

 

If you have the same issue, we found out that flagging private field that could offer cyclic referencing this way;

Code (csharp):

1.  
2.     private Parent parent;
3.  

to;

Code (csharp):

1.  
2.     [NonSerialized]
3.     private Parent parent;
4.  

Actually solves the hang time. The serialization behaviour doesn't change, but obviously the editor appear to prefer to be explicitly told about it.