Async saved-path restore + StartupLog instrumentation

Saved tree-view path restoration on startup walked the tree synchronously,
calling AssemblyTreeNode.EnsureLazyChildren which itself blocks the UI thread
on assembly.GetLoadResultAsync().GetAwaiter().GetResult(). For users with a
deep saved path that pinned the UI thread until metadata finished loading.

Assisted-by: Claude:claude-opus-4-7:Claude Code

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<MainWindow>()
 					?? new MainWindow();
+				StartupLog.Mark("MainWindow assigned to desktop.MainWindow");
 				desktop.Exit += (_, _) => {
 					try
 					{ Composition?.GetExport<SettingsService>().Save(); }

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
+{
+	/// <summary>
+	/// Lightweight timing log for the startup path. Entries land on
+	/// <see cref="Debug.WriteLine(string)"/> 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.
+	/// </summary>
+	internal static class StartupLog
+	{
+		static readonly Stopwatch sw = Stopwatch.StartNew();
+
+		public static void Mark(string message)
+			=> Debug.WriteLine($"[startup +{sw.ElapsedMilliseconds,5}ms] {message}");
+
+		/// <summary>
+		/// Brackets a scope with BEGIN/END markers carrying the duration spent inside.
+		/// Use with <c>using var _ = StartupLog.Phase("...");</c>.
+		/// </summary>
+		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)");
+		}
+	}
+}

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<SharpTreeNode> {
 				ChildrenSelector = node => {

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()
+			// Restore the previously-selected tree node off the UI critical path. The walk
-			// matching, materialising lazy children as it goes.
+			// 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);
+				System.Diagnostics.Debug.WriteLine($"[AssemblyTreeModel] saved-path restore failed: {ex}");
-				if (restored != null && restored != Root)
-					SelectedItem = restored;
 			}
 		}
 
@@ -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");
 		}
 
 		/// <summary>

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<NavigationEntry>(NavigateToHistory,
 				entry => entry != null && (history.BackEntries.Contains(entry) || history.ForwardEntries.Contains(entry)));
-			factory = new ILSpyDockFactory(toolPaneRegistry);
+			using (ILSpy.AppEnv.StartupLog.Phase("ILSpyDockFactory ctor + CreateLayout"))
-			Layout = factory.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<T>

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");
 		}
 	}
 }

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)