[.NET] Build time is slower

[rolfbjarne]

Build time is significantly slower with .NET 6 than with Xamarin.iOS.

• Checkout and build the dotnet-size-comparison-helloworld branch from my fork.
• Execute:

cd tests/dotnet
git clean -xfdq
make compare

Then check the bin logs in the tests/dotnet directory.

Xamarin.iOS takes 11s to build:

$ msbuild /v:diag build-oldnet.binlog | tail -n 15
       62 ms  ResolveAssemblyReference                   1 calls
       69 ms  DetectSigningIdentity                      1 calls
      103 ms  DetectSdkLocations                         1 calls
      119 ms  SymbolStrip                                1 calls
      126 ms  SpotlightIndexer                           1 calls
      186 ms  Codesign                                   2 calls
      653 ms  DSymUtil                                   1 calls
      772 ms  Csc                                        1 calls
     8388 ms  MTouch                                     1 calls

Build succeeded.
    0 Warning(s)
    0 Error(s)

Time Elapsed 00:00:11.24

.NET 6 takes 18s to build:

$ msbuild /v:diag build-dotnet.binlog | tail -n 15
      200 ms  MSBuild                                    7 calls
      296 ms  LinkNativeCode                             1 calls
      393 ms  GenerateDepsFile                           2 calls
      501 ms  Codesign                                   2 calls
      917 ms  Csc                                        1 calls
     1185 ms  AOTCompile                                 1 calls
     1222 ms  CopyRefAssembly                            1 calls
     3276 ms  CompileNativeCode                          2 calls
     8576 ms  ILLink                                     1 calls

Build succeeded.
    0 Warning(s)
    0 Error(s)

Time Elapsed 00:00:18.55

The ILLink task significantly longer than the MTouch task used to take (which also includes AOT compilation and native code compilation).

[rolfbjarne]

CC @marek-safar

[spouliot]

P2 numbers. They look closer, between them [1], than the original numbers.

[1] this was done on a different (and slower) computer than the original post.

msbuild /v:diag build-oldnet.binlog | tail -n 15
      129 ms  SymbolStrip                                1 calls
      222 ms  ResolveAssemblyReference                   1 calls
      232 ms  SpotlightIndexer                           1 calls
      453 ms  DetectSdkLocations                         1 calls
      723 ms  DetectSigningIdentity                      1 calls
      881 ms  Codesign                                   2 calls
     1625 ms  DSymUtil                                   1 calls
     1745 ms  Csc                                        1 calls
    11812 ms  MTouch                                     1 calls

Build succeeded.
    0 Warning(s)
    0 Error(s)

Time Elapsed 00:00:18.99

/Users/poupou/git/master/xamarin-macios/builds/downloads/dotnet-sdk-6.0.100-preview.2.21158.2-osx-x64/dotnet /Users/poupou/git/master/xamarin-macios/builds/downloads/dotnet-sdk-6.0.100-preview.2.21158.2-osx-x64/sdk/6.0.100-preview.2.21158.2/MSBuild.dll /v:diag build-dotnet.binlog | tail -n 15
      339 ms  LinkNativeCode                             1 calls
      341 ms  UnpackLibraryResources                     1 calls
      478 ms  GenerateDepsFile                           2 calls
      555 ms  DetectSigningIdentity                      1 calls
     1104 ms  AOTCompile                                 1 calls
     1408 ms  Csc                                        1 calls
     2833 ms  CompileNativeCode                          2 calls
     5142 ms  Codesign                                   2 calls
     5391 ms  ILLink                                     1 calls

Build succeeded.
    0 Warning(s)
    0 Error(s)

Time Elapsed 00:00:21.39

[filipnavara]

The difference in Codesign is quite striking. Any explanation for it? (or .binlogs to analyze)

[spouliot]

@filipnavara I missed it (looked only at how MTouchTask is now split out) and I'm not sure why in this case [1]. Let me find back the binlogs... (binlogs.zip attached)

note: It seems there was already a large diff in Codesign numbers in the original post.

