UWP build batchmode execution takes too long for Unity

[mio-moto]

Describe the bug

We're currently facing issues on our slower build machines causing builds to fail. This bug is introduced with Unity 2019.2, 2019.3 and 2019.4. Unity exits with:

Running command: C:\Program Files (x86)\Microsoft Visual Studio\2019\Community\MSBuild\Current\Bin\MSBuild.exe "C:\agent\_work\1\b\Calculon.sln"  /t:Build /p:Configuration=master /p:Platform=arm  
Timeout while executing 'executeMethod' method 'Microsoft.MixedReality.Toolkit.Build.Editor.UnityPlayerBuildTools.StartCommandLineBuild'. 
(Filename: C:\buildslave\unity\build\Runtime/Utilities/Argv.cpp Line: 376)

Exiting without the bug reporter. Application will terminate with return code 1

We're running the editor with the following chain:

C:\Program Files\Unity\Editor\Unity.exe
  -executeMethod Microsoft.MixedReality.Toolkit.Build.Editor.UnityPlayerBuildTools.StartCommandLineBuild
  -logFile C:\agent\_work\1\s\build-380.log
  -buildTarget WSAPlayer
  -batchmode
  -quit
  -buildAppx -master -arm
  -autoIncrement
  -buildOutput C:\agent\_work\1\b
  -projectPath C:\agent\_work\1\s

The Unity issue tracker has already a ticket for this behaviour: https://issuetracker.unity3d.com/issues/batch-mode-async-method-invoked-from-executemethod-unexpectedly-terminated-by-quit-timeout

Going through the source code, I have (successfully) tried to solve the problem by recreating the Method StartCommandLineBuild, making it non-async:

public static void StartCommandLineBuild()
{
    var buildInfo = new UwpBuildInfo(true);
    ParseBuildCommandLine(ref buildInfo);
    var result = UnityPlayerBuildTools.BuildUnityPlayerSimplified().Result;
    if(result)
    {
        result &= BuildAppxAsync(buildInfo).Result;
    }
    EditorApplication.Exit(result ? 0 : 1);
}

This causes the process to hang at first, something is locking the VSWhere and MSBuild commands at some point, which I then patched again like that:

https://github.com/microsoft/MixedRealityToolkit-Unity/blob/v2.5.1/Assets/MRTK/Core/Utilities/BuildAndDeploy/UwpAppxBuildTools.cs#L126

private static async Task<int> Run(string fileName, string args, bool showDebug, CancellationToken cancellationToken)
{
    Debug.Log($"Running command: {fileName} {args}");

    var process = new Process();
    process.OutputDataReceived += (x, y) => { Debug.Log(y.Data); };
    process.ErrorDataReceived += (x, y) => { Debug.LogError(y.Data); };
    process.StartInfo = new ProcessStartInfo(fileName, args) {
        UseShellExecute = true,
        CreateNoWindow = true
    };
    process.Start();
    process.WaitForExit();
    return process.ExitCode;
}

as well as https://github.com/microsoft/MixedRealityToolkit-Unity/blob/v2.5.1/Assets/MRTK/Core/Utilities/BuildAndDeploy/UwpAppxBuildTools.cs#L194L206

// ...
var process = new Process();
process.StartInfo = new ProcessStartInfo
{
    FileName = "cmd.exe",
    CreateNoWindow = true,
    UseShellExecute = false,
    RedirectStandardOutput = true,
    RedirectStandardError = true,
    Arguments = arguments,
    WorkingDirectory = @"C:\Program Files (x86)\Microsoft Visual Studio\Installer"
};
process.Start();
process.WaitForExit();
var output = process.StandardOutput.ReadToEnd().Split('\n');


foreach (var path in output)
// ...

I'm not certain why processes start to hang like that, but I'm guessing that something around the task scheduler deadlocks. Pulling these task into a new thread wasn't an option either, since the code is highly dependent on UnityEditor and causes lots of getter errors, because these APIs can only be called from the main-thread.

This is currently a tricky situation for us - we can't patch the assembly on the fly and don't want to copy paste it, if necessary. We need to remove the async method as long as we're not upgrading to a Unity version past 2020.1.

The -buildAppX code changes the solution file already. It might be useful to split up the execution of msbuild and patching the .sln in two processes.

To reproduce

Steps to reproduce the behavior:

1. Create an empty project, Unity 2019.4.x
2. Import MRTK
3. Execute the command line on a slow (or otherwise limited machine)
4. Pass an execution time of around 7min 30s

Expected behavior

