2018.3: Initialization message in the console is constantly being shown

[shana]

Unity case #1113071

The initialization message in the console is constantly being shown, instead of only showing up once when Unity first starts up. It looks like the ApplicationCache object that keeps the "is this our first load in this Unity session" state is being recreated over and over again, so we always think that this is a first run.

This is also having the side effect of rotating the logs every time the domain reloads, resetting all the metrics, and any other actions we usually only take when a Unity session first starts up. This miiight also be the cause for some weird crashes that we've had reports on.

This is only happening on 2018.3. I've tracked down the problem to a change in the way Unity is initializing custom attributes, specifically the ones that we have in our cache objects to mark where the cache file should be saved.

Before, the custom attribute would be initialized whenever we called GetCustomAttributes ourselves in https://github.com/github-for-unity/Unity/blob/master/src/UnityExtension/Assets/Editor/GitHub.Unity/ScriptObjectSingleton.cs#L95

In 2018.3 it looks like Unity is eagerly creating instances of any custom attributes it finds very early in the project loading phase, before anything else is running. In our LocationAttribute constructor we reference the environment cache object (EntryPoint.ApplicationManager.Environment). This causes the singleton to be created, but Unity is creating a broken object with missing internal data, and then it tries to create it again, and again, and again... we end up with multiple managed instances of the same broken native object, and end up with duplicate information. This is happening with singletons that are not backed by a physical file and only live in memory (so they never go through InternalEditorUtility.LoadSerializedFileAndForget).

The workaround is move the logic out of the attribute constructor and into a property, so it doesn't run at this early time that is causing things to break.

2018.3 first time it calls the constructor on the EnvironmentCache object

