Bug Unity 2022.3.20 freezes during startup in batch mode before executing app code

We have a build system that starts up build machines on demand and launches Unity in batch mode to make builds. Since updating from Unity 2022.3.5 up to Unity 2022.3.20, builds will occasionally hang indefinitely during startup, before reaching any app code. It's not every build, but fairly frequently. I would say around 25% of the time. Unity is launched using a command line similar to this:

/var/lib/unity/2022.3.20f1/Editor/Unity -batchmode -EnableCacheServer

-cacheServerEndpoint X.X.X.X:8443 -cacheServerEnableDownload true

-cacheServerEnableUpload true -nographics -buildTarget Android

-projectPath /data/unity/apps/XXXX -executeMethod Util.Editor.StartBuild.StartBuildFromCommandLine

-logLevel INFO -logFile -

This will begin executing, but freeze before reaching the StartBuildFromCommandLine method. It appears to be freezing during or after static initializers from classes with [InitializeOnLoad] attributes, or possibly during asset database refreshing. For example, one build's log ended with:

12:21:56   AssetDatabase: script compilation time: 51.437220s

12:21:56   [Licensing::Client] Successfully resolved entitlements

12:21:56   Begin MonoManager ReloadAssembly

12:21:56   Symbol file LoadedFromMemory doesn't match image /data/unity/apps/XXXX/Assets/Firebase/Plugins/Firebase.Messaging.dll

12:21:56   Symbol file LoadedFromMemory doesn't match image /data/unity/apps/XXXX/Assets/Firebase/Plugins/Firebase.Analytics.dll

12:21:56   Symbol file LoadedFromMemory doesn't match image /data/unity/apps/XXXX/Assets/Firebase/Plugins/Firebase.App.dll

12:21:56   Symbol file LoadedFromMemory doesn't match image /data/unity/apps/XXXX/Assets/Firebase/Plugins/Firebase.RemoteConfig.dll

12:21:56   Symbol file LoadedFromMemory doesn't match image /data/unity/apps/XXXX/Assets/Firebase/Editor/Firebase.Messaging.Editor.dll

12:21:56   Symbol file LoadedFromMemory doesn't match image /data/unity/apps/XXXX/Assets/Firebase/Plugins/Firebase.TaskExtension.dll

12:21:56   Symbol file LoadedFromMemory doesn't match image /data/unity/apps/XXXX/Assets/Firebase/Plugins/Firebase.Installations.dll

12:21:56   Symbol file LoadedFromMemory doesn't match image /data/unity/apps/XXXX/Assets/Firebase/Plugins/Firebase.Auth.dll

12:21:56   Symbol file LoadedFromMemory doesn't match image /data/unity/apps/XXXX/Assets/Firebase/Editor/Firebase.Crashlytics.Editor.dll

12:21:56   Symbol file LoadedFromMemory doesn't match image /data/unity/apps/XXXX/Assets/Firebase/Plugins/Firebase.Crashlytics.dll

12:21:56   Symbol file LoadedFromMemory is not a mono symbol file

12:21:56   Symbol file LoadedFromMemory doesn't match image /data/unity/apps/XXXX/Assets/Firebase/Plugins/Firebase.Platform.dll

12:21:56   Symbol file LoadedFromMemory doesn't match image /data/unity/apps/XXXX/Assets/Firebase/Editor/Firebase.Editor.dll

12:21:56   - Loaded All Assemblies, in  4.547 seconds

12:21:56   Refreshing native plugins compatible for Editor in 25.63 ms, found 7 plugins.

12:21:56   Preloading 0 native plugins for Editor in 0.00 ms.

12:21:56   Start importing ProjectSettings/ProjectSettings.asset using Guid(00000000000000004000000000000000) Importer(-1,00000000000000000000000000000000)  -> (artifact id: '624fe24d61a3fc9ba27872fe8ee91610') in 0.029375 seconds

12:21:56   Querying for cacheable assets in Cache Server:

12:21:56     e00be4d46daad493da678cdbf02095b0:Assets/Scripts/AppCode/Editor/UnitTests/Network/Duels/BalrogDuelServiceTest.cs

12:21:56     c95eddeb60ff48caaae2b03992ce2187:Assets/Scripts/Rebar/scripts/Editor/UnitTests/Mixer/Guilds/Service/GuildServiceTest.cs

