Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion eng/Versions.props
Original file line number Diff line number Diff line change
Expand Up @@ -3,7 +3,7 @@
<Import Project="Version.Details.props" />

<PropertyGroup>
<VersionPrefix>18.5.4</VersionPrefix><DotNetFinalVersionKind>release</DotNetFinalVersionKind><!-- Keep next to VersionPrefix to create a conflict in forward-flow -->
<VersionPrefix>18.5.5</VersionPrefix><DotNetFinalVersionKind>release</DotNetFinalVersionKind><!-- Keep next to VersionPrefix to create a conflict in forward-flow -->
<PreReleaseVersionLabel>servicing</PreReleaseVersionLabel>
<PackageValidationBaselineVersion>18.0.2</PackageValidationBaselineVersion>
<AssemblyVersion>15.1.0.0</AssemblyVersion>
Expand Down
115 changes: 115 additions & 0 deletions src/Build.UnitTests/BackEnd/LoggingService_Tests.cs
Original file line number Diff line number Diff line change
Expand Up @@ -1075,6 +1075,121 @@ public void ImportanceReflectsUnknownLoggerVerbosity()
}
#endregion

#region ProcessLoggingEvent After Shutdown Tests

/// <summary>
/// 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.
/// </summary>
[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();
loggingService.ServiceState.ShouldBe(LoggingServiceState.Shutdown);

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

/// <summary>
/// Verify that ProcessLoggingEvent does not crash when called after the
/// LoggingService has been shut down (synchronous mode).
/// </summary>
[Fact]
public void ProcessLoggingEventAfterShutdown_Synchronous_DoesNotThrow()
{
// _initializedService was created in synchronous mode by InitializeLoggingService().
_initializedService.RegisterLogger(new ConsoleLogger());

((IBuildComponent)_initializedService).ShutdownComponent();
_initializedService.ServiceState.ShouldBe(LoggingServiceState.Shutdown);

// Late log after shutdown - must not crash.
BuildMessageEventArgs lateEvent = new BuildMessageEventArgs("Late message after shutdown", null, null, MessageImportance.Low);
_initializedService.ProcessLoggingEvent(lateEvent);
}

/// <summary>
/// Verify that ProcessLoggingEvent still works normally during an active build
/// (before shutdown). This ensures the fix does not break regular logging.
/// </summary>
[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");
}

/// <summary>
/// Verify that concurrent shutdown and ProcessLoggingEvent calls from multiple
/// threads do not cause a crash (simulates the race condition scenario).
/// </summary>
[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();

bool joined = logThread.Join(TimeSpan.FromSeconds(10));
joined.ShouldBeTrue("Logging thread did not terminate within the allotted time.");
caughtException.ShouldBeNull();
}

#endregion

#region PrivateMethods

/// <summary>
Expand Down
42 changes: 36 additions & 6 deletions src/Build/BackEnd/Components/Logging/LoggingService.cs
Original file line number Diff line number Diff line change
Expand Up @@ -1286,18 +1286,48 @@ public void LogBuildEvent(BuildEventArgs buildEvent)
/// <exception cref="InternalErrorException">buildEvent is null</exception>
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)
{
// Block until queue is not full.
while (_eventQueue.Count >= _queueCapacity)
// Capture local references to prevent race with CleanLoggingEventProcessing
// which sets these fields to null during shutdown.
ConcurrentQueue<object> 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)
{
// Block and wait for dequeue event.
_dequeueEvent.WaitOne();
return;
}

_eventQueue.Enqueue(buildEvent);
_enqueueEvent.Set();
try
{
// Block until queue is not full.
while (eventQueue.Count >= _queueCapacity)
{
// Block and wait for dequeue event.
dequeueEvent.WaitOne();
}

eventQueue.Enqueue(buildEvent);
enqueueEvent.Set();
}
catch (ObjectDisposedException)
{
// Shutdown disposed the wait handles after we captured them;
// silently drop the event.
return;
}
}
else
{
Expand Down