Singleton constructor called GitHub.Unity.EnvironmentCache
0x00000001414122F8 (Unity) StackWalker::GetCurrentCallstack
0x00000001414187A6 (Unity) StackWalker::ShowCallstack
0x00000001412FC02B (Unity) GetStacktrace
0x00000001401432FE (Unity) DebugStringToFile
0x000000014178451D (Unity) DebugLogHandler_CUSTOM_Internal_Log
0x00000000456009B0 (Mono JIT Code) (wrapper managed-to-native) UnityEngine.DebugLogHandler:Internal_Log (UnityEngine.LogType,string,UnityEngine.Object)
0x000000004660FDA3 (Mono JIT Code) [DebugLogHandler.cs:10] UnityEngine.DebugLogHandler:LogFormat (UnityEngine.LogType,UnityEngine.Object,string,object[]) 
0x00000000465EFCA2 (Mono JIT Code) [Logger.cs:114] UnityEngine.Logger:LogFormat (UnityEngine.LogType,string,object[]) 
0x00000000465EF475 (Mono JIT Code) [Debug.bindings.cs:109] UnityEngine.Debug:LogFormat (string,object[]) 
0x0000000045604B4B (Mono JIT Code) [ScriptObjectSingleton.cs:49] GitHub.Unity.ScriptObjectSingleton`1<T_REF>:.ctor () 
0x0000000045604693 (Mono JIT Code) GitHub.Unity.EnvironmentCache:.ctor ()
0x0000000045604848 (Mono JIT Code) (wrapper runtime-invoke) object:runtime_invoke_void__this__ (object,intptr,intptr,intptr)
0x00007FFDDEE4BE4B (mono-2.0-bdwgc) [mini-runtime.c:2809] mono_jit_runtime_invoke 
0x00007FFDDEDD1E32 (mono-2.0-bdwgc) [object.c:2919] do_runtime_invoke 
0x00007FFDDEDDAE3F (mono-2.0-bdwgc) [object.c:2966] mono_runtime_invoke 
0x0000000140BE1557 (Unity) mono_runtime_object_init_exception
0x0000000140C01F46 (Unity) scripting_unity_engine_object_new_and_invoke_default_constructor
0x0000000140C449BE (Unity) SerializableManagedRef::RebuildMonoInstance
0x0000000140C44B60 (Unity) SerializableManagedRef::RebuildMonoInstanceFromScriptChange

CALLED ONCE ----> 0x0000000140BC3993 (Unity) ManagedMonoBehaviourRef::RebuildMonoInstanceFromScriptChange

0x0000000140C4529D (Unity) SerializableManagedRef::SetClass
0x0000000140BEFA03 (Unity) Scripting::CreateScriptableObjectWithType
0x000000014180790B (Unity) ScriptableObject_CUSTOM_CreateScriptableObjectInstanceFromType

0x000000004560453E (Mono JIT Code) (wrapper managed-to-native) UnityEngine.ScriptableObject:CreateScriptableObjectInstanceFromType (System.Type)
0x0000000045604403 (Mono JIT Code) [ScriptableObject.bindings.cs:34] UnityEngine.ScriptableObject:CreateInstance (System.Type) 
0x00000000456042C3 (Mono JIT Code) [ScriptableObject.bindings.cs:40] UnityEngine.ScriptableObject:CreateInstance<T_REF> () 
0x0000000045600F33 (Mono JIT Code) [ScriptObjectSingleton.cs:75] GitHub.Unity.ScriptObjectSingleton`1<T_REF>:CreateAndLoad () 
0x00000000465EF313 (Mono JIT Code) [ScriptObjectSingleton.cs:41] GitHub.Unity.ScriptObjectSingleton`1<T_REF>:get_Instance () 
0x000000004660C5D3 (Mono JIT Code) [EntryPoint.cs:92] GitHub.Unity.EntryPoint:get_ApplicationManager () 
0x000000004660BBCB (Mono JIT Code) [ScriptObjectSingleton.cs:26] GitHub.Unity.LocationAttribute:.ctor (string,GitHub.Unity.LocationAttribute/Location) 
0x000000004660C05C (Mono JIT Code) (wrapper runtime-invoke) <Module>:runtime_invoke_void__this___object_int (object,intptr,intptr,intptr)
0x00007FFDDEE4BE4B (mono-2.0-bdwgc) [mini-runtime.c:2809] mono_jit_runtime_invoke 
0x00007FFDDEDD1E32 (mono-2.0-bdwgc) [object.c:2919] do_runtime_invoke 
0x00007FFDDEE2C673 (mono-2.0-bdwgc) [custom-attrs.c:780] create_custom_attr 
0x00007FFDDEE2E704 (mono-2.0-bdwgc) [custom-attrs.c:1233] mono_custom_attrs_construct_by_type 
0x00007FFDDEE2FF69 (mono-2.0-bdwgc) [custom-attrs.c:1907] mono_reflection_get_custom_attrs_by_type_handle 
0x0000000046602E05 (Mono JIT Code) (wrapper managed-to-native) System.MonoCustomAttrs:GetCustomAttributesInternal (System.Reflection.ICustomAttributeProvider,System.Type,bool)
0x0000000046602613 (Mono JIT Code) System.MonoCustomAttrs:GetCustomAttributesBase (System.Reflection.ICustomAttributeProvider,System.Type,bool)
0x00000000466002BB (Mono JIT Code) System.MonoCustomAttrs:GetCustomAttributes (System.Reflection.ICustomAttributeProvider,System.Type,bool)
0x00000000431EFE53 (Mono JIT Code) System.RuntimeType:GetCustomAttributes (bool)
0x000000004313FD30 (Mono JIT Code) [AttributeHelperEngine.cs:122] UnityEngine.AttributeHelperEngine:GetExecuteMode (System.Type) 
0x000000004313F70B (Mono JIT Code) [AttributeHelperEngine.cs:140] UnityEngine.AttributeHelperEngine:CheckIsEditorScript (System.Type) 
0x000000004313FA0B (Mono JIT Code) (wrapper runtime-invoke) <Module>:runtime_invoke_int_object (object,intptr,intptr,intptr)
0x00007FFDDEE4BE4B (mono-2.0-bdwgc) [mini-runtime.c:2809] mono_jit_runtime_invoke 
0x00007FFDDEDD1E32 (mono-2.0-bdwgc) [object.c:2919] do_runtime_invoke 
0x00007FFDDEDDAE3F (mono-2.0-bdwgc) [object.c:2966] mono_runtime_invoke 
0x0000000140C00F2A (Unity) scripting_method_invoke
0x0000000140BF14FA (Unity) ScriptingInvocation::Invoke
0x0000000140BEB40A (Unity) ScriptingInvocation::Invoke<int>
0x0000000140BE5819 (Unity) ManagedAttributeManager::CheckIsEditorScript
0x0000000140BD3F58 (Unity) CreateMonoScriptCache
0x0000000140BD5783 (Unity) FindOrCreateMonoScriptCache
0x0000000140BDDE1D (Unity) MonoScript::Renew
0x0000000140BD4426 (Unity) MonoManager::EndReloadAssembly
0x0000000140BDDB04 (Unity) MonoManager::ReloadAssembly
0x0000000140E7C0C9 (Unity) LoadDomainAndUserAssemblies
0x0000000140E7C6A9 (Unity) LoadMonoAssembliesAndRecompileIfNecessary
0x000000014132F911 (Unity) Application::InitializeProject
0x0000000141496E45 (Unity) WinMain
0x000000014247897A (Unity) __scrt_common_main_seh
0x00007FFE285D3034 (KERNEL32) BaseThreadInitThunk
0x00007FFE293C3691 (ntdll) RtlUserThreadStart

2018.3 second time it calls the constructor on the EnvironmentCache object

Singleton constructor called GitHub.Unity.EnvironmentCache
0x00000001414122F8 (Unity) StackWalker::GetCurrentCallstack
0x00000001414187A6 (Unity) StackWalker::ShowCallstack
0x00000001412FC02B (Unity) GetStacktrace
0x00000001401432FE (Unity) DebugStringToFile
0x000000014178451D (Unity) DebugLogHandler_CUSTOM_Internal_Log
0x00000000456009B0 (Mono JIT Code) (wrapper managed-to-native) UnityEngine.DebugLogHandler:Internal_Log (UnityEngine.LogType,string,UnityEngine.Object)
0x000000004660FDA3 (Mono JIT Code) [DebugLogHandler.cs:10] UnityEngine.DebugLogHandler:LogFormat (UnityEngine.LogType,UnityEngine.Object,string,object[]) 
0x00000000465EFCA2 (Mono JIT Code) [Logger.cs:114] UnityEngine.Logger:LogFormat (UnityEngine.LogType,string,object[]) 
0x00000000465EF475 (Mono JIT Code) [Debug.bindings.cs:109] UnityEngine.Debug:LogFormat (string,object[]) 
0x0000000045604B4B (Mono JIT Code) [ScriptObjectSingleton.cs:49] GitHub.Unity.ScriptObjectSingleton`1<T_REF>:.ctor () 
0x0000000045604693 (Mono JIT Code) GitHub.Unity.EnvironmentCache:.ctor ()
0x0000000045604848 (Mono JIT Code) (wrapper runtime-invoke) object:runtime_invoke_void__this__ (object,intptr,intptr,intptr)
0x00007FFDDEE4BE4B (mono-2.0-bdwgc) [mini-runtime.c:2809] mono_jit_runtime_invoke 
0x00007FFDDEDD1E32 (mono-2.0-bdwgc) [object.c:2919] do_runtime_invoke 
0x00007FFDDEDDAE3F (mono-2.0-bdwgc) [object.c:2966] mono_runtime_invoke 
0x0000000140BE1557 (Unity) mono_runtime_object_init_exception
0x0000000140C01F46 (Unity) scripting_unity_engine_object_new_and_invoke_default_constructor
0x0000000140C449BE (Unity) SerializableManagedRef::RebuildMonoInstance
0x0000000140C44B60 (Unity) SerializableManagedRef::RebuildMonoInstanceFromScriptChange