[1] some Apple tools (like ibtool) spawn daemons that stays alive (for a while) so running two builds sequentially can skew numbers.

[filipnavara]

The majority of time in Codesign is spent on signing the native libraries. The libraries coming from https://github.com/dotnet/runtime/tree/main/src/libraries/Native are already signed with some key and get resigned. The runtime libraries (libmonosgen-2.0.dylib, libxamarin.dylib, libxamarin-dotnet.dylib) are not signed.

Presumably this is something that should not be done on every compilation or could be avoided. I cannot see the same thing happening in the old Mono build unless it's folded quietly into one of the other tasks.

Moreover, the NuGet package Microsoft.iOS.Runtime.ios-arm64 seems to distribute both libxamarin.[a|dylib] and libxamarin-dotnet.[a|dylib]. That doesn't sound right. I believe only the later should be distributed for .NET 6.

[spouliot]

@filipnavara that make sense 😄 The .dylib should not be present as they are not even allowed in iOS apps. The code is already linked (from the static library) inside the native executable. To be usable, dynamically, this would need to be put inside a (user) framework.

In all honesty taking the times from a release build (like we did here) is not really correct. It was just easier as the data was already on hands (from the size tracking issue). IOW

• We really care about build time performance in debug builds where a fast edit/build/deploy cycle is important for the developer's productivity.

• For, much less common, release builds we're willing to trade additional build time to get optimized (faster/smaller) applications.

But right now comparing release build times from current/legacy and dotnet gives us a feeling if we trend in the right (or wrong) direction. We'll eventually do more accurate measurements once all the pieces have landed. OTOH don't let me stop you from doing your own measurements/experiments 😃

[filipnavara]

The .dylib should not be present as they are not even allowed in iOS apps.

Ah, good point. Coming from macOS background I missed that, especially since there was an explicit condition for iOS dylibs:

xamarin-macios/msbuild/Xamarin.Shared/Xamarin.Shared.targets

Lines 1017 to 1022 in 3a96cb0

	<ItemGroup Condition="'$(_PlatformName)' == 'iOS' Or '$(_PlatformName)' == 'tvOS' Or '$(_PlatformName)' == 'watchOS'">
	<_CodesignNativeLibrary
	Include="$(_AppBundlePath)\**\*.dylib;$(_AppBundlePath)\**\*.metallib"
	Exclude="$(_AppBundlePath)\Watch\**;$(_AppBundlePath)\PlugIns\**"
	/>
	</ItemGroup>

So the issue is that more things get included that should not be present in the bundle, right?

In all honesty taking the times from a release build (like we did here) is not really correct.

Well, I compared the binlogs you used. Then again, on iOS the code signing is unconditionally enabled even on Debug builds:

xamarin-macios/msbuild/Xamarin.Shared/Xamarin.Shared.targets

Lines 1000 to 1004 in 3a96cb0

	<!-- Note:
	Always codesign *.dylibs even for Simulator builds for iOS/tvOS/watchOS. We use $(_CanOutputAppBundle) because dylibs can exist in app extensions as well.
	For macOS we sign if _RequireCodeSigning is true
	-->
	<Target Name="_CodesignNativeLibraries" Condition="'$(_CanOutputAppBundle)' == 'true' And ('$(_RequireCodeSigning)' == 'true' Or '$(_PlatformName)' != 'macOS')" DependsOnTargets="$(_CodesignNativeLibrariesDependsOn)">

[spouliot]

since there was an explicit condition for iOS dylibs:

Yes, dylib are fine for simulators and for device / debug build., e.g. it's used for the incremental builds. However they would be refused when submitted to the App Store.

So the issue is that more things get included that should not be present in the bundle, right?

Yes. They are not needed... or if they somehow are it's a bug that needs to be fixed.

on iOS the code signing is unconditionally enabled even on Debug builds

Yes. Devices won't accept unsigned (native) code. Simulator behave differently wrt signatures (it's not always needed).

[filipnavara]