12:21:56   Start importing Assets/Scripts/AppCode/Editor/UnitTests/Network/Duels/BalrogDuelServiceTest.cs using Guid(e00be4d46daad493da678cdbf02095b0) Importer(-1,00000000000000000000000000000000)  -> (artifact id: 'f5144db144edb48ec39602fcdf4de7ee') in 0.002689 seconds

12:21:56   Start importing Assets/Scripts/Rebar/scripts/Editor/UnitTests/Mixer/Guilds/Service/GuildServiceTest.cs using Guid(c95eddeb60ff48caaae2b03992ce2187) Importer(-1,00000000000000000000000000000000)  -> (artifact id: '17ffd69caa5744665179fd0a601bfd89') in 0.001474 seconds

12:21:56   Refreshing native plugins compatible for Editor in 28.93 ms, found 7 plugins.

12:21:56   Native extension for LinuxStandalone target not found

12:21:56   Native extension for iOS target not found

12:21:56   Native extension for Android target not found

12:21:56   [Licensing::Client] Successfully resolved entitlements

12:21:56   Generated Firebase Android Resources file Assets/Plugins/Android/FirebaseApp.androidlib/res/values/google-services.xml from /data/unity/apps/XXXX/Assets/../Assets/Plugins/Android/Firebase/google-services.json

12:21:56   

12:21:56   Executed "python3" "/data/unity/apps/XXXX/Assets/Firebase/Editor/generate_xml_from_google_services_json.py" -i "/data/unity/apps/XXXX/Assets/../Assets/Plugins/Android/Firebase/google-services.json" -o "/data/unity/apps/XXXX/Assets/../Assets/Plugins/Android/FirebaseApp.androidlib/res/values/google-services.xml" -p "com.xxx.yyy"

12:21:56   UnityEngine.StackTraceUtility:ExtractStackTrace () (at /home/bokken/build/output/unity/unity/Runtime/Export/Scripting/StackTrace.cs:37)

12:21:56   UnityEngine.DebugLogHandler:LogFormat (UnityEngine.LogType,UnityEngine.Object,string,object[])

12:21:56   UnityEngine.Logger:Log (UnityEngine.LogType,object)

12:21:56   UnityEngine.Debug:Log (object)

12:21:56   Firebase.Editor.GenerateXmlFromGoogleServicesJson:RunResourceGenerator (System.Collections.Generic.IEnumerable`1<string>,string,bool)

12:21:56   Firebase.Editor.GenerateXmlFromGoogleServicesJson:GenerateXmlResources (string,bool)

12:21:56   Firebase.Editor.GenerateXmlFromGoogleServicesJson:UpdateJson (bool,Firebase.Editor.GenerateXmlFromGoogleServicesJson/LogMessage,Firebase.Editor.GenerateXmlFromGoogleServicesJson/LogMessage)

12:21:56   Firebase.Editor.GenerateXmlFromGoogleServicesJson:UpdateJsonWithBundleIdChooserDialog (string,bool)

12:21:56   Firebase.Editor.GenerateXmlFromGoogleServicesJson:CheckConfiguration ()

12:21:56   Firebase.Editor.GenerateXmlFromGoogleServicesJson/<>c:<.cctor>b__15_1 ()

12:21:56   Google.EditorInitializer/<InitializeOnMainThread>c__AnonStorey1:<>m__2 () (at /Users/chkuang/Workspace/git/unity-jar-resolver/source/VersionHandlerImpl/src/EditorInitializer.cs:60)

12:21:56   Google.RunOnMainThread:ExecutePollingJobs () (at /Users/chkuang/Workspace/git/unity-jar-resolver/source/VersionHandlerImpl/src/RunOnMainThread.cs:409)

12:21:56   Google.RunOnMainThread:<ExecuteAllUnnested>m__12 () (at /Users/chkuang/Workspace/git/unity-jar-resolver/source/VersionHandlerImpl/src/RunOnMainThread.cs:541)

12:21:56   Google.RunOnMainThread:RunAction (System.Action) (at /Users/chkuang/Workspace/git/unity-jar-resolver/source/VersionHandlerImpl/src/RunOnMainThread.cs:343)

12:21:56   Google.RunOnMainThread:ExecuteAllUnnested (bool) (at /Users/chkuang/Workspace/git/unity-jar-resolver/source/VersionHandlerImpl/src/RunOnMainThread.cs:530)

12:21:56   Google.RunOnMainThread:<PollOnUpdateUntilComplete>m__11 () (at /Users/chkuang/Workspace/git/unity-jar-resolver/source/VersionHandlerImpl/src/RunOnMainThread.cs:365)

12:21:56   Google.RunOnMainThread:RunAction (System.Action) (at /Users/chkuang/Workspace/git/unity-jar-resolver/source/VersionHandlerImpl/src/RunOnMainThread.cs:343)

12:21:56   Google.RunOnMainThread:PollOnUpdateUntilComplete (System.Func`1<bool>,bool) (at /Users/chkuang/Workspace/git/unity-jar-resolver/source/VersionHandlerImpl/src/RunOnMainThread.cs:363)