Microsoft.MixedReality.Toolkit.Build.Editor.UnityPlayerBuildTools.StartCommandLineBuild should not be async.

Your setup (please complete the following information)

• Unity 2019.4.13f1
• MRTK v2.5.1

Target platform

• HoloLens
• HoloLens 2

[pajama]

Is this reproduceable in unity 2020.1+? The Unity Issue Tracker says it's been fixed.

[syslogic]

I still face the same issue when building for ARM64 with GitHub Actions; Unity 2020.3.30f1:

Command:

Start-UnityEditor -Project .\ -ExecuteMethod Microsoft.MixedReality.Toolkit.Build.Editor.UnityPlayerBuildTools.StartCommandLineBuild -BuildTarget WSAPlayer -BatchMode -Quit -Wait -Verbose -LogFile .\Logs\WSAPlayer.log -AdditionalArguments "-nographics -logDirectory Logs -buildAppx -master -arm64"

Result:

Timeout after 300 seconds while waiting async operations to finish. executeMethod 'Microsoft.MixedReality.Toolkit.Build.Editor.UnityPlayerBuildTools.StartCommandLineBuild'
Exiting without the bug reporter. Application will terminate with return code 1

While I wonder, if not the broken ARM64 support of the current MSBuild may be the cause (.NET 3.1.23).
A patch for this had been pushed yesterday and I'd like to try with the next one version of MSBuild now.

It's also strange, that this only happens on a 2022 data-center server, but not locally on Windows 10 ...
When running MSBuild from the console (directly), it builds without timeout - but it won't find ARM64 configuration.
And when running Start-UnityEditor on CI, it finds it but I'll always get the timeout with option -buildAppx.
With Visual Studio I can also build for ARM64; the GUI and CLI seem to behave differently.

Without -batchmode it also builds a whole lot quicker; the performance in combination with -buildAppx is poor (execution time is 27m 12s). To remove -Quit seriously cannot be the answer ...when I do so, the pipeline keeps running, which it claims to have completed. No orphan processes found either. Can this "bug reporter" be somehow enabled?

[mio-moto]

Good morning.

Just to clear up some possible misunderstandings:

• -Quit is used to exit the Unity Editor after starting or executing a method, rather than keeping it open.
• -batchmode should have no impact on performance. If I had to guess your second run was much faster as assets have already been imported. Batchmode suppresses the opening of any windows.
• -buildAppx is part of the command parser of Microsoft.MixedReality.Toolkit.Build.Editor.UnityPlayerBuildTools.StartCommandLineBuild
• The timeout has to do with the task scheduler that just always times out async methods via -ExecuteMethod
• That your process without -Quit passes has to do with the fact, that the scheduler doesn't try to exit the editor.
• The Unity Bug Reporter doesn't open and it's just the default editor bug reporter, it won't do you any help, it also just collects the last editor log - which you can do manually.

What we ultimately did is rewrite the method into synchronous operations:

https://gist.github.com/DarkMio/674c8d43029f940c606123706228658e

Since this still hangs the Unity runtime when trying to compile from within Unity, the command line exits with the msbuild commands:

Now execute following commands with msbuild: 
	& "{{msbuild}}" "C:\agent\_work\35\b\RoomDeux.sln" /t:restore 
	& "{{msbuild}}" "C:\agent\_work\35\b\RoomDeux.sln"  /t:Build /p:Configuration=master /p:Platform=arm64

We additionally have a tiny powershell template to find and replace msbuild - primarily because we still can't execute commandline operations in Unity and I just generally avoided to guesstimate in Unity which might be the correct compiler:

# find a suitable MSBuild
$msbuild = $(& "C:\Program Files (x86)\Microsoft Visual Studio\Installer\vswhere.exe" -all -products * -requires Microsoft.Component.MSBuild -find MSBuild\**\Bin\MSBuild.exe)
# replace the filler-text with msbuild
(Get-Content -path "${{ parameters.buildOutputPath }}\build.ps1_template" -Raw) -replace ('{{msbuild}}',"$msbuild") | Set-Content -Path "${{ parameters.buildOutputPath }}\build.ps1"
# execute that script
& "${{ parameters.buildOutputPath }}\build.ps1"

[syslogic]

Thanks for the prompt reply; I'll try to adopt that approach.
MSbuild is what I've used before - but only ARM could be built

What I'm trying to tell is, that one probably cannot cut down on time for the one build step - but lots of time for the other.
Caching the Library directory would make it available, but this may occasionally result in a stale build cache (not an option).

[mio-moto]

I don't see the problem here and it's derailing the issue.

