From 4d8e4a5e3c1194834c18f3b77415bc6013aabbd4 Mon Sep 17 00:00:00 2001 From: Yuliia Kovalova Date: Thu, 26 Mar 2026 16:11:39 +0100 Subject: [PATCH 1/3] Fix race condition in LoggingService.ProcessLoggingEvent after shutdown ProcessLoggingEvent accessed _eventQueue, _dequeueEvent, and _enqueueEvent directly without checking if the service had been shut down. When an external callback (e.g., Process.Exited from a ProjectCachePlugin) attempted to log after ShutdownComponent() had nullified these fields, a NullReferenceException (access violation 0xC0000005) would occur. The fix: 1. Early return when _serviceState == LoggingServiceState.Shutdown, matching the guard pattern already used by RegisterLogger, RegisterDistributedLogger, InitializeNodeLoggers, and InitializeComponent. 2. Capture field references to local variables before use, matching the existing pattern in LoggingEventProc (the queue pump thread). 3. Null-check the captured locals as a second defense against the race between the _serviceState check and field reads during concurrent shutdown. --- .../BackEnd/LoggingService_Tests.cs | 114 ++++++++++++++++++ .../Components/Logging/LoggingService.cs | 29 ++++- 2 files changed, 139 insertions(+), 4 deletions(-) diff --git a/src/Build.UnitTests/BackEnd/LoggingService_Tests.cs b/src/Build.UnitTests/BackEnd/LoggingService_Tests.cs index 4d42f596bcb..71f5c474eae 100644 --- a/src/Build.UnitTests/BackEnd/LoggingService_Tests.cs +++ b/src/Build.UnitTests/BackEnd/LoggingService_Tests.cs @@ -1075,6 +1075,120 @@ public void ImportanceReflectsUnknownLoggerVerbosity() } #endregion + #region ProcessLoggingEvent After Shutdown Tests + + /// + /// Verify that ProcessLoggingEvent does not crash when called after the + /// LoggingService has been shut down (asynchronous mode). This reproduces + /// the race condition where an external callback (e.g., Process.Exited) + /// tries to log after ShutdownComponent has nullified internal state. + /// + [Fact] + public void ProcessLoggingEventAfterShutdown_Asynchronous_DoesNotThrow() + { + BuildParameters parameters = new BuildParameters(); + parameters.MaxNodeCount = 2; + MockHost mockHost = new MockHost(parameters); + + LoggingService loggingService = (LoggingService)LoggingService.CreateLoggingService(LoggerMode.Asynchronous, 1); + ((IBuildComponent)loggingService).InitializeComponent(mockHost); + loggingService.RegisterLogger(new ConsoleLogger()); + + // Shut down the service, which will null out _eventQueue, _dequeueEvent, _enqueueEvent. + ((IBuildComponent)loggingService).ShutdownComponent(); + Assert.Equal(LoggingServiceState.Shutdown, loggingService.ServiceState); + + // Simulate a late callback (e.g., Process.Exited) trying to log after shutdown. + // This must not throw a NullReferenceException. + BuildMessageEventArgs lateEvent = new BuildMessageEventArgs("Project cache service process exited", null, null, MessageImportance.Low); + loggingService.ProcessLoggingEvent(lateEvent); + } + + /// + /// Verify that ProcessLoggingEvent does not crash when called after the + /// LoggingService has been shut down (synchronous mode). + /// + [Fact] + public void ProcessLoggingEventAfterShutdown_Synchronous_DoesNotThrow() + { + // _initializedService was created in synchronous mode by InitializeLoggingService(). + _initializedService.RegisterLogger(new ConsoleLogger()); + + ((IBuildComponent)_initializedService).ShutdownComponent(); + Assert.Equal(LoggingServiceState.Shutdown, _initializedService.ServiceState); + + // Late log after shutdown - must not crash. + BuildMessageEventArgs lateEvent = new BuildMessageEventArgs("Late message after shutdown", null, null, MessageImportance.Low); + _initializedService.ProcessLoggingEvent(lateEvent); + } + + /// + /// Verify that ProcessLoggingEvent still works normally during an active build + /// (before shutdown). This ensures the fix does not break regular logging. + /// + [Fact] + public void ProcessLoggingEventDuringActiveBuild_StillWorks() + { + MockLogger mockLogger = new MockLogger(); + _initializedService.RegisterLogger(mockLogger); + + BuildMessageEventArgs messageEvent = new BuildMessageEventArgs("Test message during active build", null, null, MessageImportance.High); + _initializedService.ProcessLoggingEvent(messageEvent); + + // In synchronous mode, the event is routed immediately. + mockLogger.BuildMessageEvents.Count.ShouldBe(1); + mockLogger.BuildMessageEvents[0].Message.ShouldBe("Test message during active build"); + } + + /// + /// Verify that concurrent shutdown and ProcessLoggingEvent calls from multiple + /// threads do not cause a crash (simulates the race condition scenario). + /// + [Fact] + public void ProcessLoggingEventConcurrentWithShutdown_DoesNotThrow() + { + BuildParameters parameters = new BuildParameters(); + parameters.MaxNodeCount = 2; + MockHost mockHost = new MockHost(parameters); + + LoggingService loggingService = (LoggingService)LoggingService.CreateLoggingService(LoggerMode.Asynchronous, 1); + ((IBuildComponent)loggingService).InitializeComponent(mockHost); + loggingService.RegisterLogger(new ConsoleLogger()); + + using ManualResetEvent startSignal = new ManualResetEvent(false); + Exception caughtException = null; + + // Start a thread that will log events repeatedly. + Thread logThread = new Thread(() => + { + startSignal.WaitOne(); + for (int i = 0; i < 100; i++) + { + try + { + BuildMessageEventArgs msg = new BuildMessageEventArgs($"Message {i}", null, null, MessageImportance.Low); + loggingService.ProcessLoggingEvent(msg); + } + catch (Exception ex) + { + Interlocked.CompareExchange(ref caughtException, ex, null); + break; + } + } + }); + + logThread.Start(); + + // Signal both threads and immediately shut down from main thread. + startSignal.Set(); + ((IBuildComponent)loggingService).ShutdownComponent(); + + logThread.Join(TimeSpan.FromSeconds(10)); + caughtException.ShouldBeNull(); + } + + #endregion + #region PrivateMethods /// diff --git a/src/Build/BackEnd/Components/Logging/LoggingService.cs b/src/Build/BackEnd/Components/Logging/LoggingService.cs index 24d8dcb0944..104e3d21fb8 100644 --- a/src/Build/BackEnd/Components/Logging/LoggingService.cs +++ b/src/Build/BackEnd/Components/Logging/LoggingService.cs @@ -1286,18 +1286,39 @@ public void LogBuildEvent(BuildEventArgs buildEvent) /// buildEvent is null protected internal virtual void ProcessLoggingEvent(object buildEvent) { + // Avoid processing events after shutdown has cleaned up resources. + // External code (e.g., plugin adapters) may hold references to LoggingService + // and attempt to log after shutdown has nullified internal state. + if (_serviceState == LoggingServiceState.Shutdown) + { + return; + } + ErrorUtilities.VerifyThrow(buildEvent != null, "buildEvent is null"); if (_logMode == LoggerMode.Asynchronous) { + // Capture local references to prevent race with CleanLoggingEventProcessing + // which sets these fields to null during shutdown. + ConcurrentQueue eventQueue = _eventQueue; + AutoResetEvent dequeueEvent = _dequeueEvent; + AutoResetEvent enqueueEvent = _enqueueEvent; + + // Double-check after capturing references in case shutdown raced between + // the _serviceState check above and the field reads. + if (eventQueue == null || dequeueEvent == null || enqueueEvent == null) + { + return; + } + // Block until queue is not full. - while (_eventQueue.Count >= _queueCapacity) + while (eventQueue.Count >= _queueCapacity) { // Block and wait for dequeue event. - _dequeueEvent.WaitOne(); + dequeueEvent.WaitOne(); } - _eventQueue.Enqueue(buildEvent); - _enqueueEvent.Set(); + eventQueue.Enqueue(buildEvent); + enqueueEvent.Set(); } else { From 4ae892abefc2cb6db81933c6cf4831cc4937b28b Mon Sep 17 00:00:00 2001 From: Yuliia Kovalova Date: Thu, 26 Mar 2026 16:25:00 +0100 Subject: [PATCH 2/3] Address review comments: ObjectDisposedException handling, Join assertion, Shouldly consistency - Wrap wait-handle operations (WaitOne/Set) in try/catch for ObjectDisposedException, since shutdown can dispose handles after they are captured into locals but before they are used. - Assert logThread.Join result to prevent silent test hangs. - Switch Assert.Equal to Shouldly ShouldBe for consistency with the rest of the test file. --- .../BackEnd/LoggingService_Tests.cs | 7 +++--- .../Components/Logging/LoggingService.cs | 23 +++++++++++++------ 2 files changed, 20 insertions(+), 10 deletions(-) diff --git a/src/Build.UnitTests/BackEnd/LoggingService_Tests.cs b/src/Build.UnitTests/BackEnd/LoggingService_Tests.cs index 71f5c474eae..7db8ea66ddd 100644 --- a/src/Build.UnitTests/BackEnd/LoggingService_Tests.cs +++ b/src/Build.UnitTests/BackEnd/LoggingService_Tests.cs @@ -1096,7 +1096,7 @@ public void ProcessLoggingEventAfterShutdown_Asynchronous_DoesNotThrow() // Shut down the service, which will null out _eventQueue, _dequeueEvent, _enqueueEvent. ((IBuildComponent)loggingService).ShutdownComponent(); - Assert.Equal(LoggingServiceState.Shutdown, loggingService.ServiceState); + loggingService.ServiceState.ShouldBe(LoggingServiceState.Shutdown); // Simulate a late callback (e.g., Process.Exited) trying to log after shutdown. // This must not throw a NullReferenceException. @@ -1115,7 +1115,7 @@ public void ProcessLoggingEventAfterShutdown_Synchronous_DoesNotThrow() _initializedService.RegisterLogger(new ConsoleLogger()); ((IBuildComponent)_initializedService).ShutdownComponent(); - Assert.Equal(LoggingServiceState.Shutdown, _initializedService.ServiceState); + _initializedService.ServiceState.ShouldBe(LoggingServiceState.Shutdown); // Late log after shutdown - must not crash. BuildMessageEventArgs lateEvent = new BuildMessageEventArgs("Late message after shutdown", null, null, MessageImportance.Low); @@ -1183,7 +1183,8 @@ public void ProcessLoggingEventConcurrentWithShutdown_DoesNotThrow() startSignal.Set(); ((IBuildComponent)loggingService).ShutdownComponent(); - logThread.Join(TimeSpan.FromSeconds(10)); + bool joined = logThread.Join(TimeSpan.FromSeconds(10)); + joined.ShouldBeTrue("Logging thread did not terminate within the allotted time."); caughtException.ShouldBeNull(); } diff --git a/src/Build/BackEnd/Components/Logging/LoggingService.cs b/src/Build/BackEnd/Components/Logging/LoggingService.cs index 104e3d21fb8..65c67c44041 100644 --- a/src/Build/BackEnd/Components/Logging/LoggingService.cs +++ b/src/Build/BackEnd/Components/Logging/LoggingService.cs @@ -1310,15 +1310,24 @@ protected internal virtual void ProcessLoggingEvent(object buildEvent) return; } - // Block until queue is not full. - while (eventQueue.Count >= _queueCapacity) + try { - // Block and wait for dequeue event. - dequeueEvent.WaitOne(); - } + // Block until queue is not full. + while (eventQueue.Count >= _queueCapacity) + { + // Block and wait for dequeue event. + dequeueEvent.WaitOne(); + } - eventQueue.Enqueue(buildEvent); - enqueueEvent.Set(); + eventQueue.Enqueue(buildEvent); + enqueueEvent.Set(); + } + catch (ObjectDisposedException) + { + // Shutdown disposed the wait handles after we captured them; + // silently drop the event. + return; + } } else { From 486376190b1e9c2515f73b8b41a451efdd5dbe34 Mon Sep 17 00:00:00 2001 From: Rainer Sigwald Date: Wed, 15 Apr 2026 17:13:06 -0500 Subject: [PATCH 3/3] Version 18.5.5 --- eng/Versions.props | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/eng/Versions.props b/eng/Versions.props index 095269de9fd..3b30054b1d8 100644 --- a/eng/Versions.props +++ b/eng/Versions.props @@ -3,7 +3,7 @@ - 18.5.4release + 18.5.5release servicing 18.0.2 15.1.0.0