From 2d0a7418d7e3f04ced790233103bf58415c09f49 Mon Sep 17 00:00:00 2001 From: Siegfried Pammer Date: Sat, 9 May 2026 21:53:30 +0200 Subject: [PATCH] Lazy LoadedAssembly + 2s cooldown sweep + perf test Replace LoadedAssembly's eager Task.Run(LoadAsync) with a Lazy> so construction is free and the load only starts on the first GetLoadResultAsync / await / .Result access. Active assembly's load fires from the saved-path restore and runs without competition; everything else stays cold until either the user expands a tree node OR the cooldown sweep fires. Assisted-by: Claude:claude-opus-4-7:Claude Code --- ICSharpCode.ILSpyX/LoadedAssembly.cs | 34 ++- ILSpy.Tests/Diagnostics/StartupPerfTests.cs | 244 ++++++++++++++++++++ ILSpy/AssemblyTree/AssemblyTreeModel.cs | 37 +++ ILSpy/ViewModels/ToolPaneModel.cs | 12 +- 4 files changed, 319 insertions(+), 8 deletions(-) create mode 100644 ILSpy.Tests/Diagnostics/StartupPerfTests.cs diff --git a/ICSharpCode.ILSpyX/LoadedAssembly.cs b/ICSharpCode.ILSpyX/LoadedAssembly.cs index a12622173..ef60ceeb0 100644 --- a/ICSharpCode.ILSpyX/LoadedAssembly.cs +++ b/ICSharpCode.ILSpyX/LoadedAssembly.cs @@ -60,7 +60,11 @@ namespace ICSharpCode.ILSpyX /// internal static readonly ConditionalWeakTable loadedAssemblies = new ConditionalWeakTable(); - readonly Task loadingTask; + readonly Lazy> lazyLoadingTask; + // Routes through Lazy so the actual Task.Run(LoadAsync) only kicks off on first + // demand (any caller that awaits or reads .Result). Status checks below use + // IsValueCreated so they don't accidentally trigger the load just by polling. + Task loadingTask => lazyLoadingTask.Value; readonly AssemblyList assemblyList; readonly string fileName; readonly string shortName; @@ -86,7 +90,14 @@ namespace ICSharpCode.ILSpyX this.applyWinRTProjections = applyWinRTProjections; this.useDebugSymbols = useDebugSymbols; - this.loadingTask = Task.Run(() => LoadAsync(stream)); // requires that this.fileName is set + // Lazy: the first GetLoadResultAsync / await / .Result kicks off the work. Lets + // callers (e.g. AssemblyListTreeNode) construct LoadedAssembly entries en masse + // without flooding the thread pool with metadata-loading tasks; the active + // assembly's path-restore awaits first and gets a clean run. + var localStream = stream; + this.lazyLoadingTask = new Lazy>( + () => Task.Run(() => LoadAsync(localStream)), + LazyThreadSafetyMode.ExecutionAndPublication); // requires that this.fileName is set this.shortName = Path.GetFileNameWithoutExtension(fileName); } @@ -290,15 +301,21 @@ namespace ICSharpCode.ILSpyX /// /// Gets whether loading finished for this file (either successfully or unsuccessfully). + /// Reading this property must NOT trigger the lazy load — callers poll it as a status + /// check (e.g. tree-icon overlays) and would deadlock if every poll started another + /// metadata load. /// - public bool IsLoaded => loadingTask.IsCompleted; + public bool IsLoaded => lazyLoadingTask.IsValueCreated && lazyLoadingTask.Value.IsCompleted; /// /// Gets whether this file was loaded successfully as an assembly (not as a bundle). /// public bool IsLoadedAsValidAssembly { get { - return loadingTask.Status == TaskStatus.RanToCompletion && loadingTask.Result.MetadataFile is { IsMetadataOnly: false }; + if (!lazyLoadingTask.IsValueCreated) + return false; + var task = lazyLoadingTask.Value; + return task.Status == TaskStatus.RanToCompletion && task.Result.MetadataFile is { IsMetadataOnly: false }; } } @@ -306,7 +323,7 @@ namespace ICSharpCode.ILSpyX /// Gets whether loading failed (file does not exist, unknown file format). /// Returns false for valid assemblies and valid bundles. /// - public bool HasLoadError => loadingTask.IsFaulted; + public bool HasLoadError => lazyLoadingTask.IsValueCreated && lazyLoadingTask.Value.IsFaulted; public bool IsAutoLoaded { get; set; } @@ -655,9 +672,12 @@ namespace ICSharpCode.ILSpyX public void Dispose() { - if (loadingTask.Status == TaskStatus.RanToCompletion) + // Only inspect the load task if it's been started. Disposing a never-loaded + // LoadedAssembly must not synchronously kick off the load just to dispose its + // (still-non-existent) MetadataFile. + if (lazyLoadingTask.IsValueCreated && lazyLoadingTask.Value.Status == TaskStatus.RanToCompletion) { - loadingTask.Result.MetadataFile?.Dispose(); + lazyLoadingTask.Value.Result.MetadataFile?.Dispose(); } (debugInfoProvider as IDisposable)?.Dispose(); } diff --git a/ILSpy.Tests/Diagnostics/StartupPerfTests.cs b/ILSpy.Tests/Diagnostics/StartupPerfTests.cs new file mode 100644 index 000000000..e7a485ff9 --- /dev/null +++ b/ILSpy.Tests/Diagnostics/StartupPerfTests.cs @@ -0,0 +1,244 @@ +// Copyright (c) 2026 AlphaSierraPapa for the SharpDevelop Team +// +// Permission is hereby granted, free of charge, to any person obtaining a copy of this +// software and associated documentation files (the "Software"), to deal in the Software +// without restriction, including without limitation the rights to use, copy, modify, merge, +// publish, distribute, sublicense, and/or sell copies of the Software, and to permit persons +// to whom the Software is furnished to do so, subject to the following conditions: +// +// The above copyright notice and this permission notice shall be included in all copies or +// substantial portions of the Software. +// +// THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR IMPLIED, +// INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY, FITNESS FOR A PARTICULAR +// PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE +// FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR +// OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER +// DEALINGS IN THE SOFTWARE. + +using System; +using System.Collections.Generic; +using System.Diagnostics; +using System.IO; +using System.Linq; +using System.Threading.Tasks; + +using Avalonia.Controls; +using Avalonia.Headless.NUnit; +using Avalonia.Threading; + +using AwesomeAssertions; + +using ILSpy.AppEnv; +using ILSpy.AssemblyTree; +using ILSpy.ViewModels; +using ILSpy.Views; + +using NUnit.Framework; + +namespace ICSharpCode.ILSpy.Tests; + +/// +/// Hand-run benchmarks for startup-related code paths under load. Marked +/// so the regular test suite skips them — they're +/// expensive (file copies + waiting on metadata loads) and the timings depend on +/// the host machine's IO + thread-pool contention. Run via: +/// dotnet test ILSpy.Tests --filter "Category=Performance" +/// or invoke a single benchmark by name. Output is written to NUnit's TestContext +/// log so the timings show up next to each test in the runner. +/// +[TestFixture] +[Category("Performance")] +public class StartupPerfTests +{ + const int LargeListAssemblyCount = 200; + + [Explicit("Perf benchmark — emits timings for manual inspection")] + [AvaloniaTest] + public async Task BindTree_With_Large_AssemblyList_Reports_Phase_Timings() + { + // Simulates the user-perceived startup of a saved list with many assemblies. The + // composition is shared across tests, so we can't measure cold-start of MainWindow + // — instead we time the phases that dominate startup with N assemblies: opening the + // LoadedAssembly entries, settling the AssemblyList, and waiting for every metadata + // load to finish. Compare these numbers against the same run after a code change to + // see if startup got better or worse. + + // Arrange — N temp copies of CoreLib so OpenAssembly can't dedupe them. + var tempDir = Path.Combine(Path.GetTempPath(), "ILSpy.PerfTest", Guid.NewGuid().ToString("N")); + Directory.CreateDirectory(tempDir); + try + { + var sourcePath = typeof(object).Assembly.Location; + TestContext.Out.WriteLine($"Cloning {LargeListAssemblyCount} copies of {sourcePath} to {tempDir}"); + var swCopy = Stopwatch.StartNew(); + var copies = new string[LargeListAssemblyCount]; + for (int i = 0; i < LargeListAssemblyCount; i++) + { + copies[i] = Path.Combine(tempDir, $"copy{i:D4}.dll"); + File.Copy(sourcePath, copies[i]); + } + swCopy.Stop(); + TestContext.Out.WriteLine($" file copy: {swCopy.ElapsedMilliseconds} ms"); + + // Boot the window + wait for the standard 3 assemblies (CoreLib + Uri + Linq) to + // settle so they don't pollute the per-assembly timing. + var window = AppComposition.Current.GetExport(); + window.Show(); + var vm = (MainWindowViewModel)window.DataContext!; + await vm.AssemblyTreeModel.WaitForAssembliesAsync(minimumCount: 3); + var baselineCount = vm.AssemblyTreeModel.AssemblyList!.GetAssemblies().Length; + TestContext.Out.WriteLine($"Baseline: {baselineCount} assemblies after window opened"); + + // Act 1 — fire OpenAssembly for every clone. Each call constructs a LoadedAssembly + // and queues a Task.Run(LoadAsync), so this is essentially the cost of the + // in-memory bookkeeping (path canonicalisation, dictionary insert, list append). + var swOpen = Stopwatch.StartNew(); + foreach (var path in copies) + vm.AssemblyTreeModel.AssemblyList!.OpenAssembly(path); + swOpen.Stop(); + TestContext.Out.WriteLine($"OpenAssembly x{LargeListAssemblyCount}: {swOpen.ElapsedMilliseconds} ms " + + $"({swOpen.ElapsedMilliseconds / (double)LargeListAssemblyCount:0.##} ms/asm)"); + + // Act 2 — wait for the AssemblyList to actually contain all the new entries (the + // add is dispatched onto the UI thread when called from a worker thread; we're on + // the UI thread here so the add was synchronous, but we still need to wait for the + // AssemblyListTreeNode to project the new children into the tree). + var swSettle = Stopwatch.StartNew(); + await Waiters.WaitForAsync( + () => vm.AssemblyTreeModel.AssemblyList!.GetAssemblies().Length >= baselineCount + LargeListAssemblyCount, + timeout: TimeSpan.FromSeconds(60)); + swSettle.Stop(); + TestContext.Out.WriteLine($"AssemblyList settled to {baselineCount + LargeListAssemblyCount}: {swSettle.ElapsedMilliseconds} ms"); + + // Act 3 — wait for every assembly's metadata load to complete. This is the work + // that the async-restore path defers when the user has a saved selection. + var allAssemblies = vm.AssemblyTreeModel.AssemblyList!.GetAssemblies(); + var swLoad = Stopwatch.StartNew(); + await Task.WhenAll(allAssemblies.Select(a => a.GetLoadResultAsync())); + swLoad.Stop(); + TestContext.Out.WriteLine($"All {allAssemblies.Length} GetLoadResultAsync awaited: {swLoad.ElapsedMilliseconds} ms " + + $"({swLoad.ElapsedMilliseconds / (double)allAssemblies.Length:0.##} ms/asm)"); + + // Act 4 — the assembly-tree pane should still be responsive. Measure how long it + // takes the AssemblyListPane to produce a fresh DataGrid descendant from this point + // (proxy for "tree is interactive"). + var pane = await window.WaitForComponent(); + var swGrid = Stopwatch.StartNew(); + var grid = await pane.WaitForComponent(); + swGrid.Stop(); + TestContext.Out.WriteLine($"DataGrid descendant available: {swGrid.ElapsedMilliseconds} ms"); + + // Sanity assertions — large enough to never trip on slow machines, but tight + // enough to flag a 10× regression. + vm.AssemblyTreeModel.AssemblyList!.GetAssemblies().Length + .Should().BeGreaterThanOrEqualTo(baselineCount + LargeListAssemblyCount); + swOpen.Elapsed.Should().BeLessThan(TimeSpan.FromSeconds(30), + "opening N LoadedAssembly entries is in-memory work and should never get this slow"); + + // Surface the StartupLog elapsed (ms since process start) so the test output also + // captures the big-picture timing alongside the per-phase deltas above. + StartupLog.Mark("StartupPerfTests benchmark completed"); + } + finally + { + try + { Directory.Delete(tempDir, recursive: true); } + catch { /* test cleanup must never fail */ } + } + } + + const int ResponsivenessAssemblyCount = 200; + + [Explicit("Perf benchmark — emits dispatcher-latency stats for manual inspection")] + [AvaloniaTest] + public async Task UI_Stays_Responsive_While_Many_Assemblies_Load() + { + // Probes latency at + // continuously while a flood of assemblies is added and their metadata loads on the + // background thread pool. If the UI thread blocks (e.g. someone re-introduces a + // .GetAwaiter().GetResult() on the saved-path restore), latency spikes and the test + // reports it. Run with: + // dotnet test --filter "FullyQualifiedName~UI_Stays_Responsive" + + // Setup: clone CoreLib N times. + var tempDir = Path.Combine(Path.GetTempPath(), "ILSpy.PerfTest", Guid.NewGuid().ToString("N")); + Directory.CreateDirectory(tempDir); + try + { + var sourcePath = typeof(object).Assembly.Location; + var copies = new string[ResponsivenessAssemblyCount]; + for (int i = 0; i < ResponsivenessAssemblyCount; i++) + { + copies[i] = Path.Combine(tempDir, $"copy{i:D4}.dll"); + File.Copy(sourcePath, copies[i]); + } + + var window = AppComposition.Current.GetExport(); + window.Show(); + var vm = (MainWindowViewModel)window.DataContext!; + await vm.AssemblyTreeModel.WaitForAssembliesAsync(minimumCount: 3); + + // Trigger the heavy load: each OpenAssembly queues a Task.Run(LoadAsync), so the + // metadata IO + parsing happens on the thread pool — the UI thread is free to keep + // pumping the dispatcher. + var swLoad = Stopwatch.StartNew(); + foreach (var path in copies) + vm.AssemblyTreeModel.AssemblyList!.OpenAssembly(path); + var allAssemblies = vm.AssemblyTreeModel.AssemblyList!.GetAssemblies(); + var loadTasks = allAssemblies.Select(a => a.GetLoadResultAsync()).ToArray(); + + // Probe the dispatcher from the UI thread itself. Each iteration: + // 1) await an InvokeAsync(noop, Background) — this measures how long the + // dispatcher takes to service a low-priority callback + // 2) await Task.Delay(20) — yields to the dispatcher between samples + // If the UI thread blocks synchronously (e.g. someone re-introduces a + // .GetAwaiter().GetResult() call in the load path), that block manifests as a + // huge step in the InvokeAsync latency for that iteration. + var latencies = new List(); + var probeStart = Stopwatch.StartNew(); + while (!loadTasks.All(t => t.IsCompleted) && probeStart.Elapsed < TimeSpan.FromMinutes(2)) + { + var sw = Stopwatch.StartNew(); + await Dispatcher.UIThread.InvokeAsync(static () => { }, DispatcherPriority.Background); + sw.Stop(); + latencies.Add(sw.ElapsedMilliseconds); + await Task.Delay(20); + } + swLoad.Stop(); + + if (latencies.Count == 0) + { + Assert.Fail("dispatcher probe collected no samples — load may have completed before the probe could run"); + return; + } + + latencies.Sort(); + long max = latencies[^1]; + long p50 = latencies[latencies.Count / 2]; + long p95 = latencies[(int)(latencies.Count * 0.95)]; + double mean = latencies.Average(); + + TestContext.Out.WriteLine($"Load completed in {swLoad.ElapsedMilliseconds} ms across {ResponsivenessAssemblyCount} assemblies."); + TestContext.Out.WriteLine($"Dispatcher Background-priority latency over {latencies.Count} samples:"); + TestContext.Out.WriteLine($" max {max} ms"); + TestContext.Out.WriteLine($" p95 {p95} ms"); + TestContext.Out.WriteLine($" p50 {p50} ms"); + TestContext.Out.WriteLine($" mean {mean:0} ms"); + + // p95 keeps the threshold honest — occasional one-off spikes (GC, JIT, the assembly + // post-load Add-to-collection notification) are fine. 200 ms is the boundary where + // the user starts perceiving "stutter"; a sync block on the UI thread would push + // p95 into the seconds. + p95.Should().BeLessThan(200, + $"the UI thread must stay responsive while {ResponsivenessAssemblyCount} assemblies load — " + + $"p95 latency >= 200 ms means something is blocking the dispatcher"); + } + finally + { + try + { Directory.Delete(tempDir, recursive: true); } + catch { /* test cleanup must never fail */ } + } + } +} diff --git a/ILSpy/AssemblyTree/AssemblyTreeModel.cs b/ILSpy/AssemblyTree/AssemblyTreeModel.cs index 491d344a4..55f9c2a9a 100644 --- a/ILSpy/AssemblyTree/AssemblyTreeModel.cs +++ b/ILSpy/AssemblyTree/AssemblyTreeModel.cs @@ -248,6 +248,43 @@ namespace ILSpy.AssemblyTree assemblyListTreeNode = new AssemblyListTreeNode(list); Root = assemblyListTreeNode; AppEnv.StartupLog.Mark("Root assigned"); + ScheduleBackgroundLoadSweep(list); + } + + /// + /// LoadedAssembly entries are now lazy — their Task.Run(LoadAsync) only kicks + /// off when something asks for the metadata. The active assembly's load is awaited + /// by , so it gets a clean run. Everything else + /// only loads on-demand (tree expansion, hyperlink follow, …) which can stretch + /// quietly into "the user never sees a populated icon for assemblies they don't + /// touch". + /// + /// To strike a middle ground, schedule a one-shot sweep a couple of seconds after + /// the list appears that nudges every to start loading + /// in the background. By that point the active assembly's metadata is usually ready + /// and the user has had a frame or two to interact with the tree. + /// + void ScheduleBackgroundLoadSweep(AssemblyList list) + { + _ = Task.Run(async () => { + try + { + await Task.Delay(TimeSpan.FromSeconds(2)).ConfigureAwait(false); + AppEnv.StartupLog.Mark("Background-load sweep starting"); + foreach (var assembly in list.GetAssemblies()) + { + // Calling GetLoadResultAsync triggers the Lazy creation. We don't + // await — fire-and-forget so all 122/200/whatever loads run in parallel + // on the thread pool, just delayed past the active-assembly window. + _ = assembly.GetLoadResultAsync(); + } + AppEnv.StartupLog.Mark("Background-load sweep dispatched"); + } + catch (Exception ex) + { + System.Diagnostics.Debug.WriteLine($"[AssemblyTreeModel] background load sweep failed: {ex}"); + } + }); } /// diff --git a/ILSpy/ViewModels/ToolPaneModel.cs b/ILSpy/ViewModels/ToolPaneModel.cs index 7fce1a6ac..080bbfdfe 100644 --- a/ILSpy/ViewModels/ToolPaneModel.cs +++ b/ILSpy/ViewModels/ToolPaneModel.cs @@ -16,11 +16,21 @@ // OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER // DEALINGS IN THE SOFTWARE. +using Dock.Controls.DeferredContentControl; using Dock.Model.Mvvm.Controls; namespace ILSpy.ViewModels { - public abstract class ToolPaneModel : Tool + /// + /// Base for our docked tool panes (assembly tree, search results, analyzers, …). Opts + /// out of Dock.Avalonia's deferred-content presentation: by default Dock waits for the + /// layout to settle before instantiating each tool pane's view, which on startup costs + /// hundreds of milliseconds between the window painting and the panes appearing. The + /// trees + search results are cheap to materialise (lazy loading handles deeper levels) + /// so eager realisation is the right tradeoff — same as ContentTabPage. + /// + public abstract class ToolPaneModel : Tool, IDeferredContentPresentation { + bool IDeferredContentPresentation.DeferContentPresentation => false; } }