If you're offended by the licensing model or have a problem understanding / orchestrating Github Actions and or cache retaining inside pipelines, then I kindly ask to approach the vendors of the products.

This issue continues focusing on StartCommandLineBuild being mostly incompatible with any project past their prototypical stage as the Unity runtime kills any C# async method as entry point for -ExecuteMethod after a certain runtime (while non-async methods have an unlimited runtime).

Additionally this has been (apparently?) addressed by Unity: https://issuetracker.unity3d.com/issues/batch-mode-async-method-invoked-from-executemethod-unexpectedly-terminated-by-quit-timeout

To the maintainers: It should either be reworked (preferably, reasonably) or the (undocumented) -quitTimeout should be somewhere documented along this entry point.

[syslogic]

I don't have any issues except the one at hand (generally that neither way properly works); hoped for -buildAppx to be able to build for ARM64 and then hit this one issue. Also, when passing -verbose, it will generate incompatible logging arguments.

That these are 2-3 companies' products, which have to work together in unison, in order to build, doesn't necessarily make it any easier to build. This current way of licensing makes sense on-premises - but not necessarily when licensing builds on partner's cloud platforms (which may be considered a "trusted environment", which may permit for other models). Being able to simplify this one step would be a huge gain (3.5 minutes of roughly an hour, which are 5.8% of the total time).

On GitHub I'm calling MSbuild.exe differently (where microsoft/setup-msbuild just wraps vswhere.exe):

Start-Process -FilePath "MSBuild.exe" -ArgumentList "$solution /t:restore" -Wait -NoNewWindow -Verbose
Start-Process -FilePath "MSBuild.exe" -ArgumentList "$solution /p:PlatformTarget=ARM64 /p:Configuration=Master /p:AppxBundlePlatforms=ARM64 /p:AppxBundle=Always /p:UapAppxPackageBuildMode=StoreUpload /t:Build" -Wait -NoNewWindow -Verbose
Get-ChildItem "$ENV:GITHUB_WORKSPACE\Builds\WSAPlayer\build\bin\ARM64\master\*" -Include *.appx

---

One can similarly start MSbuild.exe as Process from C# (shows a console window):

#if UNITY_EDITOR
private static void MSBuild(string arguments)
{
    try
    {
        Process msbuild = new Process();
        msbuild.StartInfo.FileName = "MSBuild.exe";
        msbuild.StartInfo.Arguments = arguments;
        msbuild.StartInfo.WindowStyle = ProcessWindowStyle.Minimized;
        msbuild.StartInfo.UseShellExecute = true;
        msbuild.EnableRaisingEvents = true;
        msbuild.Start();

        msbuild.WaitForExit();
        Debug.Log("MSBuild ExitCode " + msbuild.ExitCode);
    }
    catch (Exception e)
    {
        Debug.Log("MSBuild Exception " + e.Message);
    }
}

[MenuItem("Mixed Reality/Build APPX")]
public static void BuildWSAPlayer()
{
    BuildPipeline.BuildPlayer(new BuildPlayerOptions
    {
        scenes = new string[],
        locationPathName = "Builds\\WSAPlayer",
        target = BuildTarget.WSAPlayer,
        options = BuildOptions.Development
    });
    MSBuild(Environment.CurrentDirectory + "\\Builds\\WSAPlayer\\XY.sln" + " /p:PlatformTarget=ARM64 /p:Configuration=Master /p:AppxBundlePlatforms=ARM64 /p:AppxBundle=Always /p:UapAppxPackageBuildMode=StoreUpload");
}
#endif

Not using method -buildAppx, but building with MSBuild.exe runs for 32m 48s and will not timeout.
/t:restore will add ARM64 as build configuration; this one hint helped me much to unpuzzle the issue.
Defintely could not have done it, because I was missing something - now it still takes ages, but it works.

[IssueSyncBot]

We appreciate your feedback and thank you for reporting this issue.

Microsoft Mixed Reality Toolkit version 2 (MRTK2) is currently in limited support. This means that Microsoft is only fixing high priority security issues. Unfortunately, this issue does not meet the necessary priority and will be closed. If you strongly feel that this issue deserves more attention, please open a new issue and explain why it is important.

Microsoft recommends that all new HoloLens 2 Unity applications use MRTK3 instead of MRTK2.

Please note that MRTK3 was released in August 2023. It features an all new architecture for developing rich mixed reality experiences and has a minimum requirement of Unity 2021.3 LTS. For more information about MRTK3, please visithttps://www.mixedrealitytoolkit.org.

Thank you for your continued support of the Mixed Reality Toolkit!