Skip to content

Commit

Permalink
Use AutoResetEvent as oppose to ManualResetEventSlim (#8575)
Browse files Browse the repository at this point in the history
Summary
Customer, mainly internal like XStore, with huge repos, using msbuild /graph /bl on powerful development and build computers, might experience 15x plus regression in evaluation time.

It has been identified as performance bug in our logging event pub/sub mechanism. When ingest queue reaches its bound, at .net472 ManualResetEventSlim causes way too many thread.Yields flooding the system with thread context switches.
This hypothesis has been verified by PerfMon perfcounter System.ContextSwitches.

Alhougt counterintuitive, AutoResetEvent , ManualResetEvent or even SpinLocking produced better behavior and with those the issue no longer reproduce.

Customer Impact
In case of XStore it was about 7 minutes in build time.

Regression?
Yes, introduced in VS 17.4.

Testing
Manual validation by @rokonec and automated tests. Using local repro to verify changes has fixed it.

Risk
Low

Note
It effect only VS MSBuild.exe. In dotnet build ManualResetEventSlim works better.
  • Loading branch information
rokonec committed Mar 21, 2023
1 parent f08e881 commit 7e646be
Show file tree
Hide file tree
Showing 2 changed files with 11 additions and 13 deletions.
2 changes: 1 addition & 1 deletion eng/Versions.props
Original file line number Diff line number Diff line change
Expand Up @@ -2,7 +2,7 @@
<!-- Copyright (c) .NET Foundation and contributors. All rights reserved. Licensed under the MIT license. See License.txt in the project root for full license information. -->
<Project>
<PropertyGroup>
<VersionPrefix>17.4.2</VersionPrefix><DotNetFinalVersionKind>release</DotNetFinalVersionKind>
<VersionPrefix>17.4.3</VersionPrefix><DotNetFinalVersionKind>release</DotNetFinalVersionKind>
<AssemblyVersion>15.1.0.0</AssemblyVersion>
<PreReleaseVersionLabel>preview</PreReleaseVersionLabel>
<DotNetUseShippingVersions>true</DotNetUseShippingVersions>
Expand Down
22 changes: 10 additions & 12 deletions src/Build/BackEnd/Components/Logging/LoggingService.cs
Original file line number Diff line number Diff line change
Expand Up @@ -244,15 +244,15 @@ internal partial class LoggingService : ILoggingService, INodePacketHandler, IBu
/// <summary>
/// Event set when message is consumed from queue.
/// </summary>
private ManualResetEventSlim _dequeueEvent;
private AutoResetEvent _dequeueEvent;
/// <summary>
/// Event set when queue become empty.
/// </summary>
private ManualResetEventSlim _emptyQueueEvent;
private ManualResetEvent _emptyQueueEvent;
/// <summary>
/// Even set when message is added into queue.
/// </summary>
private ManualResetEventSlim _enqueueEvent;
private AutoResetEvent _enqueueEvent;

/// <summary>
/// CTS for stopping logging event processing.
Expand Down Expand Up @@ -1184,8 +1184,7 @@ internal virtual void ProcessLoggingEvent(object buildEvent)
while (_eventQueue.Count >= _queueCapacity)
{
// Block and wait for dequeue event.
_dequeueEvent.Wait();
_dequeueEvent.Reset();
_dequeueEvent.WaitOne();
}

_eventQueue.Enqueue(buildEvent);
Expand All @@ -1210,12 +1209,12 @@ public void WaitForLoggingToProcessEvents()
{
while (_eventQueue?.IsEmpty == false)
{
_emptyQueueEvent?.Wait();
_emptyQueueEvent?.WaitOne();
}
// To avoid race condition when last message has been removed from queue but
// not yet fully processed (handled by loggers), we need to make sure _emptyQueueEvent
// is set as it is guaranteed to be in set state no sooner than after event has been processed.
_emptyQueueEvent?.Wait();
_emptyQueueEvent?.WaitOne();
}

/// <summary>
Expand Down Expand Up @@ -1264,9 +1263,9 @@ private static int GetWarningsAsErrorOrMessageKey(BuildEventArgs buildEventArgs)
private void StartLoggingEventProcessing()
{
_eventQueue = new ConcurrentQueue<object>();
_dequeueEvent = new ManualResetEventSlim(false);
_emptyQueueEvent = new ManualResetEventSlim(false);
_enqueueEvent = new ManualResetEventSlim(false);
_dequeueEvent = new AutoResetEvent(false);
_emptyQueueEvent = new ManualResetEvent(false);
_enqueueEvent = new AutoResetEvent(false);
_loggingEventProcessingCancellation = new CancellationTokenSource();

_loggingEventProcessingThread = new Thread(LoggingEventProc);
Expand All @@ -1277,7 +1276,7 @@ private void StartLoggingEventProcessing()
void LoggingEventProc()
{
var completeAdding = _loggingEventProcessingCancellation.Token;
WaitHandle[] waitHandlesForNextEvent = { completeAdding.WaitHandle, _enqueueEvent.WaitHandle };
WaitHandle[] waitHandlesForNextEvent = { completeAdding.WaitHandle, _enqueueEvent };

do
{
Expand All @@ -1296,7 +1295,6 @@ void LoggingEventProc()
WaitHandle.WaitAny(waitHandlesForNextEvent);
}

_enqueueEvent.Reset();
_emptyQueueEvent.Reset();
}
} while (!_eventQueue.IsEmpty || !completeAdding.IsCancellationRequested);
Expand Down

0 comments on commit 7e646be

Please sign in to comment.