iOS/Catalyst build performance regression from net8.0 to net9.0

[jeremy-visionaid]

Description

There's quite a noticeable decrease in performance building iOS and Catalyst apps:

dotnet build -bl:../net8.0-ios.binlog
Restore complete (0.5s)
  MauiTestApp net8.0-ios succeeded (12.6s) → bin/Debug/net8.0-ios/iossimulator-arm64/MauiTestApp.dll

Build succeeded in 13.3s

dotnet build -bl:../net9.0-ios.binlog
Restore complete (0.4s)
  MauiTestApp net9.0-ios succeeded (17.4s) → bin/Debug/net9.0-ios/iossimulator-arm64/MauiTestApp.dll

Build succeeded in 18.1s

The performance regresson is also present for maccatalyst

Steps to Reproduce

The problem is reproducible with a MAUI template project, changing the TFM between net8.0-ios and net9.0-ios

Link to public reproduction project repository

No response

Version with bug

9.0.10 SR1

Is this a regression from previous behavior?

Yes, this used to work in .NET MAUI

Last version that worked well

8.0.100 SR10

Affected platforms

iOS, macOS

Affected platform versions

No response

Did you find any workaround?

Roll back to dotnet 8

Relevant log output

net8.0-ios.binlog.txt
net9.0-ios.binlog.txt

[jeremy-visionaid]

Also, the GitHub form won't allow uploading files with the extension ".binlog" which is less than ideal

[Ying-6]

This issue has been verified using latest version VSCode (9.0.10 & 9.0.0 & 8.0.100). Can unstably repro this issue on iOS and MacOS platforms. I verified it 5 times and repro once.

Unstable repro information:

aspnet@Yings-Mac-mini MauiApp1 % dotnet build -bl:../net8.0-maccatalyst.binlog
Restore complete (0.6s)
  MauiApp1 net8.0-maccatalyst succeeded (10.4s) → bin/Debug/net8.0-maccatalyst/maccatalyst-x64/MauiApp1.dll

Build succeeded in 11.5s

aspnet@Yings-Mac-mini MauiApp1 % dotnet build -bl:../net9.0-maccatalyst.binlog
Restore complete (0.6s)
  MauiApp1 net9.0-maccatalyst succeeded (11.6s) → bin/Debug/net9.0-maccatalyst/maccatalyst-x64/MauiApp1.dll

Build succeeded in 12.8s

[jeremy-visionaid]

@Ying-6 Thanks for checking the repro. On my system (Mac Mini M2 Pro), the repro rate is 100%. My figures were for a clean rebuild (git clean -dfx), but the incremental build performance also seems pretty bad. Nearly 20 seconds just to build what's essentially a Hello World app on a relatively fast machine. It wasn't exactly great with net8.0, but net9.0 really negatively affects the build, run, test cycle.

[Ying-6]

I verified this issue again on an M1 Mac Mini, changed the framework from net8.0-ios to net9.0-ios, verified it 5 times and the reproduction rate was 100%.
Note: The first verification result was on Intel Mac Mini.

admin@hotia-surface MauiApp1 % dotnet build -bl:../net8.0-ios.binlog     
Restore complete (0.3s)
  MauiApp1 net8.0-ios succeeded (7.1s) → bin/Debug/net8.0-ios/iossimulator-arm64/MauiApp1.dll

Build succeeded in 7.7s

admin@hotia-surface MauiApp1 % dotnet build -bl:../net9.0-ios.binlog     
Restore complete (0.4s)
  MauiApp1 net9.0-ios succeeded (16.4s) → bin/Debug/net9.0-ios/iossimulator-arm64/MauiApp1.dll

Build succeeded in 17.0s

[jeremy-visionaid]

Oh wow. Other members of my team use M1s, no wonder there have been some complaints! Though I'm also curious how/why your M1 builds faster than my M2 Pro... 7 or 8 seconds would be OK, but 18 is really pushing the bounds of acceptability.

[maonaoda]

M2 ...

SkiaSharpBug % dotnet build -bl:../net9.0-ios.binlog
Restore complete (0.6s)
  SkiaSharpSample net9.0-ios succeeded (24.4s) → bin/Debug/net9.0-ios/iossimulator-arm64/SkiaSharpSample.dll

Build succeeded in 25.3s

SkiaSharpBug % dotnet build -bl:../net8.0-ios.binlog
Restore complete (0.3s)
  SkiaSharpSample net8.0-ios succeeded (16.8s) → bin/Debug/net8.0-ios/iossimulator-arm64/SkiaSharpSample.dll

