diff --git a/src/modules/cmdpal/Microsoft.CmdPal.UI/Helpers/Icons/IconLoadDiagnostics.cs b/src/modules/cmdpal/Microsoft.CmdPal.UI/Helpers/Icons/IconLoadDiagnostics.cs index fa69962e7b..0dc73ec36d 100644 --- a/src/modules/cmdpal/Microsoft.CmdPal.UI/Helpers/Icons/IconLoadDiagnostics.cs +++ b/src/modules/cmdpal/Microsoft.CmdPal.UI/Helpers/Icons/IconLoadDiagnostics.cs @@ -247,6 +247,22 @@ internal static class IconLoadDiagnostics return new DemandedIdleCapacityMeasurement(session, startedAt); } + internal static SpeculativeDispatchDeferralMeasurement? BeginSpeculativeDispatchDeferral( + int speculativeQueueDepth, + int workerCount, + int reservedWorkerSlots) + { + var session = Volatile.Read(ref _activeSession); + if (session is null) + { + return null; + } + + var startedAt = Stopwatch.GetTimestamp(); + session.RecordSpeculativeDispatchDeferralStarted(speculativeQueueDepth, workerCount, reservedWorkerSlots); + return new SpeculativeDispatchDeferralMeasurement(session, startedAt, workerCount); + } + private static IconLoadInputKind ClassifyInput(string? iconString, bool hasStream) { if (!string.IsNullOrEmpty(iconString)) @@ -415,4 +431,40 @@ internal static class IconLoadDiagnostics } } } + + internal sealed class SpeculativeDispatchDeferralMeasurement + { + private readonly IconLoadDiagnosticsSession _session; + private readonly long _startedAt; + private readonly int _workerCount; + private int _completed; + + public SpeculativeDispatchDeferralMeasurement( + IconLoadDiagnosticsSession session, + long startedAt, + int workerCount) + { + _session = session; + _startedAt = startedAt; + _workerCount = workerCount; + } + + public bool IsForActiveSession => ReferenceEquals(_session, Volatile.Read(ref _activeSession)); + + public void Observe(int speculativeQueueDepth, int reservedWorkerSlots) + { + _session.RecordSpeculativeDispatchDeferralObserved( + speculativeQueueDepth, + _workerCount, + reservedWorkerSlots); + } + + public void Complete() + { + if (Interlocked.Exchange(ref _completed, 1) == 0) + { + _session.RecordSpeculativeDispatchDeferralCompleted(Stopwatch.GetTimestamp() - _startedAt); + } + } + } } diff --git a/src/modules/cmdpal/Microsoft.CmdPal.UI/Helpers/Icons/IconLoadDiagnosticsSession.cs b/src/modules/cmdpal/Microsoft.CmdPal.UI/Helpers/Icons/IconLoadDiagnosticsSession.cs index 8de99d26dc..0a94c5a9f4 100644 --- a/src/modules/cmdpal/Microsoft.CmdPal.UI/Helpers/Icons/IconLoadDiagnosticsSession.cs +++ b/src/modules/cmdpal/Microsoft.CmdPal.UI/Helpers/Icons/IconLoadDiagnosticsSession.cs @@ -66,6 +66,7 @@ internal sealed class IconLoadDiagnosticsSession private readonly DiagnosticHistogram _workerReadyToDemandedDispatchLatency = new(); private readonly DiagnosticHistogram _workerReadyToSpeculativeDispatchLatency = new(); private readonly DiagnosticHistogram _demandedIdleCapacityDuration = new(); + private readonly DiagnosticHistogram _speculativeDispatchDeferralDuration = new(); private readonly InputKindMeasurements[] _inputKindMeasurements = CreateInputKindMeasurements(); private readonly ElementKindMeasurements[] _elementKindMeasurements = CreateElementKindMeasurements(); private readonly ConditionalWeakTable, IconLoadMeasurement> _loadsByTask = new(); @@ -142,6 +143,11 @@ internal sealed class IconLoadDiagnosticsSession private long _currentDemandedIdleCapacityIntervals; private long _maximumDemandedQueueDepthWithIdleCapacity; private long _maximumAvailableWorkerSlotsWithDemandedWork; + private long _speculativeDispatchDeferralIntervalsStarted; + private long _currentSpeculativeDispatchDeferralIntervals; + private long _maximumSpeculativeQueueDepthDuringDeferral; + private long _maximumWorkerCountDuringSpeculativeDispatchDeferral; + private long _maximumReservedWorkerSlotsDuringDeferral; private long _activeWorkers; private long _maximumActiveWorkers; private long _dispatcherEnqueuedDemanded; @@ -315,6 +321,34 @@ internal sealed class IconLoadDiagnosticsSession IconLoadEventSource.Log.DemandedIdleCapacityCompleted(Id, ToMicroseconds(elapsedTicks)); } + public void RecordSpeculativeDispatchDeferralStarted( + int speculativeQueueDepth, + int workerCount, + int reservedWorkerSlots) + { + Interlocked.Increment(ref _speculativeDispatchDeferralIntervalsStarted); + Interlocked.Increment(ref _currentSpeculativeDispatchDeferralIntervals); + RecordSpeculativeDispatchDeferralObserved(speculativeQueueDepth, workerCount, reservedWorkerSlots); + } + + public void RecordSpeculativeDispatchDeferralObserved( + int speculativeQueueDepth, + int workerCount, + int reservedWorkerSlots) + { + UpdateMaximum(ref _maximumSpeculativeQueueDepthDuringDeferral, speculativeQueueDepth); + UpdateMaximum(ref _maximumWorkerCountDuringSpeculativeDispatchDeferral, workerCount); + UpdateMaximum(ref _maximumReservedWorkerSlotsDuringDeferral, reservedWorkerSlots); + } + + public void RecordSpeculativeDispatchDeferralCompleted(long elapsedTicks) + { + var activeIntervals = Interlocked.Decrement(ref _currentSpeculativeDispatchDeferralIntervals); + Debug.Assert(activeIntervals >= 0, "A speculative-dispatch-deferral interval must start before it completes."); + _speculativeDispatchDeferralDuration.Record(elapsedTicks); + IconLoadEventSource.Log.SpeculativeDispatchDeferralCompleted(Id, ToMicroseconds(elapsedTicks)); + } + public IconRequestMeasurement BeginRequest(IconRequestReason reason, double scale, IconRequestOrigin origin) { origin = origin.Normalize(); @@ -1590,6 +1624,34 @@ internal sealed class IconLoadDiagnosticsSession Volatile.Read(ref _maximumAvailableWorkerSlotsWithDemandedWork), " "); _demandedIdleCapacityDuration.Append(builder, "Interval duration", " "); + builder.AppendLine(" Speculative dispatch deferred by the demand reserve"); + builder.AppendLine(" Definition: a coordinator-state interval with speculative work queued, no demanded work queued, and a worker-ready slot deliberately retained for a future live request."); + AppendValue( + builder, + "Intervals started", + Volatile.Read(ref _speculativeDispatchDeferralIntervalsStarted), + " "); + AppendValue( + builder, + "Intervals active at stop", + Math.Max(0, Volatile.Read(ref _currentSpeculativeDispatchDeferralIntervals)), + " "); + AppendValue( + builder, + "Maximum speculative queue depth during an interval", + Volatile.Read(ref _maximumSpeculativeQueueDepthDuringDeferral), + " "); + AppendValue( + builder, + "Maximum configured worker count during an interval", + Volatile.Read(ref _maximumWorkerCountDuringSpeculativeDispatchDeferral), + " "); + AppendValue( + builder, + "Maximum worker-ready slots retained during an interval", + Volatile.Read(ref _maximumReservedWorkerSlotsDuringDeferral), + " "); + _speculativeDispatchDeferralDuration.Append(builder, "Interval duration", " "); } private void AppendLoadDemandMeasurements(StringBuilder builder) diff --git a/src/modules/cmdpal/Microsoft.CmdPal.UI/Helpers/Icons/IconLoadEventSource.cs b/src/modules/cmdpal/Microsoft.CmdPal.UI/Helpers/Icons/IconLoadEventSource.cs index 9fb5b46a4d..08b48a4d75 100644 --- a/src/modules/cmdpal/Microsoft.CmdPal.UI/Helpers/Icons/IconLoadEventSource.cs +++ b/src/modules/cmdpal/Microsoft.CmdPal.UI/Helpers/Icons/IconLoadEventSource.cs @@ -403,6 +403,17 @@ internal sealed partial class IconLoadEventSource : EventSource WriteEvent(37, sessionId, elapsedMicroseconds); } + [Event(38, Level = EventLevel.Informational)] + public void SpeculativeDispatchDeferralCompleted(long sessionId, long elapsedMicroseconds) + { + if (!IsEnabled()) + { + return; + } + + WriteEvent(38, sessionId, elapsedMicroseconds); + } + // These exact overloads intentionally shadow EventSource.WriteEvent(params object?[]). // The params overload allocates an array and boxes values while ETW is enabled, which // would make the icon diagnostics measurably perturb the paths they are observing. diff --git a/src/modules/cmdpal/Microsoft.CmdPal.UI/Helpers/Icons/IconLoadQueue.cs b/src/modules/cmdpal/Microsoft.CmdPal.UI/Helpers/Icons/IconLoadQueue.cs index 662d11385d..6b8ecb1745 100644 --- a/src/modules/cmdpal/Microsoft.CmdPal.UI/Helpers/Icons/IconLoadQueue.cs +++ b/src/modules/cmdpal/Microsoft.CmdPal.UI/Helpers/Icons/IconLoadQueue.cs @@ -27,6 +27,7 @@ internal sealed class IconLoadQueue private readonly Queue _availableWorkerMeasurements = new(); private readonly TaskCompletionSource _schedulerCompletion = new(TaskCreationOptions.RunContinuationsAsynchronously); private readonly Thread _schedulerThread; + private readonly int _workerSlotsReservedForDemand; private readonly int _workerCount; private TaskCompletionSource? _faultedEnqueuePublishersDrained; @@ -41,11 +42,18 @@ internal sealed class IconLoadQueue private int _availableWorkerSlots; private bool _completionRequested; private IconLoadDiagnostics.DemandedIdleCapacityMeasurement? _demandedIdleCapacityMeasurement; + private IconLoadDiagnostics.SpeculativeDispatchDeferralMeasurement? _speculativeDispatchDeferralMeasurement; public IconLoadQueue(int workerCount) { ArgumentOutOfRangeException.ThrowIfLessThan(workerCount, 1); _workerCount = workerCount; + + // Keep one consumer waiting for live demand while only speculative work is + // queued. At two workers this deliberately halves speculative concurrency: + // reserving no slot would let non-preemptible speculative loads occupy all + // capacity. A single-worker queue must still make progress. + _workerSlotsReservedForDemand = workerCount > 1 ? 1 : 0; _readyWork = Channel.CreateUnbounded(new UnboundedChannelOptions { SingleReader = false, @@ -253,9 +261,12 @@ internal sealed class IconLoadQueue command.Measurement?.Processed(); Apply(command); - if (command.Measurement is not null || _demandedIdleCapacityMeasurement is not null) + if (command.Measurement is not null + || _demandedIdleCapacityMeasurement is not null + || _speculativeDispatchDeferralMeasurement is not null) { UpdateDemandedIdleCapacityMeasurement(); + UpdateSpeculativeDispatchDeferralMeasurement(); } commandBeingProcessed = null; @@ -268,6 +279,10 @@ internal sealed class IconLoadQueue UpdateDemandedIdleCapacityMeasurement(); } + // Dispatch can consume the last non-reserved slot and begin a + // deferral interval without another command changing state. + UpdateSpeculativeDispatchDeferralMeasurement(); + if (measureBatch) { wakeMeasurement!.BatchCompleted( @@ -293,6 +308,7 @@ internal sealed class IconLoadQueue try { CompleteDemandedIdleCapacityMeasurement(); + CompleteSpeculativeDispatchDeferralMeasurement(); } catch (Exception ex) { @@ -421,7 +437,7 @@ internal sealed class IconLoadQueue private int DispatchAvailableWorkers() { var dispatchedWorkItemCount = 0; - while (_availableWorkerSlots > 0 && RemoveNext() is { } item) + while (CanDispatchNextWorkItem() && RemoveNext() is { } item) { try { @@ -448,6 +464,24 @@ internal sealed class IconLoadQueue return dispatchedWorkItemCount; } + private bool CanDispatchNextWorkItem() + { + if (_availableWorkerSlots == 0) + { + return false; + } + + if (_demandedHigh.Count != 0 || _demandedLow.Count != 0) + { + return true; + } + + // Speculative work uses at most workerCount - 1 consumers. Because a + // consumer publishes WorkerReady only after its previous load completes, + // retaining this slot also bounds the number of active speculative loads. + return _availableWorkerSlots > _workerSlotsReservedForDemand; + } + private void UpdateDemandedIdleCapacityMeasurement() { var hasDemandedWorkWithIdleCapacity = _availableWorkerSlots > 0 @@ -479,6 +513,43 @@ internal sealed class IconLoadQueue _demandedIdleCapacityMeasurement = null; } + private void UpdateSpeculativeDispatchDeferralMeasurement() + { + var speculativeQueueDepth = _speculativeHigh.Count + _speculativeLow.Count; + var reserveIsDeferringWork = _workerSlotsReservedForDemand > 0 + && _availableWorkerSlots > 0 + && _availableWorkerSlots <= _workerSlotsReservedForDemand + && _demandedHigh.Count == 0 + && _demandedLow.Count == 0 + && speculativeQueueDepth > 0; + if (!reserveIsDeferringWork) + { + CompleteSpeculativeDispatchDeferralMeasurement(); + return; + } + + if (_speculativeDispatchDeferralMeasurement is null + || !_speculativeDispatchDeferralMeasurement.IsForActiveSession) + { + CompleteSpeculativeDispatchDeferralMeasurement(); + _speculativeDispatchDeferralMeasurement = IconLoadDiagnostics.BeginSpeculativeDispatchDeferral( + speculativeQueueDepth, + _workerCount, + _availableWorkerSlots); + return; + } + + _speculativeDispatchDeferralMeasurement.Observe( + speculativeQueueDepth, + _availableWorkerSlots); + } + + private void CompleteSpeculativeDispatchDeferralMeasurement() + { + _speculativeDispatchDeferralMeasurement?.Complete(); + _speculativeDispatchDeferralMeasurement = null; + } + // Strict order by design: speculative work may starve while demanded work keeps // arriving, since no live request is waiting on it. private WorkItem? RemoveNext() diff --git a/src/modules/cmdpal/Tests/Microsoft.CmdPal.UI.UnitTests/IconLoadDiagnosticsTests.cs b/src/modules/cmdpal/Tests/Microsoft.CmdPal.UI.UnitTests/IconLoadDiagnosticsTests.cs index dfefc6c992..9add60f8a1 100644 --- a/src/modules/cmdpal/Tests/Microsoft.CmdPal.UI.UnitTests/IconLoadDiagnosticsTests.cs +++ b/src/modules/cmdpal/Tests/Microsoft.CmdPal.UI.UnitTests/IconLoadDiagnosticsTests.cs @@ -279,6 +279,58 @@ public class IconLoadDiagnosticsTests StringAssert.Contains(report.Text, " Interval duration: count=1"); } + [TestMethod] + [Timeout(5_000)] + public async Task SchedulerReportCapturesSpeculativeDemandReserve() + { + IconLoadDiagnostics.Start(); + var queue = new IconLoadQueue(workerCount: 4); + var speculativeWork = new TestOperation(); + var demandedWork = new TestOperation(); + var speculativeDemand = IconLoadDemand.CreateDemanded(); + speculativeDemand.RemoveRequester(); + + Assert.IsTrue(queue.TryEnqueue( + speculativeWork, + IconLoadPriority.Low, + speculativeDemand, + out _)); + + var reservedDequeue = queue.DequeueAsync().AsTask(); + Assert.IsTrue(queue.TryEnqueue( + demandedWork, + IconLoadPriority.Low, + IconLoadDemand.CreateDemanded(), + out _)); + Assert.AreSame(demandedWork, await reservedDequeue); + + var firstReadyWorker = queue.DequeueAsync().AsTask(); + var secondReadyWorker = queue.DequeueAsync().AsTask(); + var speculativeDequeue = await Task.WhenAny(firstReadyWorker, secondReadyWorker); + Assert.AreSame(speculativeWork, await speculativeDequeue); + + queue.Complete(); + var remainingDequeue = ReferenceEquals(speculativeDequeue, firstReadyWorker) + ? secondReadyWorker + : firstReadyWorker; + Assert.IsNull(await remainingDequeue); + await queue.Completion; + + var report = IconLoadDiagnostics.StopAndCreateReport(); + + Assert.IsNotNull(report); + var reserveBlock = + $" Speculative dispatch deferred by the demand reserve{Environment.NewLine}" + + $" Definition: a coordinator-state interval with speculative work queued, no demanded work queued, and a worker-ready slot deliberately retained for a future live request.{Environment.NewLine}" + + $" Intervals started: 2{Environment.NewLine}" + + $" Intervals active at stop: 0{Environment.NewLine}" + + $" Maximum speculative queue depth during an interval: 1{Environment.NewLine}" + + $" Maximum configured worker count during an interval: 4{Environment.NewLine}" + + $" Maximum worker-ready slots retained during an interval: 1{Environment.NewLine}" + + $" Interval duration: count=2"; + StringAssert.Contains(report.Text, reserveBlock); + } + [TestMethod] public void SchedulerReportSeparatesEmptyCoalescedBatchWakeLatency() { diff --git a/src/modules/cmdpal/Tests/Microsoft.CmdPal.UI.UnitTests/IconLoadEventSourceTests.cs b/src/modules/cmdpal/Tests/Microsoft.CmdPal.UI.UnitTests/IconLoadEventSourceTests.cs index b1acb8588d..2c15e15511 100644 --- a/src/modules/cmdpal/Tests/Microsoft.CmdPal.UI.UnitTests/IconLoadEventSourceTests.cs +++ b/src/modules/cmdpal/Tests/Microsoft.CmdPal.UI.UnitTests/IconLoadEventSourceTests.cs @@ -51,8 +51,9 @@ public sealed class IconLoadEventSourceTests log.DispatcherUiSliceCompleted(11, 14, 52, 53, isDemanded: true, 54); log.DispatcherAsyncSuspensionCompleted(11, 14, 55, isDemanded: false, 56); log.UiResponsivenessProbeCompleted(11, 57); + log.SpeculativeDispatchDeferralCompleted(11, 69); - Assert.AreEqual(30, listener.Events.Count); + Assert.AreEqual(31, listener.Events.Count); Assert.IsFalse(listener.Events.Any(e => e.EventId == 0), listener.GetEventSourceErrors()); CollectionAssert.AreEqual( @@ -88,6 +89,9 @@ public sealed class IconLoadEventSourceTests CollectionAssert.AreEqual( new object?[] { 11L, 14L, 55, false, 56L }, listener.GetEvent(36).Payload!.ToArray()); + CollectionAssert.AreEqual( + new object?[] { 11L, 69L }, + listener.GetEvent(38).Payload!.ToArray()); } private sealed class CollectingEventListener : EventListener diff --git a/src/modules/cmdpal/Tests/Microsoft.CmdPal.UI.UnitTests/IconLoadQueueTests.cs b/src/modules/cmdpal/Tests/Microsoft.CmdPal.UI.UnitTests/IconLoadQueueTests.cs index 37384d67c9..49cb5c3ec1 100644 --- a/src/modules/cmdpal/Tests/Microsoft.CmdPal.UI.UnitTests/IconLoadQueueTests.cs +++ b/src/modules/cmdpal/Tests/Microsoft.CmdPal.UI.UnitTests/IconLoadQueueTests.cs @@ -145,6 +145,89 @@ public class IconLoadQueueTests await queue.Completion; } + [TestMethod] + [DataRow(2)] + [DataRow(4)] + [Timeout(5_000)] + public async Task SpeculativeWorkLeavesOneWorkerAvailableForDemand(int workerCount) + { + var queue = new IconLoadQueue(workerCount); + var releaseSpeculativeWork = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously); + var speculativeCapacityFilled = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously); + var demandedWorkStarted = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously); + var speculativeStarts = 0; + var workers = new Task[workerCount]; + + for (var i = 0; i < workers.Length; i++) + { + workers[i] = RunWorkerAsync(queue); + } + + try + { + for (var i = 0; i < workerCount; i++) + { + var speculativeDemand = IconLoadDemand.CreateDemanded(); + speculativeDemand.RemoveRequester(); + Assert.IsTrue(queue.TryEnqueue( + new TestOperation(async () => + { + if (Interlocked.Increment(ref speculativeStarts) == workerCount - 1) + { + speculativeCapacityFilled.TrySetResult(true); + } + + await releaseSpeculativeWork.Task; + }), + IconLoadPriority.Low, + speculativeDemand, + out _)); + } + + await speculativeCapacityFilled.Task.WaitAsync(TimeSpan.FromSeconds(1)); + + Assert.IsTrue(queue.TryEnqueue( + new TestOperation(() => + { + demandedWorkStarted.TrySetResult(true); + return Task.CompletedTask; + }), + IconLoadPriority.Low, + IconLoadDemand.CreateDemanded(), + out _)); + + await demandedWorkStarted.Task.WaitAsync(TimeSpan.FromSeconds(1)); + Assert.AreEqual(workerCount - 1, Volatile.Read(ref speculativeStarts)); + } + finally + { + queue.Complete(); + releaseSpeculativeWork.TrySetResult(true); + await Task.WhenAll(workers); + await queue.Completion; + } + + Assert.AreEqual(workerCount, speculativeStarts); + } + + [TestMethod] + [Timeout(5_000)] + public async Task SingleWorkerStillProcessesSpeculativeWork() + { + var queue = new IconLoadQueue(workerCount: 1); + var work = new TestOperation(); + var speculativeDemand = IconLoadDemand.CreateDemanded(); + speculativeDemand.RemoveRequester(); + + var dequeue = queue.DequeueAsync().AsTask(); + Assert.IsTrue(queue.TryEnqueue(work, IconLoadPriority.Low, speculativeDemand, out _)); + + Assert.AreSame(work, await dequeue); + queue.Complete(); + Assert.IsNull(await queue.DequeueAsync()); + await queue.Completion; + } + [TestMethod] [Timeout(10_000)] public async Task DemandChurnDuringDequeueRunsEveryWorkExactlyOnce()