12:21:56   Google.EditorInitializer:InitializeOnMainThread (System.Func`1<bool>,System.Func`1<bool>,string,Google.Logger) (at /Users/chkuang/Workspace/git/unity-jar-resolver/source/VersionHandlerImpl/src/EditorInitializer.cs:48)

12:21:56   Firebase.Editor.GenerateXmlFromGoogleServicesJson:.cctor ()

12:21:56   System.Runtime.CompilerServices.RuntimeHelpers:RunClassConstructor (System.RuntimeTypeHandle)

12:21:56   UnityEditor.EditorAssemblies:ProcessInitializeOnLoadAttributes (System.Type[]) (at /home/bokken/build/output/unity/unity/Editor/Mono/EditorAssemblies.cs:119)

12:21:56   

12:21:56   (Filename: /Users/chkuang/Workspace/git/unity-jar-resolver/source/VersionHandlerImpl/src/EditorInitializer.cs Line: 60)

12:21:56   

12:21:56   [Licensing::Client] Successfully resolved entitlements

12:21:56   GPGSUpgrader start

12:21:56   UnityEngine.StackTraceUtility:ExtractStackTrace () (at /home/bokken/build/output/unity/unity/Runtime/Export/Scripting/StackTrace.cs:37)

12:21:56   UnityEngine.DebugLogHandler:LogFormat (UnityEngine.LogType,UnityEngine.Object,string,object[])

12:21:56   UnityEngine.Logger:Log (UnityEngine.LogType,object)

12:21:56   UnityEngine.Debug:Log (object)

12:21:56   GooglePlayGames.Editor.GPGSUpgrader:.cctor () (at Assets/GooglePlayGames/com.google.play.games/Editor/GPGSUpgrader.cs:38)

12:21:56   System.Runtime.CompilerServices.RuntimeHelpers:RunClassConstructor (System.RuntimeTypeHandle)

12:21:56   UnityEditor.EditorAssemblies:ProcessInitializeOnLoadAttributes (System.Type[]) (at /home/bokken/build/output/unity/unity/Editor/Mono/EditorAssemblies.cs:119)

12:21:56   

12:21:56   (Filename: Assets/GooglePlayGames/com.google.play.games/Editor/GPGSUpgrader.cs Line: 38)

12:21:56   

12:21:56   GPGSUpgrader done

12:21:56   UnityEngine.StackTraceUtility:ExtractStackTrace () (at /home/bokken/build/output/unity/unity/Runtime/Export/Scripting/StackTrace.cs:37)

12:21:56   UnityEngine.DebugLogHandler:LogFormat (UnityEngine.LogType,UnityEngine.Object,string,object[])

12:21:56   UnityEngine.Logger:Log (UnityEngine.LogType,object)

12:21:56   UnityEngine.Debug:Log (object)

12:21:56   GooglePlayGames.Editor.GPGSUpgrader:.cctor () (at Assets/GooglePlayGames/com.google.play.games/Editor/GPGSUpgrader.cs:57)

GPGSUpgrader is an [InitializeOnLoad] class, and GPGSUpgrade done is printed at the end of the static initializer.

Another build stops here:

12:26:15       SetupLoadedEditorAssemblies (9287ms)

12:26:15         LogAssemblyErrors (0ms)

12:26:15         InitializePlatformSupportModulesInManaged (48ms)

12:26:15         SetLoadedEditorAssemblies (6ms)

12:26:15         RefreshPlugins (0ms)

12:26:15         BeforeProcessingInitializeOnLoad (163ms)

12:26:15         ProcessInitializeOnLoadAttributes (8438ms)

12:26:15         ProcessInitializeOnLoadMethodAttributes (624ms)

12:26:15         AfterProcessingInitializeOnLoad (7ms)

12:26:15         EditorAssembliesLoaded (1ms)

12:26:15       ExecutionOrderSort2 (0ms)

12:26:15       AwakeInstancesAfterBackupRestoration (5ms)