Build succeeded in 17.3s

[tj-devel709]

@jonathanpeppers do you have any thoughts on this one?

[jonathanpeppers]

Maybe @rolfbjarne can comment, the difference appears to be the top 2 expensive tasks. Reviewing the .binlog above:

.NET 8:

.NET 9:

The <CompileNativeCode/> task just looks like it shell's out to xcrun clang, so probably not much control on how long that takes.

<AOTCompile/> calls mono-aot-cross, so this is from the dotnet/runtime repo.

[rolfbjarne]

I've looked a bit into this, and this is what I've found so far:

1. With the interpreter enabled, the compilation time is much slower because it takes much longer to compile the AOT-compiled aot-instances code. I'm guessing this is because there's twice as much native code:

$ ls -lah /Users/rolf/test/dotnet/aotperf/TestApp/obj/Debug/net*.0-ios/iossimulator-arm64/nativelibraries/aot-output/arm64/aot-instances.dll.s
.rw-r--r--@  88,225,773 rolf 2024-12-04 18:01:48.832720614 +0100 obj/Debug/net8.0-ios/iossimulator-arm64/nativelibraries/aot-output/arm64/aot-instances.dll.s
.rw-r--r--@ 151,735,792 rolf 2024-12-04 18:02:08.333604974 +0100 obj/Debug/net9.0-ios/iossimulator-arm64/nativelibraries/aot-output/arm64/aot-instances.dll.s

• .NET 8: 88 mb
• .NET 9: 151 mb

The AOT compilation is also slower, but that shows up better in the next finding:

2. With the interpreter disabled (/p:UseInterpreter=false), we AOT much more code, and since the AOT compiler is also much slower, it has a much bigger effect:

Timings for only the AOT compilation:

• .NET 8: 33s
• .NET 9: 1m23s

The resulting app bundle is also a bit bigger, but nothing that would explain the almost 3x difference in AOT compilation:

$ du -hs bin/Debug/net*.0-ios/iossimulator-arm64/TestApp-net*.0.app
397M	bin/Debug/net8.0-ios/iossimulator-arm64/TestApp-net8.0.app
420M	bin/Debug/net9.0-ios/iossimulator-arm64/TestApp-net9.0.app

So it seems this is a runtime issue, so moving there.

[rolfbjarne]

This is my test project: TestApp-94f8396.zip

Run prepare.sh to build the project a few times for net8.0+net9.0 and with+without interpreter.

Then run reproduce.sh to show timings.

I get this:

$ ./prepare.sh
[...]
$ ./reproduce.sh
Compiling (with clang) the aot-instances.dll.s file generated by the AOT compiler for an interpreted build (.NET 8)

real	0m3.406s
user	0m2.976s
sys	0m0.268s

Compiling (with clang) the aot-instances.dll.s file generated by the AOT compiler for an interpreted build (.NET 9)

real	0m5.739s
user	0m5.104s
sys	0m0.335s

AOT-compiling all assemblies for a non-interpreted build (.NET 8)
Unable to compile method 'void System.Runtime.Serialization.SerializationGuard:<ThrowIfDeserializationInProgress>g__ThrowIfDeserializationInProgress|0_0 (System.Runtime.Serialization.SerializationInfo,string,int&)' due to: 'Method has zero rva'.
Unable to compile method 'void System.Runtime.Serialization.SerializationGuard:<ThrowIfDeserializationInProgress>g__ThrowIfDeserializationInProgress|0_0 (System.Runtime.Serialization.SerializationInfo,string,int&)' due to: 'Method has zero rva'.

real	0m33.807s
user	0m30.247s
sys	0m1.816s

AOT-compiling all assemblies for a non-interpreted build (.NET 9)

real	1m23.448s
user	1m19.085s
sys	0m2.176s

[rolfbjarne]

I just tested passing compile-in-child to the aot compiler, and saw no significant difference in timing. Updated reproduce.sh script: https://gist.github.com/rolfbjarne/665a9d4e7058a6a6dbbfaea71a71f09a

AOT-compiling all assemblies for a non-interpreted build (.NET 9) options: compile-in-child,temp-path=tmppath,

real	1m23.375s
user	1m18.554s
sys	0m3.079s

AOT-compiling all assemblies for a non-interpreted build (.NET 9) options:

real	1m22.578s
user	1m18.602s
sys	0m2.126s