Moreover, the NuGet package Microsoft.iOS.Runtime.ios-arm64 seems to distribute both libxamarin.[a|dylib] and libxamarin-dotnet.[a|dylib]. That doesn't sound right. I believe only the later should be distributed for .NET 6.

I checked the latest package from main and this was already fixed. I could not pinpoint which commit did that though.

[spouliot]

time on release builds (with the same caveats as mentioned in earlier comments)

legacy 16.19 real 14.47 user 2.98 sys
dotnet 17.23 real 18.64 user 3.52 sys

[rolfbjarne]

This is an example of where our build is pretty slow: #11886

[rolfbjarne]

See also: dotnet/linker#2089

[spouliot]

time on release builds (same caveats as before, but it match the previous data used here) using RC1 binaries on MacBook Pro / M1

legacy 29.25 real 23.83 user 3.45 sys
dotnet 38.83 real 35.05 user 4.71 sys [1][2]

[1] configured to use LLVM, like legacy but unlike previous numbers for dotnet
[2] IL strip is not done (on dotnet/rc1) but is done on legacy

[spouliot]

time on debug builds for simulators - again using RC1 binaries on MacBook Pro / M1

Legacy

time 5.03 real 3.81 user 1.04 sys

debug-oldnet.binlog.zip

Duration = 3.770 s
...
Top 10 most expensive tasks
    MTouch = 1.076 s
    Csc = 220 ms
    DetectSdkLocations = 215 ms
    ResolveAssemblyReference = 197 ms
    Codesign = 110 ms
    CompileAppManifest = 44 ms
    WriteItemsToFile = 41 ms
    MakeDir = 31 ms
    Message = 28 ms
    GetReferenceAssemblyPaths = 26 ms

net6 rc.1

time 22.32 real 23.38 user 4.40 sys

debug-dotnet.binlog.zip

Duration = 21.327 s
...
Top 10 most expensive tasks
    ILLink = 15.833 s
    CompileNativeCode = 566 ms
    RestoreTask = 450 ms
    Codesign = 275 ms
    LinkNativeCode = 264 ms
    Csc = 221 ms
    Copy = 214 ms
    DetectSdkLocations = 165 ms
    ProcessFrameworkReferences = 147 ms
    GenerateRuntimeConfigurationFiles = 123 ms

since it's close to the smallest app possible this kind of show the minimal build times.

note: this can be duplicated by applying https://gist.github.com/spouliot/2ade2822865fa7dff6cad0f11bbb2b09 to xamarin-macios branch release/6.0.1xx-rc.1 (or main for rc2 / work-in-progress)

[chamons]

I did some testing on release/6.0.1xx-preview9 to get speed info.

It was done on an older mac pro (trashcan), so they are comparable only to each other, not older builds.

These are release device builds:
Legacy: 33.95 real 32.75 user 2.57 sys
net6: 55.73 real 56.81 user 4.32 sys

These are debug sim builds:
Legacy: real 0m2.146s user 0m1.757s sys 0m0.467s
net6: real 0m35.024s user 0m46.012s sys 0m4.629s

[chamons]

These are on a newer machine than last time, so they are comparable only to each other, not older builds.

Release Device

Legacy - real 0m24.838s user 0m23.670s sys 0m3.584s
net6 - real 0m37.889s user 0m37.353s sys 0m5.227s

Debug Sim

Legacy - real 0m5.205s user 0m3.823s sys 0m1.142s
net6 - real 0m22.010s user 0m19.365s sys 0m4.626s

[chamons]

Report on 4564969 from https://github.com/xamarin/xamarin-macios/commits/release/6.0.1xx-preview11:

Release Device

Legacy - real 0m30.268s user 0m24.250s sys 0m3.900s
net6 - real 0m42.698s user 0m37.756s sys 0m5.734s

Debug Sim

Legacy - real 0m5.227s user 0m3.829s sys 0m1.123s
net6 - 0m21.774s user 0m19.472s sys 0m4.666s

[rolfbjarne]

There is still work to do here, but it's too late in the .NET 6 timeframe, so I'm postponing until .NET 7.