12:26:15   Start importing Assets/StreamingAssets/google-services-desktop.json using Guid(d62d85df804666281bd5b9c6bc440573) Importer(-1,00000000000000000000000000000000)  -> (artifact id: 'b31f570dd09255f8d4d46c054a645ed6') in 0.004060 seconds

12:26:15   Querying for cacheable assets in Cache Server:

12:26:15     5ec4e657d49eb40049ab19c95eb10195:Assets/XXX1.png

12:26:15   Artifact(content hash=4dcd60533c0a3fe99320c16c0f3501bb) downloaded for 'Assets/XXXX.png'

12:26:15   Querying for cacheable assets in Cache Server:

12:26:15     64da01ea55fe44ddea514d143f6e7531:Assets/XXX2.asset

12:26:15     b81f142c875fa4958902f22b0c38eb34:Assets/XXX3.asset

12:26:15   Artifact(content hash=8a08c766c149aa5e93ffc25894e2d697) downloaded for 'Assets/XXX2.asset'

12:26:15   Querying for cacheable assets in Cache Server:

12:26:15     2187ac96e82bc4061a898d7e92035046:Assets/XXX4.prefab

12:26:15   Artifact(content hash=9d1d8cbc3f3031e80b1ee39cb28f8bef) downloaded for 'XXX4.prefab'

12:26:15   Shader Hidden/ProbeVolume/VoxelizeScene is not supported: GPU does not support conservative rasterization

12:26:15   [Licensing::Client] Successfully resolved entitlements

12:26:15   Refreshing native plugins compatible for Editor in 32.21 ms, found 7 plugins.

12:26:15   Preloading 0 native plugins for Editor in 0.00 ms.

12:26:15   Asset Pipeline Refresh (id=867d165de0331de74b022e6637e273d2): Total: 67.150 seconds - Initiated by InitialRefreshV2(ForceSynchronousImport)

12:26:15     Summary:

12:26:15       Imports: total=12 (actual=2, local cache=0, cache server=10)

12:26:15       Asset DB Process Time: managed=8 ms, native=13867 ms

12:26:15       Asset DB Callback time: managed=553 ms, native=358 ms

I could come up with more examples. They all freeze before the -executeMethod from the command line is ever started, and it appears to mostly be very shortly before it would execute, based on successful runs. There are never any exceptions printed to the console.

This issue did not exist in Unity 2022.3.5.

Has anybody else seen this issue, or have any idea on a method to track down the problem?

 

Try without the cache server to rule out that this is interfering somehow.

Then I would add logs to every static ctor and every class/method with InitializeOnLoad attributes (but not the Runtime... versions). One log at the start and one at the end of the method so you learn whether there's a specific method/ctor where it stops all the time. Then analyze what that is doing, or post that code.

One thing to note: In any such methods, avoid calling any AssetDatabase methods since the AssetDatabase at this point isn't fully initialized. The fact that this only occurs every so often may be an indicator that the culprit is one such method which works fine most of the time but due to undefined order of execution it may get stuck on an AssetDatabase method because this time it ran before the AssetDatabase's initialization process.

A simple workaround if you find such a method might be to wrap all the code in:
EditorApplication.delayCall += () => { /* original code here */ };

This makes it run just a little later.

 

I have disabled the cache server just to make sure it's nothing there.

After adding all the logging I could during InitializeOnLoad, I see that the build stops after all of the InitializeOnLoads complete, as far as I can tell. I added a callback to EditorApplication.delayCall as part of one of the InitializeOnLoad methods, to check whether the build has stalled, but the delayCall itself is never invoked.

In this instance, immediately after the InitializeOnLoad methods are finished, it froze at this point:

Mono: successfully reloaded assembly

- Finished resetting the current domain, in 10.754 seconds

Domain Reload Profiling: 17658ms

  BeginReloadAssembly (518ms)

    ExecutionOrderSort (0ms)

    DisableScriptedObjects (46ms)

    BackupInstance (0ms)

    ReleaseScriptingObjects (0ms)

    CreateAndSetChildDomain (180ms)

  RebuildCommonClasses (95ms)

  RebuildNativeTypeToScriptingClass (21ms)

  initialDomainReloadingComplete (123ms)

  LoadAllAssembliesAndSetupDomain (6147ms)

 

I have downgraded the project to 2022.3.10, and the build is functioning again. So something between 2022.3.10 and 2022.3.20 broke the build. For now I'll just leave this alone, since it's functioning enough for my needs.