From fc9e71ce22cca652b59ce13bd647d1a5aeceb0d8 Mon Sep 17 00:00:00 2001 From: Hansjoerg Petriffer Date: Wed, 12 Aug 2026 10:31:26 +0200 Subject: [PATCH] [Vsintegration] Fix deadlock when a solution is opened during VS 2026 startup Opening a solution while VS is starting - a solution pinned to the start window or jumplist, or passed on the commandline - deadlocked the IDE in VS 2026. VS 2022 is not affected. The managed solution loader that is new in VS 2026 (Microsoft.VisualStudio.CommonIDE.Solutions) needs our project factory while it walks the projects of the solution, so it demands XSharpProjectPackage synchronously from Solution.OpenAsync -> LoadProjectsLoopAsync -> Project.CanOpenProject -> ProjectTypeManager.HrCanOpenProject and then blocks the UI thread on the package load task in VsTask.InternalGetResult -> UIThreadReentrancyScope.WaitOnTaskComplete -> Task.WaitAny. That is a plain task wait and not a JoinableTask join, so nothing can be inlined onto the blocked UI thread. In VS 2022 the solution is opened over the native path, which does not block this way. Our InitializeAsync blocked on the UI thread from a background thread through JoinableTaskFactory.Run, which can never complete in that situation: the UI thread waits for the package load and the package load waits for the UI thread. The observed stack was XSharpProjectPackage.InitializeAsync -> Logger.Initialize -> Logger.Start -> JoinableTaskFactory.Run -> WaitSynchronously -> CompleteOnCurrentThread. All blocking waits are removed from the package initialization path: - Logger.Initialize becomes InitializeAsync and awaits its work. Start() is split into ConfigureSerilog(), which is pure configuration without VS services, and LogEnvironmentAsync(), which holds everything that needs the UI thread. StartAsync() awaits the latter; the synchronous Start(), which is still needed for ILogger.Start(), fires it and forgets it. This removes four blocking hops: GetVsVersionAsync/ IsOpeningAsync, the synchronous VS.Solutions.GetCurrentSolution() wrapper, GetSolutionExplorerWindowAsync and the COM walk over the solution items. - XSharpShellLink and XSharpShellEvents subscribe to the shell events in an awaited InitializeAsync() instead of calling JoinableTaskFactory.Run in their constructors. - The static XSharpShellEvents constructor no longer shows a modal message box when XSharpMsBuildDir is missing, because that blocks for the UI thread as well. The warning is reported from InitializeAsync(). - Both packages await Logger.InitializeAsync() in their own InitializeAsync. Awaiting SwitchToMainThreadAsync stays as it is. The shell resolves those - the RegisterProjectFactory call in the same method needs the UI thread too, so MPF project packages could not load at all otherwise - only blocking waits cannot be resolved. Two small behaviour changes fall out of the split: the logger is marked active as soon as Serilog is configured instead of after the solution has been enumerated, so messages from other threads reach the log earlier, and the walk over the solution items now runs on the UI thread, which it did not before. Verified in the VS 2026 experimental instance: the build without this change deadlocks reproducibly when devenv is started with the solution as an argument, this build starts through, writes the complete environment block to the log and loads all three packages without an error in the ActivityLog. Co-Authored-By: Claude Opus 5 --- .../LanguageService/XSharpLanguagePackage.cs | 2 +- .../ProjectPackage/XSharpProjectPackage.cs | 9 +- .../ProjectPackage/XSharpShellEvents.cs | 54 ++-- src/VisualStudio/Support/Logger.cs | 290 +++++++++++------- src/VisualStudio/Support/XSharpShellLink.cs | 18 +- 5 files changed, 216 insertions(+), 157 deletions(-) diff --git a/src/VisualStudio/LanguageService/XSharpLanguagePackage.cs b/src/VisualStudio/LanguageService/XSharpLanguagePackage.cs index ed203be557..b0b0171115 100644 --- a/src/VisualStudio/LanguageService/XSharpLanguagePackage.cs +++ b/src/VisualStudio/LanguageService/XSharpLanguagePackage.cs @@ -236,7 +236,7 @@ public void GetIntellisenseSettings(bool load) protected override async System.Threading.Tasks.Task InitializeAsync(CancellationToken cancellationToken, IProgress progress) { instance = this; - Logger.Initialize(); + await Logger.InitializeAsync(); await base.InitializeAsync(cancellationToken, progress); _txtManager = await GetServiceAsync(typeof(SVsTextManager)) as IVsTextManager4; Assumes.Present(_txtManager); diff --git a/src/VisualStudio/ProjectPackage/XSharpProjectPackage.cs b/src/VisualStudio/ProjectPackage/XSharpProjectPackage.cs index da020b38e7..9a77d9ec9b 100644 --- a/src/VisualStudio/ProjectPackage/XSharpProjectPackage.cs +++ b/src/VisualStudio/ProjectPackage/XSharpProjectPackage.cs @@ -174,9 +174,14 @@ public XSharpProjectPackage() : base() /// protected override async Task InitializeAsync(CancellationToken cancellationToken, IProgress progress) { - // Give the codemodel a way to talk to the VS Shell + // Give the codemodel a way to talk to the VS Shell. + // Everything on this path is awaited and must stay that way: when a solution is opened + // while VS is starting, the shell loads this package synchronously from + // Solution.OpenAsync() -> CanOpenProject() and waits for it on the UI thread. Blocking + // here while waiting for that same UI thread deadlocks the IDE. _shellEvents = new XSharpShellEvents(); - XSharp.Support.Logger.Initialize(); + await _shellEvents.InitializeAsync(); + await XSharp.Support.Logger.InitializeAsync(); this.RegisterToolWindows(); await base.InitializeAsync(cancellationToken, progress); diff --git a/src/VisualStudio/ProjectPackage/XSharpShellEvents.cs b/src/VisualStudio/ProjectPackage/XSharpShellEvents.cs index 5783cfcd53..1530436562 100644 --- a/src/VisualStudio/ProjectPackage/XSharpShellEvents.cs +++ b/src/VisualStudio/ProjectPackage/XSharpShellEvents.cs @@ -28,34 +28,22 @@ internal class XSharpShellEvents bool isInitialized = false; static XSharpShellEvents() { + // Only read the environment here. Showing the warning is UI work and would block while + // waiting for the UI thread, which deadlocks when we are constructed during a package + // load that the shell is waiting for. It is reported from InitializeAsync() instead. hasEnvironmentvariable = !string.IsNullOrEmpty(System.Environment.GetEnvironmentVariable("XSharpMsBuildDir")); - if (!hasEnvironmentvariable) - { - VS.MessageBox.ShowWarning("The environment variable 'XSharpMsBuildDir' is missing. \rSome projects may have problems loading. \rPlease run the XSharp setup program again."); - } } - internal XSharpShellEvents() - { - if (ThreadHelper.CheckAccess()) - { - // Already on UI thread - Initialize(); - } - else - { - ThreadHelper.JoinableTaskFactory.Run(async delegate - { - await ThreadHelper.JoinableTaskFactory.SwitchToMainThreadAsync(); - Initialize(); - }); - } - } - internal void Initialize() + /// + /// Subscribe to the shell events. Must be awaited and never waited on: we are called from + /// XSharpProjectPackage.InitializeAsync(), where blocking while waiting for the UI thread + /// deadlocks the IDE. See the remarks on Logger.InitializeAsync(). + /// + internal async Task InitializeAsync() { if (isInitialized) return; - ThreadHelper.ThrowIfNotOnUIThread(); + await ThreadHelper.JoinableTaskFactory.SwitchToMainThreadAsync(); #if DEV17 VS.Events.SolutionEvents.OnAfterOpenSolution += SolutionEvents_OnAfterOpenSolution; #endif @@ -65,20 +53,22 @@ internal void Initialize() VS.Events.SolutionEvents.OnBeforeOpenProject += SolutionEvents_OnBeforeOpenProject; VS.Events.DocumentEvents.Closed += DocumentEvents_Closed; - ThreadHelper.JoinableTaskFactory.Run(async delegate - { - _ = await VS.Commands.InterceptAsync(KnownCommands.File_CloseSolution, CloseDesignerWindows); - _ = await VS.Commands.InterceptAsync(KnownCommands.File_Exit, CloseDesignerWindows); - var sol = await VS.Solutions.GetCurrentSolutionAsync(); + _ = await VS.Commands.InterceptAsync(KnownCommands.File_CloseSolution, CloseDesignerWindows); + _ = await VS.Commands.InterceptAsync(KnownCommands.File_Exit, CloseDesignerWindows); + var sol = await VS.Solutions.GetCurrentSolutionAsync(); #if DEV17 - if (sol is Solution) - { - SolutionEvents_OnAfterOpenSolution(sol); - } + if (sol is Solution) + { + await ThreadHelper.JoinableTaskFactory.SwitchToMainThreadAsync(); + SolutionEvents_OnAfterOpenSolution(sol); + } #endif - }); isInitialized = true; + if (!hasEnvironmentvariable) + { + VS.MessageBox.ShowWarningAsync("The environment variable 'XSharpMsBuildDir' is missing. \rSome projects may have problems loading. \rPlease run the XSharp setup program again.").FireAndForget(); + } } diff --git a/src/VisualStudio/Support/Logger.cs b/src/VisualStudio/Support/Logger.cs index 5cf755769c..856699b54f 100644 --- a/src/VisualStudio/Support/Logger.cs +++ b/src/VisualStudio/Support/Logger.cs @@ -24,13 +24,23 @@ public static class Logger static object gate = new object (); static bool initialized = false; - public static bool Initialize() + /// + /// Initialize the logger and the link to the VS shell. + /// + /// + /// Nothing on this path may block the calling thread, because this is called from the + /// InitializeAsync() of our packages. The shell can load those packages synchronously from + /// Solution.OpenAsync() -> CanOpenProject() when a solution is opened while VS is starting + /// (a pinned solution or a solution on the commandline). The UI thread then waits for the + /// package load to complete, so anything here that blocks while waiting for the UI thread - + /// a JoinableTaskFactory.Run() or one of the synchronous Community Toolkit wrappers - + /// deadlocks the IDE. The work that needs the UI thread is therefore awaited and never + /// waited on: see StartAsync(), LogEnvironmentAsync() and XSharpShellLink.InitializeAsync(). + /// Flags are still set inside the lock and everything else happens after it is released, + /// so we also never hold the lock while waiting for another thread. + /// + public static async System.Threading.Tasks.Task InitializeAsync() { - // Flags set inside the lock; all JoinableTaskFactory.Run work happens outside it. - // Holding a lock while calling JoinableTaskFactory.Run risks a deadlock: the background - // thread blocks waiting for the UI thread, but the UI thread may be waiting to acquire - // the same lock. XSharpShellLink's constructor and Logger.Start/Stop all call - // JoinableTaskFactory.Run, so they must be invoked after the lock is released. bool needsShellLink = false; bool shouldStart = false; bool alreadyActive; @@ -57,13 +67,17 @@ public static bool Initialize() } } if (needsShellLink) - XSettings.ShellLink = new XSharpShellLink(); + { + var shellLink = new XSharpShellLink(); + XSettings.ShellLink = shellLink; + await shellLink.InitializeAsync(); + } if (alreadyActive) return active; if (shouldStart) - Logger.Start(); - else - Logger.Stop(); + await Logger.StartAsync(); + else + Logger.Stop(); return shouldStart; } @@ -73,127 +87,177 @@ public static bool Initialize() static bool active = false; internal static bool Active => active; + /// + /// Start logging. The environment is logged in the background, because that part needs the + /// UI thread. Callers that can await should use StartAsync(). + /// public static void Start() { try { - if (!active || - log2debugger != XSettings.EnableDebugLogging || - log2file != XSettings.EnableFileLogging) + if (ConfigureSerilog()) { - if (active) - { - Stop(); - } - var config = new LoggerConfiguration() - .MinimumLevel.Debug(); - log2debugger = false; - log2file = false; - if (XSettings.EnableDebugLogging) - { - config = config.WriteTo.Debug(); - log2debugger = true; - } - if (XSettings.EnableFileLogging) - { - var temp = Path.GetTempPath(); - temp = Path.Combine(temp, "XSharp.Intellisense"); - if (!Directory.Exists(temp)) - { - Directory.CreateDirectory(temp); - } - int threadid = Process.GetCurrentProcess().Id; - string strId = threadid.ToString("X"); - var log = Path.Combine(temp, "Project_" + strId + "_.log"); - config = config.WriteTo.File(log, - rollingInterval: RollingInterval.Day, - rollOnFileSizeLimit: true, - flushToDiskInterval: TimeSpan.FromSeconds(15), - retainedFileCountLimit: 5); - log2file = true; - } + active = true; + LogEnvironmentAsync().FireAndForget(); + } + // Force all Logging options to be enabled + XSettings.EnableAll(); + } + catch (Exception e) + { + System.Diagnostics.Debug.WriteLine(e.Message); + } + } + /// + /// Start logging without ever blocking the calling thread. Use this from package + /// initialization. See the remarks on InitializeAsync(). + /// + public static async System.Threading.Tasks.Task StartAsync() + { + try + { + if (ConfigureSerilog()) + { + active = true; + await LogEnvironmentAsync(); + } + // Force all Logging options to be enabled + XSettings.EnableAll(); + } + catch (Exception e) + { + System.Diagnostics.Debug.WriteLine(e.Message); + } + } - Log.Logger = config.CreateLogger(); + /// + /// (Re)create the Serilog logger. This is pure configuration: no VS services, no UI thread. + /// + /// TRUE when the logger was (re)created, so the environment must be logged again + private static bool ConfigureSerilog() + { + if (active && + log2debugger == XSettings.EnableDebugLogging && + log2file == XSettings.EnableFileLogging) + { + return false; + } + if (active) + { + Stop(); + } + var config = new LoggerConfiguration() + .MinimumLevel.Debug(); + log2debugger = false; + log2file = false; + if (XSettings.EnableDebugLogging) + { + config = config.WriteTo.Debug(); + log2debugger = true; + } + if (XSettings.EnableFileLogging) + { + var temp = Path.GetTempPath(); + temp = Path.Combine(temp, "XSharp.Intellisense"); + if (!Directory.Exists(temp)) + { + Directory.CreateDirectory(temp); + } + int threadid = Process.GetCurrentProcess().Id; + string strId = threadid.ToString("X"); + var log = Path.Combine(temp, "Project_" + strId + "_.log"); + config = config.WriteTo.File(log, + rollingInterval: RollingInterval.Day, + rollOnFileSizeLimit: true, + flushToDiskInterval: TimeSpan.FromSeconds(15), + retainedFileCountLimit: 5); + log2file = true; + } + + + Log.Logger = config.CreateLogger(); - Log.Information(doubleline); - Log.Information("Started Logging"); - string version = ""; - bool isOpening = false; // This is TRUE when we are opening VS with a solution from the commandline - ThreadHelper.JoinableTaskFactory.Run(async delegate + Log.Information(doubleline); + Log.Information("Started Logging"); + return true; + } + + /// + /// Log the environment and register the current solution with the code model. + /// This needs the UI thread, so it must be awaited and never waited on. + /// + internal static async System.Threading.Tasks.Task LogEnvironmentAsync() + { + try + { + var ver = await VS.Shell.GetVsVersionAsync(); + // This is TRUE when we are opening VS with a solution from the commandline, + // which is also what happens for a solution pinned to the start window or the jumplist + bool isOpening = await VS.Solutions.IsOpeningAsync(); + Log.Information("Visual Studio Exe : " + Process.GetCurrentProcess().MainModule.FileName); + Log.Information("Visual Studio version : " + ver?.ToString()); + Log.Information("XSharp Project System : " + Constants.FileVersion); + Log.Information("Commandline : " + Environment.CommandLine.ToString()); + + + Log.Information(doubleline); + var sol = await VS.Solutions.GetCurrentSolutionAsync(); + if (sol == null) + { + return; + } + Log.Information(singleline); + Log.Information("Current solution: " + sol.FullPath); + if (!XSolution.IsOpen) + XSolution.Open(sol.FullPath); + // we only want to enum projects when the solution explorer window is already visible + bool enumProjects = !isOpening; + if (enumProjects) + { + try { - var ver = await VS.Shell.GetVsVersionAsync(); - isOpening = await VS.Solutions.IsOpeningAsync(); - version = ver.ToString(); - }); - Log.Information("Visual Studio Exe : " + Process.GetCurrentProcess().MainModule.FileName); - Log.Information("Visual Studio version : " + version); - Log.Information("XSharp Project System : " + Constants.FileVersion); - Log.Information("Commandline : " + Environment.CommandLine.ToString()); - - - Log.Information(doubleline); - var sol = VS.Solutions.GetCurrentSolution(); - if (sol != null) + var solwin = await VS.Windows.GetSolutionExplorerWindowAsync(); + enumProjects = solwin != null; + } + catch (Exception) { - Log.Information(singleline); - Log.Information("Current solution: " + sol.FullPath); - if (!XSolution.IsOpen) - XSolution.Open(sol.FullPath); - // we only want to enum projects when the solution explorer window is already visible - bool enumProjects = !isOpening; - if (enumProjects) - { - ThreadHelper.JoinableTaskFactory.Run(async delegate - { - try - { - var solwin = await VS.Windows.GetSolutionExplorerWindowAsync(); - enumProjects = solwin != null; - } - catch (Exception) - { - // This happens when the solution explorer is not visible yet - // do not enum the projects then - enumProjects = false; - } - - }); - } - if (enumProjects) + // This happens when the solution explorer is not visible yet + // do not enum the projects then + enumProjects = false; + } + } + if (enumProjects) + { + // walking the solution items is COM work, so we need the UI thread for that + await ThreadHelper.JoinableTaskFactory.SwitchToMainThreadAsync(); + try + { + var children = EnumChildren(sol, SolutionItemType.Project); + if (children != null) { - var children = EnumChildren(sol, SolutionItemType.Project); - try + foreach (var child in children) { - if (children != null) + if (child.Type == SolutionItemType.Project) { - foreach (var child in children) - { - if (child.Type == SolutionItemType.Project) - { - Log.Information("Project " + child.FullPath); - } - } + Log.Information("Project " + child.FullPath); } } - catch (Exception e) - { - Log.Error(e.Message); - } - } - else - { - Log.Information("No projects opened yet"); } - Log.Information(singleline); - - AppDomain.CurrentDomain.UnhandledException += CurrentDomain_UnhandledException; - //AppDomain.CurrentDomain.FirstChanceException += CurrentDomain_FirstChanceException; } - active = true; + catch (Exception e) + { + Log.Error(e.Message); + } } - // Force all Logging options to be enabled - XSettings.EnableAll(); + else + { + Log.Information("No projects opened yet"); + } + Log.Information(singleline); + + AppDomain.CurrentDomain.UnhandledException += CurrentDomain_UnhandledException; + //AppDomain.CurrentDomain.FirstChanceException += CurrentDomain_FirstChanceException; } catch (Exception e) { diff --git a/src/VisualStudio/Support/XSharpShellLink.cs b/src/VisualStudio/Support/XSharpShellLink.cs index cbcdb3b7d1..9d7974517b 100644 --- a/src/VisualStudio/Support/XSharpShellLink.cs +++ b/src/VisualStudio/Support/XSharpShellLink.cs @@ -33,13 +33,16 @@ internal class XSharpShellLink : IXVsShellLink { static ILogger Logger => XSettings.Logger; - internal XSharpShellLink() + /// + /// Subscribe to the shell events. Must be awaited and never waited on: we are called from + /// the InitializeAsync() of our packages, where blocking while waiting for the UI thread + /// deadlocks the IDE. See the remarks on Logger.InitializeAsync(). + /// + internal async System.Threading.Tasks.Task InitializeAsync() { - ThreadHelper.JoinableTaskFactory.Run(async delegate - { - await ThreadHelper.JoinableTaskFactory.SwitchToMainThreadAsync(); - // Logger may not be fully initialized yet, so guard against null - Logger?.Information("Initialize XSharpShellLink"); + await ThreadHelper.JoinableTaskFactory.SwitchToMainThreadAsync(); + // Logger may not be fully initialized yet, so guard against null + Logger?.Information("Initialize XSharpShellLink"); @@ -88,9 +91,6 @@ internal XSharpShellLink() Logger?.Information("Initialized XSharpShellLink"); - }); - - } private List GetProjects(SolutionItem parent)