diff --git a/ILSpy/App.axaml.cs b/ILSpy/App.axaml.cs index fbee14e21..89ec8c9c1 100644 --- a/ILSpy/App.axaml.cs +++ b/ILSpy/App.axaml.cs @@ -45,6 +45,7 @@ namespace ILSpy public override void OnFrameworkInitializationCompleted() { + StartupLog.Mark("App.OnFrameworkInitializationCompleted entered"); ILSpyTraceListener.Install(); GlobalExceptionHandler.Install(); @@ -69,6 +70,7 @@ namespace ILSpy try { + using var _ = StartupLog.Phase("AppComposition.Initialize"); Composition = AppComposition.Initialize(); } catch (Exception ex) @@ -84,8 +86,10 @@ namespace ILSpy if (ApplicationLifetime is IClassicDesktopStyleApplicationLifetime desktop) { + StartupLog.Mark("MainWindow about to be resolved from MEF"); desktop.MainWindow = Composition?.GetExport() ?? new MainWindow(); + StartupLog.Mark("MainWindow assigned to desktop.MainWindow"); desktop.Exit += (_, _) => { try { Composition?.GetExport().Save(); } diff --git a/ILSpy/AppEnv/StartupLog.cs b/ILSpy/AppEnv/StartupLog.cs new file mode 100644 index 000000000..74037fe54 --- /dev/null +++ b/ILSpy/AppEnv/StartupLog.cs @@ -0,0 +1,54 @@ +// 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.Diagnostics; + +namespace ILSpy.AppEnv +{ + /// + /// Lightweight timing log for the startup path. Entries land on + /// so they show up in the IDE Debug Output + /// when running under a debugger; release builds elide them. Times are millisecond + /// elapsed since the first call (process-wide), so different log lines are directly + /// comparable. + /// + internal static class StartupLog + { + static readonly Stopwatch sw = Stopwatch.StartNew(); + + public static void Mark(string message) + => Debug.WriteLine($"[startup +{sw.ElapsedMilliseconds,5}ms] {message}"); + + /// + /// Brackets a scope with BEGIN/END markers carrying the duration spent inside. + /// Use with using var _ = StartupLog.Phase("...");. + /// + public static IDisposable Phase(string name) + { + Mark($"BEGIN {name}"); + var local = Stopwatch.StartNew(); + return new PhaseScope(name, local); + } + + sealed class PhaseScope(string name, Stopwatch local) : IDisposable + { + public void Dispose() => Mark($"END {name} ({local.ElapsedMilliseconds}ms)"); + } + } +} diff --git a/ILSpy/AssemblyTree/AssemblyListPane.axaml.cs b/ILSpy/AssemblyTree/AssemblyListPane.axaml.cs index 53d6b7ae9..72ab82cca 100644 --- a/ILSpy/AssemblyTree/AssemblyListPane.axaml.cs +++ b/ILSpy/AssemblyTree/AssemblyListPane.axaml.cs @@ -47,7 +47,10 @@ namespace ILSpy.AssemblyTree public AssemblyListPane() { + AppEnv.StartupLog.Mark("AssemblyListPane ctor entered"); InitializeComponent(); + AttachedToVisualTree += (_, _) => AppEnv.StartupLog.Mark("AssemblyListPane attached to visual tree"); + Loaded += (_, _) => AppEnv.StartupLog.Mark("AssemblyListPane Loaded"); TreeGrid.DoubleTapped += OnTreeGridDoubleTapped; TreeGrid.KeyDown += OnTreeGridKeyDown; // Bubble + handledEventsToo: ProDataGrid's row-level pointer handlers mark @@ -369,11 +372,13 @@ namespace ILSpy.AssemblyTree protected override void OnDataContextChanged(System.EventArgs e) { + using var _ = AppEnv.StartupLog.Phase("AssemblyListPane.OnDataContextChanged"); base.OnDataContextChanged(e); if (DataContext is AssemblyTreeModel model) { model.PropertyChanged += Model_PropertyChanged; + AppEnv.StartupLog.Mark($"AssemblyListPane DataContext is AssemblyTreeModel; Root={(model.Root != null ? "set" : "null")}"); if (model.Root != null) { BindTree(model.Root); @@ -415,6 +420,7 @@ namespace ILSpy.AssemblyTree void BindTree(SharpTreeNode root) { + using var _ = AppEnv.StartupLog.Phase("AssemblyListPane.BindTree"); var settings = languageSettings; var options = new HierarchicalOptions { ChildrenSelector = node => { diff --git a/ILSpy/AssemblyTree/AssemblyTreeModel.cs b/ILSpy/AssemblyTree/AssemblyTreeModel.cs index efd4481f2..491d344a4 100644 --- a/ILSpy/AssemblyTree/AssemblyTreeModel.cs +++ b/ILSpy/AssemblyTree/AssemblyTreeModel.cs @@ -103,6 +103,7 @@ namespace ILSpy.AssemblyTree [ImportingConstructor] public AssemblyTreeModel(SettingsService settingsService, LanguageService languageService) { + AppEnv.StartupLog.Mark("AssemblyTreeModel ctor entered"); this.settingsService = settingsService; this.languageService = languageService; languageService.PropertyChanged += (_, e) => { @@ -113,6 +114,7 @@ namespace ILSpy.AssemblyTree Id = PaneContentId; Title = "Assemblies"; CanClose = false; + AppEnv.StartupLog.Mark("AssemblyTreeModel ctor exited"); } void OnSelectedItemsChanged(object? sender, NotifyCollectionChangedEventArgs e) @@ -145,8 +147,10 @@ namespace ILSpy.AssemblyTree public void Initialize() { + using var _ = AppEnv.StartupLog.Phase("AssemblyTreeModel.Initialize body"); listManager = settingsService.AssemblyListManager; - listManager.CreateDefaultAssemblyLists(); + using (AppEnv.StartupLog.Phase("CreateDefaultAssemblyLists")) + listManager.CreateDefaultAssemblyLists(); SyncListNames(); listManager.AssemblyLists.CollectionChanged += (_, _) => SyncListNames(); @@ -174,14 +178,48 @@ namespace ILSpy.AssemblyTree settingsService.SessionSettings.ActiveAssemblyList = value; ShowAssemblyList(value); - // Restore the previously-selected tree node, if any. Walks the tree by ToString() - // matching, materialising lazy children as it goes. + // Restore the previously-selected tree node off the UI critical path. The walk + // crosses an AssemblyTreeNode whose EnsureLazyChildren synchronously blocks on + // GetLoadResultAsync — by going async here and awaiting the load, we let the + // initial paint happen first and the UI stays responsive while metadata loads. var savedPath = settingsService.SessionSettings.ActiveTreeViewPath; if (savedPath is { Length: > 0 }) + _ = RestoreSelectedPathAsync(savedPath); + } + + async Task RestoreSelectedPathAsync(string[] path) + { + using var _ = AppEnv.StartupLog.Phase($"RestoreSelectedPathAsync ({path.Length} segments)"); + try + { + if (Root == null) + return; + // Snapshot — if the user selects something else before the restore completes, + // don't yank their selection out from under them. + var initialSelection = SelectedItem; + SharpTreeNode? node = Root; + foreach (var element in path) + { + if (node == null) + break; + // Awaiting GetLoadResultAsync keeps EnsureLazyChildren — which itself does + // GetAwaiter().GetResult() on the same task — from blocking the UI thread. + // Once the load completes the .GetAwaiter().GetResult() returns instantly. + if (node is AssemblyTreeNode asm) + { + using (AppEnv.StartupLog.Phase($"await GetLoadResultAsync ({asm.LoadedAssembly.ShortName})")) + await asm.LoadedAssembly.GetLoadResultAsync().ConfigureAwait(true); + } + using (AppEnv.StartupLog.Phase($"EnsureLazyChildren ({node.GetType().Name} \"{element}\")")) + node.EnsureLazyChildren(); + node = node.Children.FirstOrDefault(c => c.ToString() == element); + } + if (node != null && node != Root && ReferenceEquals(SelectedItem, initialSelection)) + SelectedItem = node; + } + catch (Exception ex) { - var restored = FindNodeByPath(savedPath, returnBestMatch: true); - if (restored != null && restored != Root) - SelectedItem = restored; + System.Diagnostics.Debug.WriteLine($"[AssemblyTreeModel] saved-path restore failed: {ex}"); } } @@ -189,18 +227,27 @@ namespace ILSpy.AssemblyTree { if (listManager == null) return; - var list = listManager.LoadList(name); + AssemblyList list; + using (AppEnv.StartupLog.Phase($"LoadList({name})")) + list = listManager.LoadList(name); if (AssemblyList == null || list.ListName != AssemblyList.ListName) ShowAssemblyList(list); } void ShowAssemblyList(AssemblyList list) { + using var _ = AppEnv.StartupLog.Phase("ShowAssemblyList(list)"); AssemblyList = list; if (list.GetAssemblies().Length == 0 && list.ListName == AssemblyListManager.DefaultListName) - LoadInitialAssemblies(list); - assemblyListTreeNode = new AssemblyListTreeNode(list); + { + using (AppEnv.StartupLog.Phase("LoadInitialAssemblies")) + LoadInitialAssemblies(list); + } + AppEnv.StartupLog.Mark($"AssemblyList contains {list.GetAssemblies().Length} assemblies"); + using (AppEnv.StartupLog.Phase("new AssemblyListTreeNode")) + assemblyListTreeNode = new AssemblyListTreeNode(list); Root = assemblyListTreeNode; + AppEnv.StartupLog.Mark("Root assigned"); } /// diff --git a/ILSpy/Docking/DockWorkspace.cs b/ILSpy/Docking/DockWorkspace.cs index d270bf798..738251cb9 100644 --- a/ILSpy/Docking/DockWorkspace.cs +++ b/ILSpy/Docking/DockWorkspace.cs @@ -81,14 +81,18 @@ namespace ILSpy.Docking ToolPaneRegistry toolPaneRegistry, LanguageService languageService) { + ILSpy.AppEnv.StartupLog.Mark("DockWorkspace ctor entered"); this.assemblyTreeModel = assemblyTreeModel; this.languageService = languageService; NavigateBackCommand = new RelayCommand(NavigateBack, () => history.CanNavigateBack); NavigateForwardCommand = new RelayCommand(NavigateForward, () => history.CanNavigateForward); NavigateToHistoryCommand = new RelayCommand(NavigateToHistory, entry => entry != null && (history.BackEntries.Contains(entry) || history.ForwardEntries.Contains(entry))); - factory = new ILSpyDockFactory(toolPaneRegistry); - Layout = factory.CreateLayout(); + using (ILSpy.AppEnv.StartupLog.Phase("ILSpyDockFactory ctor + CreateLayout")) + { + factory = new ILSpyDockFactory(toolPaneRegistry); + Layout = factory.CreateLayout(); + } assemblyTreeModel.PropertyChanged += OnAssemblyTreePropertyChanged; assemblyTreeModel.SelectedItems.CollectionChanged += (_, _) => { @@ -108,6 +112,7 @@ namespace ILSpy.Docking factory.DockableClosed += OnDocumentMembershipChanged; factory.DockableClosing += OnDockableClosing; factory.ActiveDockableChanged += OnActiveDockableChanged; + ILSpy.AppEnv.StartupLog.Mark("DockWorkspace ctor exited"); // TODO: layout persistence (load on startup, save on exit). DockSerializer.SystemTextJson // trips System.Text.Json's MaxDepth=64 limit on our layout because Dock's JsonConverterList diff --git a/ILSpy/ViewModels/MainWindowViewModel.cs b/ILSpy/ViewModels/MainWindowViewModel.cs index 7117107e7..43a7c57fa 100644 --- a/ILSpy/ViewModels/MainWindowViewModel.cs +++ b/ILSpy/ViewModels/MainWindowViewModel.cs @@ -54,10 +54,12 @@ namespace ILSpy.ViewModels DockWorkspace dockWorkspace, SettingsService settingsService) { + AppEnv.StartupLog.Mark("MainWindowViewModel ctor entered (deps already resolved)"); AssemblyTreeModel = assemblyTreeModel; LanguageService = languageService; DockWorkspace = dockWorkspace; LanguageSettings = settingsService.SessionSettings.LanguageSettings; + AppEnv.StartupLog.Mark("MainWindowViewModel ctor exited"); } } } diff --git a/ILSpy/Views/MainWindow.axaml.cs b/ILSpy/Views/MainWindow.axaml.cs index 764c8a6dd..cd17bd323 100644 --- a/ILSpy/Views/MainWindow.axaml.cs +++ b/ILSpy/Views/MainWindow.axaml.cs @@ -22,6 +22,7 @@ using System.Composition; using Avalonia; using Avalonia.Controls; +using ILSpy.AppEnv; using ILSpy.ViewModels; namespace ILSpy.Views @@ -40,14 +41,19 @@ namespace ILSpy.Views [ImportingConstructor] public MainWindow(MainWindowViewModel viewModel, SettingsService settingsService) : this() { + StartupLog.Mark("MainWindow ctor entered"); this.settingsService = settingsService; DataContext = viewModel; ApplySessionSettings(settingsService.SessionSettings); Opened += async (_, _) => { - viewModel.AssemblyTreeModel.Initialize(); + StartupLog.Mark("MainWindow.Opened fired"); + using (StartupLog.Phase("AssemblyTreeModel.Initialize")) + viewModel.AssemblyTreeModel.Initialize(); + StartupLog.Mark("MainWindow.Opened handler returning"); if (App.CommandLineArguments is { } args) await viewModel.AssemblyTreeModel.HandleCommandLineArgumentsAsync(args); }; + StartupLog.Mark("MainWindow ctor exited"); } void ApplySessionSettings(SessionSettings session)