From e2ed9d652ad6d14fe1fecb56844a80dc510c590b Mon Sep 17 00:00:00 2001 From: Jonathan Pobst Date: Mon, 25 Nov 2024 07:59:30 -1000 Subject: [PATCH] [Xamarin.Android.Build.Tasks] Add PerformanceTimer for measuring task steps time. --- .../Tasks/BuildApk.cs | 71 ++++++++++++++-- .../Utilities/PerformanceTimer.cs | 83 +++++++++++++++++++ 2 files changed, 146 insertions(+), 8 deletions(-) create mode 100644 src/Xamarin.Android.Build.Tasks/Utilities/PerformanceTimer.cs diff --git a/src/Xamarin.Android.Build.Tasks/Tasks/BuildApk.cs b/src/Xamarin.Android.Build.Tasks/Tasks/BuildApk.cs index 024b181fc66..0d507d29f64 100644 --- a/src/Xamarin.Android.Build.Tasks/Tasks/BuildApk.cs +++ b/src/Xamarin.Android.Build.Tasks/Tasks/BuildApk.cs @@ -18,6 +18,7 @@ using Xamarin.Android.Tools; using Xamarin.Tools.Zip; using Microsoft.Android.Build.Tasks; +using Xamarin.Android.Tasks.Utilities; namespace Xamarin.Android.Tasks { @@ -147,8 +148,10 @@ protected virtual void FixupArchive (ZipArchiveEx zip) { } List includePatterns = new List (); - void ExecuteWithAbi (DSOWrapperGenerator.Config dsoWrapperConfig, string [] supportedAbis, string apkInputPath, string apkOutputPath, bool debug, bool compress, IDictionary> compressedAssembliesInfo, string assemblyStoreApkName) + void ExecuteWithAbi (DSOWrapperGenerator.Config dsoWrapperConfig, string [] supportedAbis, string apkInputPath, string apkOutputPath, bool debug, bool compress, IDictionary> compressedAssembliesInfo, string assemblyStoreApkName, PerformanceTimer timer) { + timer.StartSubTask ("Setup"); + ArchiveFileList files = new ArchiveFileList (); bool refresh = true; if (apkInputPath != null && File.Exists (apkInputPath) && !File.Exists (apkOutputPath)) { @@ -204,6 +207,8 @@ void ExecuteWithAbi (DSOWrapperGenerator.Config dsoWrapperConfig, string [] supp } apk.FixupWindowsPathSeparators ((a, b) => Log.LogDebugMessage ($"Fixing up malformed entry `{a}` -> `{b}`")); + timer.StartSubTask ("Add DalvikClasses"); + // Add classes.dx CompressionMethod dexCompressionMethod = GetCompressionMethod (".dex"); foreach (var dex in DalvikClasses) { @@ -214,22 +219,36 @@ void ExecuteWithAbi (DSOWrapperGenerator.Config dsoWrapperConfig, string [] supp } if (EmbedAssemblies) { - AddAssemblies (dsoWrapperConfig, apk, debug, compress, compressedAssembliesInfo, assemblyStoreApkName); - apk.Flush (); + using var embed_assemblies_timer = timer.StartSubTask ("Embed Assemblies"); { + AddAssemblies (dsoWrapperConfig, apk, debug, compress, compressedAssembliesInfo, assemblyStoreApkName, embed_assemblies_timer); + apk.Flush (); + } } + timer.StartSubTask ("AddRuntimeConfigBlob"); AddRuntimeConfigBlob (dsoWrapperConfig, apk); + + timer.StartSubTask ("AddRuntimeLibraries"); AddRuntimeLibraries (apk, supportedAbis); + + timer.StartSubTask ("Flush"); apk.Flush(); + + timer.StartSubTask ("AddNativeLibraries"); AddNativeLibraries (files, supportedAbis); + + timer.StartSubTask ("AddAdditionalNativeLibraries"); AddAdditionalNativeLibraries (files, supportedAbis); if (TypeMappings != null) { + timer.StartSubTask ("Add TypeMappings"); foreach (ITaskItem typemap in TypeMappings) { AddFileToArchiveIfNewer (apk, typemap.ItemSpec, RootPath + Path.GetFileName(typemap.ItemSpec), compressionMethod: UncompressedMethod); } } + timer.StartSubTask ("Add files"); + foreach (var file in files) { var item = Path.Combine (file.archivePath.Replace (Path.DirectorySeparatorChar, '/')); existingEntries.Remove (item); @@ -242,6 +261,8 @@ void ExecuteWithAbi (DSOWrapperGenerator.Config dsoWrapperConfig, string [] supp apk.AddFileAndFlush (file.filePath, item, compressionMethod: compressionMethod); } + timer.StartSubTask ("Add Jars"); + var jarFiles = (JavaSourceFiles != null) ? JavaSourceFiles.Where (f => f.ItemSpec.EndsWith (".jar", StringComparison.OrdinalIgnoreCase)) : null; if (jarFiles != null && JavaLibraries != null) jarFiles = jarFiles.Concat (JavaLibraries); @@ -308,6 +329,9 @@ void ExecuteWithAbi (DSOWrapperGenerator.Config dsoWrapperConfig, string [] supp } } } + + timer.StartSubTask ("Clean up Removed files"); + // Clean up Removed files. foreach (var entry in existingEntries) { // never remove an AndroidManifest. It may be renamed when using aab. @@ -316,13 +340,23 @@ void ExecuteWithAbi (DSOWrapperGenerator.Config dsoWrapperConfig, string [] supp Log.LogDebugMessage ($"Removing {entry} as it is not longer required."); apk.Archive.DeleteEntry (entry); } + + timer.StartSubTask ("Flush"); apk.Flush (); + + timer.StartSubTask ("FixupArchive"); FixupArchive (apk); + + timer.Stop (); } } public override bool RunTask () { + var timer = PerformanceTimer.Create ("BuildApk.RunTask"); + + timer.StartSubTask ("Setup"); + Aot.TryGetSequencePointsMode (AndroidSequencePointsMode, out sequencePointsMode); var outputFiles = new List (); @@ -348,6 +382,8 @@ public override bool RunTask () includePatterns.Add (FileGlobToRegEx (pattern, RegexOptions.IgnoreCase | RegexOptions.Compiled)); } + timer.StartSubTask ("Compression"); + bool debug = _Debug; bool compress = !debug && EnableCompression; IDictionary> compressedAssembliesInfo = null; @@ -360,8 +396,13 @@ public override bool RunTask () throw new InvalidOperationException ($"Assembly compression info not found for key '{key}'. Compression will not be performed."); } + timer.StartSubTask ("DSOWrapperGenerator"); + DSOWrapperGenerator.Config dsoWrapperConfig = DSOWrapperGenerator.GetConfig (Log, AndroidBinUtilsDirectory, IntermediateOutputPath); - ExecuteWithAbi (dsoWrapperConfig, SupportedAbis, ApkInputPath, ApkOutputPath, debug, compress, compressedAssembliesInfo, assemblyStoreApkName: null); + + using var abi_timer = timer.StartSubTask ($"ExecuteWithAbi '{string.Join (", ", SupportedAbis)}'"); + ExecuteWithAbi (dsoWrapperConfig, SupportedAbis, ApkInputPath, ApkOutputPath, debug, compress, compressedAssembliesInfo, assemblyStoreApkName: null, abi_timer); + outputFiles.Add (ApkOutputPath); if (CreatePackagePerAbi && SupportedAbis.Length > 1) { var abiArray = new string[] { String.Empty }; @@ -370,9 +411,11 @@ public override bool RunTask () var path = Path.GetDirectoryName (ApkOutputPath); var apk = Path.GetFileNameWithoutExtension (ApkOutputPath); abiArray[0] = abi; - ExecuteWithAbi (dsoWrapperConfig, abiArray, String.Format ("{0}-{1}", ApkInputPath, abi), - Path.Combine (path, String.Format ("{0}-{1}.apk", apk, abi)), - debug, compress, compressedAssembliesInfo, assemblyStoreApkName: abi); + + using var inner_abi_timer = timer.StartSubTask ($"ExecuteWithAbi '{abi}'"); + ExecuteWithAbi (dsoWrapperConfig, abiArray, String.Format ("{0}-{1}", ApkInputPath, abi), + Path.Combine (path, String.Format ("{0}-{1}.apk", apk, abi)), + debug, compress, compressedAssembliesInfo, assemblyStoreApkName: abi, inner_abi_timer); outputFiles.Add (Path.Combine (path, String.Format ("{0}-{1}.apk", apk, abi))); } } @@ -380,8 +423,14 @@ public override bool RunTask () OutputFiles = outputFiles.Select (a => new TaskItem (a)).ToArray (); Log.LogDebugTaskItems (" [Output] OutputFiles :", OutputFiles); + + timer.StartSubTask ("Cleanup"); + DSOWrapperGenerator.CleanUp (dsoWrapperConfig); + timer.Stop (); + timer.WriteLog (Log); + return !Log.HasLoggedErrors; } @@ -420,7 +469,7 @@ void AddRuntimeConfigBlob (DSOWrapperGenerator.Config dsoWrapperConfig, ZipArchi } } - void AddAssemblies (DSOWrapperGenerator.Config dsoWrapperConfig, ZipArchiveEx apk, bool debug, bool compress, IDictionary> compressedAssembliesInfo, string assemblyStoreApkName) + void AddAssemblies (DSOWrapperGenerator.Config dsoWrapperConfig, ZipArchiveEx apk, bool debug, bool compress, IDictionary> compressedAssembliesInfo, string assemblyStoreApkName, PerformanceTimer timer) { string sourcePath; AssemblyCompression.AssemblyData compressedAssembly = null; @@ -432,15 +481,18 @@ void AddAssemblies (DSOWrapperGenerator.Config dsoWrapperConfig, ZipArchiveEx ap } // Add user assemblies + timer.StartSubTask ($"Add {ResolvedUserAssemblies.Length} user assemblies"); AssemblyPackagingHelper.AddAssembliesFromCollection (Log, SupportedAbis, ResolvedUserAssemblies, DoAddAssembliesFromArchCollection); // Add framework assemblies + timer.StartSubTask ($"Add {ResolvedFrameworkAssemblies.Length} framework assemblies"); AssemblyPackagingHelper.AddAssembliesFromCollection (Log, SupportedAbis, ResolvedFrameworkAssemblies, DoAddAssembliesFromArchCollection); if (!UseAssemblyStore) { return; } + timer.StartSubTask ("Generate assembly store"); Dictionary assemblyStorePaths = storeBuilder.Generate (AppSharedLibrariesDir); if (assemblyStorePaths.Count == 0) { @@ -452,6 +504,9 @@ void AddAssemblies (DSOWrapperGenerator.Config dsoWrapperConfig, ZipArchiveEx ap } string inArchivePath; + + timer.StartSubTask ("Add assembly store"); + foreach (var kvp in assemblyStorePaths) { string abi = MonoAndroidHelper.ArchToAbi (kvp.Key); inArchivePath = MakeArchiveLibPath (abi, "lib" + Path.GetFileName (kvp.Value)); diff --git a/src/Xamarin.Android.Build.Tasks/Utilities/PerformanceTimer.cs b/src/Xamarin.Android.Build.Tasks/Utilities/PerformanceTimer.cs new file mode 100644 index 00000000000..96d4e904d7f --- /dev/null +++ b/src/Xamarin.Android.Build.Tasks/Utilities/PerformanceTimer.cs @@ -0,0 +1,83 @@ +#nullable enable + +using System; +using System.Collections.Generic; +using System.Diagnostics; +using System.Text; +using Microsoft.Android.Build.Tasks; +using Microsoft.Build.Utilities; + +namespace Xamarin.Android.Tasks.Utilities; + +// A class that faciliates performance timing of a task. +// Example usage: +// var timer = PerformanceTimer.Create ("MyTask"); +// timer.StartSubTask ("Step 1"); +// +// timer.StartSubTask ("Step 2"); +// +// timer.Stop (); +// timer.Log (Log); +// Also supports Disposable syntax: +// using (timer.StartSubTask ("Step 1")) { +// +// } +class PerformanceTimer : IDisposable +{ + readonly Stopwatch sw; + readonly List subtasks = []; + + PerformanceTimer? active_subtask; + + public string Name { get; } + + PerformanceTimer (string name) + { + Name = name; + sw = Stopwatch.StartNew (); + } + + public static PerformanceTimer Create (string name) + { + return new PerformanceTimer (name); + } + + public void Dispose () + { + Stop (); + } + + public PerformanceTimer StartSubTask (string name) + { + active_subtask?.Stop (); + + active_subtask = new PerformanceTimer (name); + subtasks.Add (active_subtask); + return active_subtask; + } + + public void Stop () + { + active_subtask?.Stop (); + sw.Stop (); + } + + public void WriteLog (TaskLoggingHelper log) + { + var sb = new StringBuilder (); + + WriteLog (sb, 0); + + log.LogDebugMessage (sb.ToString ()); + } + + void WriteLog (StringBuilder sb, int level) + { + sb.AppendLine ($"{new string (' ', level * 2)}- {Name} - {sw.ElapsedMilliseconds}ms"); + + level++; + + foreach (var timer in subtasks) + timer.WriteLog (sb, level); + } +}