WHY U CALLED TWICE FOR THE SAME SINGLETON ---> 0x0000000140BC3993 (Unity) ManagedMonoBehaviourRef::RebuildMonoInstanceFromScriptChange

0x0000000140C453C0 (Unity) SerializableManagedRef::SetEditorClassIdentifier
0x0000000140BF5935 (Unity) Scripting::SetupScriptableObject
0x0000000140BEFA0B (Unity) Scripting::CreateScriptableObjectWithType

0x000000014180790B (Unity) ScriptableObject_CUSTOM_CreateScriptableObjectInstanceFromType
0x000000004560453E (Mono JIT Code) (wrapper managed-to-native) UnityEngine.ScriptableObject:CreateScriptableObjectInstanceFromType (System.Type)
0x0000000045604403 (Mono JIT Code) [ScriptableObject.bindings.cs:34] UnityEngine.ScriptableObject:CreateInstance (System.Type) 
0x00000000456042C3 (Mono JIT Code) [ScriptableObject.bindings.cs:40] UnityEngine.ScriptableObject:CreateInstance<T_REF> () 
0x0000000045600F33 (Mono JIT Code) [ScriptObjectSingleton.cs:75] GitHub.Unity.ScriptObjectSingleton`1<T_REF>:CreateAndLoad () 
0x00000000465EF313 (Mono JIT Code) [ScriptObjectSingleton.cs:41] GitHub.Unity.ScriptObjectSingleton`1<T_REF>:get_Instance () 
0x000000004660C5D3 (Mono JIT Code) [EntryPoint.cs:92] GitHub.Unity.EntryPoint:get_ApplicationManager () 
0x000000004660BBCB (Mono JIT Code) [ScriptObjectSingleton.cs:26] GitHub.Unity.LocationAttribute:.ctor (string,GitHub.Unity.LocationAttribute/Location) 
0x000000004660C05C (Mono JIT Code) (wrapper runtime-invoke) <Module>:runtime_invoke_void__this___object_int (object,intptr,intptr,intptr)
0x00007FFDDEE4BE4B (mono-2.0-bdwgc) [mini-runtime.c:2809] mono_jit_runtime_invoke 
0x00007FFDDEDD1E32 (mono-2.0-bdwgc) [object.c:2919] do_runtime_invoke 
0x00007FFDDEE2C673 (mono-2.0-bdwgc) [custom-attrs.c:780] create_custom_attr 
0x00007FFDDEE2E704 (mono-2.0-bdwgc) [custom-attrs.c:1233] mono_custom_attrs_construct_by_type 
0x00007FFDDEE2FF69 (mono-2.0-bdwgc) [custom-attrs.c:1907] mono_reflection_get_custom_attrs_by_type_handle 
0x0000000046602E05 (Mono JIT Code) (wrapper managed-to-native) System.MonoCustomAttrs:GetCustomAttributesInternal (System.Reflection.ICustomAttributeProvider,System.Type,bool)
0x0000000046602613 (Mono JIT Code) System.MonoCustomAttrs:GetCustomAttributesBase (System.Reflection.ICustomAttributeProvider,System.Type,bool)
0x00000000466002BB (Mono JIT Code) System.MonoCustomAttrs:GetCustomAttributes (System.Reflection.ICustomAttributeProvider,System.Type,bool)
0x00000000431EFE53 (Mono JIT Code) System.RuntimeType:GetCustomAttributes (bool)
0x000000004313FD30 (Mono JIT Code) [AttributeHelperEngine.cs:122] UnityEngine.AttributeHelperEngine:GetExecuteMode (System.Type) 
0x000000004313F70B (Mono JIT Code) [AttributeHelperEngine.cs:140] UnityEngine.AttributeHelperEngine:CheckIsEditorScript (System.Type) 
0x000000004313FA0B (Mono JIT Code) (wrapper runtime-invoke) <Module>:runtime_invoke_int_object (object,intptr,intptr,intptr)
0x00007FFDDEE4BE4B (mono-2.0-bdwgc) [mini-runtime.c:2809] mono_jit_runtime_invoke 
0x00007FFDDEDD1E32 (mono-2.0-bdwgc) [object.c:2919] do_runtime_invoke 
0x00007FFDDEDDAE3F (mono-2.0-bdwgc) [object.c:2966] mono_runtime_invoke 
0x0000000140C00F2A (Unity) scripting_method_invoke
0x0000000140BF14FA (Unity) ScriptingInvocation::Invoke
0x0000000140BEB40A (Unity) ScriptingInvocation::Invoke<int>
0x0000000140BE5819 (Unity) ManagedAttributeManager::CheckIsEditorScript
0x0000000140BD3F58 (Unity) CreateMonoScriptCache
0x0000000140BD5783 (Unity) FindOrCreateMonoScriptCache
0x0000000140BDDE1D (Unity) MonoScript::Renew
0x0000000140BD4426 (Unity) MonoManager::EndReloadAssembly
0x0000000140BDDB04 (Unity) MonoManager::ReloadAssembly
0x0000000140E7C0C9 (Unity) LoadDomainAndUserAssemblies
0x0000000140E7C6A9 (Unity) LoadMonoAssembliesAndRecompileIfNecessary
0x000000014132F911 (Unity) Application::InitializeProject
0x0000000141496E45 (Unity) WinMain
0x000000014247897A (Unity) __scrt_common_main_seh
0x00007FFE285D3034 (KERNEL32) BaseThreadInitThunk
0x00007FFE293C3691 (ntdll) RtlUserThreadStart