From ce5f5eac9b5c1dc073d310ed216f7556caa382d2 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Amaury=20Lev=C3=A9?= Date: Tue, 21 Jul 2026 17:31:21 +0200 Subject: [PATCH 1/8] Add cooperative slow-test diagnostics for browser Track active tests internally in the simplified browser and WASI output path, and report long-running tests with exponential backoff without relying on threads, processes, or named pipes. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 2eba6c9f-f63f-4726-a0ce-f90ed2404431 --- samples/BrowserPlayground/README.md | 17 ++ .../InternalAPI/InternalAPI.Unshipped.txt | 18 ++ .../OutputDevice/ActiveTestTracker.cs | 119 +++++++++++ .../ProgressReportingConfiguration.cs | 24 +++ .../SimplifiedConsoleOutputDeviceBase.cs | 113 ++++++++++ .../TerminalOutputDevice.Initialization.cs | 19 +- .../OutputDevice/TerminalOutputDevice.cs | 6 - .../OutputDevice/ActiveTestTrackerTests.cs | 136 ++++++++++++ .../SimplifiedConsoleOutputDeviceTests.cs | 199 +++++++++++++++++- 9 files changed, 623 insertions(+), 28 deletions(-) create mode 100644 src/Platform/Microsoft.Testing.Platform/OutputDevice/ActiveTestTracker.cs create mode 100644 src/Platform/Microsoft.Testing.Platform/OutputDevice/ProgressReportingConfiguration.cs create mode 100644 test/UnitTests/Microsoft.Testing.Platform.UnitTests/OutputDevice/ActiveTestTrackerTests.cs diff --git a/samples/BrowserPlayground/README.md b/samples/BrowserPlayground/README.md index df47ffba2d..8b4a78ac83 100644 --- a/samples/BrowserPlayground/README.md +++ b/samples/BrowserPlayground/README.md @@ -124,6 +124,23 @@ countdown-event wait, and the adapter's per-test task factory. Console output is routed through `BrowserOutputDevice`, which forwards to the browser's `globalThis.console.*` APIs via `[JSImport]`. +Long-running tests are surfaced as durable diagnostic lines after 60 seconds, with +exponential backoff (60 seconds, 2 minutes, 4 minutes, and so on): + +```console +[slow] still running after 1m 00s: MyLongRunningTest +``` + +Set `MTP_PROGRESS_SLOW_TEST_SECONDS` to a non-negative integer to change the first +reporting threshold; `0` disables these diagnostics. Test starts are tracked silently, +so this does not duplicate normal per-test progress output. + +The reporter is cooperative: it uses asynchronous delays and does not create a thread, +timer thread, or process. It can therefore identify an asynchronously suspended test, +because control returns to the browser event loop. It cannot report while a test +synchronously blocks the sole WebAssembly thread; no managed timer or continuation can +run until that test yields or returns. + ### Feature matrix (what is *not* available on browser-wasm) Several extensions/capabilities are intentionally unavailable in the browser sandbox and diff --git a/src/Platform/Microsoft.Testing.Platform/InternalAPI/InternalAPI.Unshipped.txt b/src/Platform/Microsoft.Testing.Platform/InternalAPI/InternalAPI.Unshipped.txt index 103558d233..bfb5ceb744 100644 --- a/src/Platform/Microsoft.Testing.Platform/InternalAPI/InternalAPI.Unshipped.txt +++ b/src/Platform/Microsoft.Testing.Platform/InternalAPI/InternalAPI.Unshipped.txt @@ -195,3 +195,21 @@ Microsoft.Testing.Platform.OutputDevice.Terminal.TerminalTestReporter.TerminalTe Microsoft.Testing.Platform.OutputDevice.Terminal.TestProgressStateAwareTerminal.TestProgressStateAwareTerminal(Microsoft.Testing.Platform.OutputDevice.Terminal.ITerminal! terminal, System.Func! showProgress, Microsoft.Testing.Platform.OutputDevice.Terminal.IProgressRenderer! renderer, Microsoft.Testing.Platform.Logging.ILogger! logger) -> void Microsoft.Testing.Platform.ServerMode.ServerModeManager.MessageHandlerFactory.MessageHandlerFactory(string! host, int port, Microsoft.Testing.Platform.OutputDevice.IOutputDevice! outputDevice, Microsoft.Testing.Platform.Logging.ILogger! logger) -> void Microsoft.Testing.Platform.ServerMode.TcpMessageHandler.TcpMessageHandler(System.Net.Sockets.TcpClient! client, System.IO.Stream! clientToServerStream, System.IO.Stream! serverToClientStream, Microsoft.Testing.Platform.ServerMode.IMessageFormatter! formatter, Microsoft.Testing.Platform.Logging.ILogger! logger) -> void +const Microsoft.Testing.Platform.OutputDevice.ProgressReportingConfiguration.MTP_PROGRESS_SILENCE_SECONDS = "MTP_PROGRESS_SILENCE_SECONDS" -> string! +const Microsoft.Testing.Platform.OutputDevice.ProgressReportingConfiguration.MTP_PROGRESS_SLOW_TEST_SECONDS = "MTP_PROGRESS_SLOW_TEST_SECONDS" -> string! +Microsoft.Testing.Platform.OutputDevice.ActiveTestTracker +Microsoft.Testing.Platform.OutputDevice.ActiveTestTracker.ActiveTestTracker(System.TimeSpan slowTestThreshold, System.Func! createStopwatch) -> void +Microsoft.Testing.Platform.OutputDevice.ActiveTestTracker.Clear() -> void +Microsoft.Testing.Platform.OutputDevice.ActiveTestTracker.Complete(Microsoft.Testing.Platform.Extensions.Messages.TestNodeUid! uid) -> void +Microsoft.Testing.Platform.OutputDevice.ActiveTestTracker.GetDueDiagnostics() -> Microsoft.Testing.Platform.OutputDevice.SlowTestDiagnostic![]! +Microsoft.Testing.Platform.OutputDevice.ActiveTestTracker.IsEnabled.get -> bool +Microsoft.Testing.Platform.OutputDevice.ActiveTestTracker.Start(Microsoft.Testing.Platform.Extensions.Messages.TestNodeUid! uid, string! displayName) -> void +Microsoft.Testing.Platform.OutputDevice.ProgressReportingConfiguration +Microsoft.Testing.Platform.OutputDevice.SimplifiedConsoleOutputDeviceBase.ReportSlowTestsOnceAsync(System.Threading.CancellationToken cancellationToken) -> System.Threading.Tasks.Task! +Microsoft.Testing.Platform.OutputDevice.SimplifiedConsoleOutputDeviceBase.SimplifiedConsoleOutputDeviceBase(Microsoft.Testing.Platform.Helpers.IConsole! console, Microsoft.Testing.Platform.Services.ITestApplicationModuleInfo! testApplicationModuleInfo, Microsoft.Testing.Platform.Helpers.IAsyncMonitor! asyncMonitor, Microsoft.Testing.Platform.Helpers.IRuntimeFeature! runtimeFeature, Microsoft.Testing.Platform.Helpers.IEnvironment! environment, Microsoft.Testing.Platform.Services.IPlatformInformation! platformInformation, Microsoft.Testing.Platform.Services.IStopPoliciesService! policiesService, System.TimeSpan slowTestThreshold, System.Func! createStopwatch, System.TimeSpan slowTestPollInterval) -> void +Microsoft.Testing.Platform.OutputDevice.SlowTestDiagnostic +Microsoft.Testing.Platform.OutputDevice.SlowTestDiagnostic.DisplayName.get -> string! +Microsoft.Testing.Platform.OutputDevice.SlowTestDiagnostic.Elapsed.get -> System.TimeSpan +Microsoft.Testing.Platform.OutputDevice.SlowTestDiagnostic.SlowTestDiagnostic(Microsoft.Testing.Platform.Extensions.Messages.TestNodeUid! uid, string! displayName, System.TimeSpan elapsed) -> void +Microsoft.Testing.Platform.OutputDevice.SlowTestDiagnostic.Uid.get -> Microsoft.Testing.Platform.Extensions.Messages.TestNodeUid! +static Microsoft.Testing.Platform.OutputDevice.ProgressReportingConfiguration.GetThreshold(Microsoft.Testing.Platform.Helpers.IEnvironment! environment, string! variableName, int defaultSeconds) -> System.TimeSpan diff --git a/src/Platform/Microsoft.Testing.Platform/OutputDevice/ActiveTestTracker.cs b/src/Platform/Microsoft.Testing.Platform/OutputDevice/ActiveTestTracker.cs new file mode 100644 index 0000000000..2e4c2cedda --- /dev/null +++ b/src/Platform/Microsoft.Testing.Platform/OutputDevice/ActiveTestTracker.cs @@ -0,0 +1,119 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT license. See LICENSE file in the project root for full license information. + +using Microsoft.Testing.Platform.Extensions.Messages; +using Microsoft.Testing.Platform.Helpers; + +namespace Microsoft.Testing.Platform.OutputDevice; + +internal sealed class ActiveTestTracker +{ +#if NET9_0_OR_GREATER + private readonly Lock _lock = new(); +#else + private readonly object _lock = new(); +#endif + private readonly TimeSpan _slowTestThreshold; + private readonly Func _createStopwatch; + private readonly Dictionary _activeTests = []; + + internal ActiveTestTracker(TimeSpan slowTestThreshold, Func createStopwatch) + { + _slowTestThreshold = slowTestThreshold; + _createStopwatch = createStopwatch; + } + + internal bool IsEnabled => _slowTestThreshold > TimeSpan.Zero; + + internal void Start(TestNodeUid uid, string displayName) + { + if (!IsEnabled) + { + return; + } + + lock (_lock) + { + if (!_activeTests.ContainsKey(uid)) + { + _activeTests.Add(uid, new(displayName, _createStopwatch(), _slowTestThreshold.Ticks)); + } + } + } + + internal void Complete(TestNodeUid uid) + { + lock (_lock) + { + _activeTests.Remove(uid); + } + } + + internal SlowTestDiagnostic[] GetDueDiagnostics() + { + lock (_lock) + { + if (_activeTests.Count == 0) + { + return []; + } + + var diagnostics = new List(); + foreach ((TestNodeUid uid, ActiveTest activeTest) in _activeTests.OrderBy(static pair => pair.Key.Value, StringComparer.Ordinal)) + { + long elapsedTicks = activeTest.Stopwatch.Elapsed.Ticks; + if (elapsedTicks < activeTest.NextThresholdTicks) + { + continue; + } + + diagnostics.Add(new(uid, activeTest.DisplayName, TimeSpan.FromTicks(elapsedTicks))); + activeTest.NextThresholdTicks = GetNextThreshold(activeTest.NextThresholdTicks, elapsedTicks); + } + + return [.. diagnostics]; + } + } + + internal void Clear() + { + lock (_lock) + { + _activeTests.Clear(); + } + } + + private static long GetNextThreshold(long currentThresholdTicks, long elapsedTicks) + { + long nextThresholdTicks = currentThresholdTicks; + while (nextThresholdTicks <= elapsedTicks) + { + if (nextThresholdTicks > long.MaxValue / 2) + { + return long.MaxValue; + } + + nextThresholdTicks *= 2; + } + + return nextThresholdTicks; + } + + private sealed class ActiveTest(string displayName, IStopwatch stopwatch, long nextThresholdTicks) + { + public string DisplayName { get; } = displayName; + + public IStopwatch Stopwatch { get; } = stopwatch; + + public long NextThresholdTicks { get; set; } = nextThresholdTicks; + } +} + +internal sealed class SlowTestDiagnostic(TestNodeUid uid, string displayName, TimeSpan elapsed) +{ + internal TestNodeUid Uid { get; } = uid; + + internal string DisplayName { get; } = displayName; + + internal TimeSpan Elapsed { get; } = elapsed; +} diff --git a/src/Platform/Microsoft.Testing.Platform/OutputDevice/ProgressReportingConfiguration.cs b/src/Platform/Microsoft.Testing.Platform/OutputDevice/ProgressReportingConfiguration.cs new file mode 100644 index 0000000000..857cf42396 --- /dev/null +++ b/src/Platform/Microsoft.Testing.Platform/OutputDevice/ProgressReportingConfiguration.cs @@ -0,0 +1,24 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT license. See LICENSE file in the project root for full license information. + +using Microsoft.Testing.Platform.Helpers; + +namespace Microsoft.Testing.Platform.OutputDevice; + +internal static class ProgressReportingConfiguration +{ +#pragma warning disable SA1310 // Field names should not contain underscore + internal const string MTP_PROGRESS_SILENCE_SECONDS = nameof(MTP_PROGRESS_SILENCE_SECONDS); + internal const string MTP_PROGRESS_SLOW_TEST_SECONDS = nameof(MTP_PROGRESS_SLOW_TEST_SECONDS); +#pragma warning restore SA1310 // Field names should not contain underscore + + internal static TimeSpan GetThreshold(IEnvironment environment, string variableName, int defaultSeconds) + { + string? raw = environment.GetEnvironmentVariable(variableName); + return !RoslynString.IsNullOrWhiteSpace(raw) + && int.TryParse(raw, NumberStyles.Integer, CultureInfo.InvariantCulture, out int seconds) + && seconds >= 0 + ? TimeSpan.FromSeconds(seconds) + : TimeSpan.FromSeconds(defaultSeconds); + } +} diff --git a/src/Platform/Microsoft.Testing.Platform/OutputDevice/SimplifiedConsoleOutputDeviceBase.cs b/src/Platform/Microsoft.Testing.Platform/OutputDevice/SimplifiedConsoleOutputDeviceBase.cs index c0236ee064..efe1a7bf35 100644 --- a/src/Platform/Microsoft.Testing.Platform/OutputDevice/SimplifiedConsoleOutputDeviceBase.cs +++ b/src/Platform/Microsoft.Testing.Platform/OutputDevice/SimplifiedConsoleOutputDeviceBase.cs @@ -27,6 +27,8 @@ internal abstract class SimplifiedConsoleOutputDeviceBase : IPlatformOutputDevic private readonly IEnvironment _environment; private readonly IPlatformInformation _platformInformation; private readonly IStopPoliciesService _policiesService; + private readonly ActiveTestTracker _activeTestTracker; + private readonly TimeSpan _slowTestPollInterval; private readonly string? _longArchitecture; private readonly Dictionary _progressMessages = []; @@ -40,6 +42,8 @@ internal abstract class SimplifiedConsoleOutputDeviceBase : IPlatformOutputDevic private bool _firstCallTo_OnSessionStartingAsync = true; private bool _bannerDisplayed; private volatile bool _wasCancelled; + private CancellationTokenSource? _slowTestReporterCancellationTokenSource; + private Task? _slowTestReporterTask; private int _passedTests; private int _failedTests; @@ -50,6 +54,27 @@ protected SimplifiedConsoleOutputDeviceBase( ITestApplicationModuleInfo testApplicationModuleInfo, IAsyncMonitor asyncMonitor, IRuntimeFeature runtimeFeature, IEnvironment environment, IPlatformInformation platformInformation, IStopPoliciesService policiesService) + : this( + console, + testApplicationModuleInfo, + asyncMonitor, + runtimeFeature, + environment, + platformInformation, + policiesService, + ProgressReportingConfiguration.GetThreshold( + environment, ProgressReportingConfiguration.MTP_PROGRESS_SLOW_TEST_SECONDS, defaultSeconds: 60), + SystemStopwatch.StartNew, + TimeSpan.FromSeconds(1)) + { + } + + internal SimplifiedConsoleOutputDeviceBase( + IConsole console, + ITestApplicationModuleInfo testApplicationModuleInfo, IAsyncMonitor asyncMonitor, + IRuntimeFeature runtimeFeature, IEnvironment environment, IPlatformInformation platformInformation, + IStopPoliciesService policiesService, TimeSpan slowTestThreshold, + Func createStopwatch, TimeSpan slowTestPollInterval) { _console = console; _asyncMonitor = asyncMonitor; @@ -57,6 +82,8 @@ protected SimplifiedConsoleOutputDeviceBase( _environment = environment; _platformInformation = platformInformation; _policiesService = policiesService; + _activeTestTracker = new(slowTestThreshold, createStopwatch); + _slowTestPollInterval = slowTestPollInterval; if (_runtimeFeature.IsDynamicCodeSupported) { @@ -207,9 +234,33 @@ public async Task DisplayAfterSessionEndRunAsync(CancellationToken cancellationT public async Task OnTestSessionFinishingAsync(ITestSessionContext testSessionContext) { + CancellationTokenSource? cancellationTokenSource = _slowTestReporterCancellationTokenSource; + Task? reporterTask = _slowTestReporterTask; + _slowTestReporterCancellationTokenSource = null; + _slowTestReporterTask = null; + +#if NET + if (cancellationTokenSource is { } cts) + { + await cts.CancelAsync().ConfigureAwait(false); + } +#else +#pragma warning disable VSTHRD103 // CancellationTokenSource.CancelAsync is not available on this target framework. + cancellationTokenSource?.Cancel(); +#pragma warning restore VSTHRD103 +#endif + + if (reporterTask is not null) + { + await reporterTask.ConfigureAwait(false); + } + + cancellationTokenSource?.Dispose(); + using (await _asyncMonitor.LockAsync(TimeoutHelper.DefaultHangTimeSpanTimeout).ConfigureAwait(false)) { _progressMessages.Clear(); + _activeTestTracker.Clear(); } } @@ -224,6 +275,11 @@ public Task OnTestSessionStartingAsync(ITestSessionContext testSessionContext) if (_firstCallTo_OnSessionStartingAsync) { _firstCallTo_OnSessionStartingAsync = false; + if (_activeTestTracker.IsEnabled) + { + _slowTestReporterCancellationTokenSource = CancellationTokenSource.CreateLinkedTokenSource(cancellationToken); + _slowTestReporterTask = ReportSlowTestsAsync(_slowTestReporterCancellationTokenSource.Token); + } } return Task.CompletedTask; @@ -343,6 +399,18 @@ public Task ConsumeAsync(IDataProducer dataProducer, IData value, CancellationTo TimeSpan? duration = timingProp?.GlobalTiming.Duration; + if (nodeStateProp is InProgressTestNodeStateProperty) + { + _activeTestTracker.Start(testNodeStateChanged.TestNode.Uid, testNodeStateChanged.TestNode.DisplayName); + } +#pragma warning disable CS0618, MTP0001 // Type or member is obsolete + else if (nodeStateProp is PassedTestNodeStateProperty or ErrorTestNodeStateProperty or CancelledTestNodeStateProperty +#pragma warning restore CS0618, MTP0001 // Type or member is obsolete + or FailedTestNodeStateProperty or TimeoutTestNodeStateProperty or SkippedTestNodeStateProperty) + { + _activeTestTracker.Complete(testNodeStateChanged.TestNode.Uid); + } + switch (nodeStateProp) { case InProgressTestNodeStateProperty: @@ -398,6 +466,51 @@ public Task ConsumeAsync(IDataProducer dataProducer, IData value, CancellationTo return Task.CompletedTask; } + /// + /// Reports tests that have crossed their next slow-test threshold. + /// + /// + /// Browser WebAssembly runs this cooperatively. Delay continuations can run while a test is asynchronously + /// suspended, but no managed diagnostic can execute while a test synchronously blocks the sole WebAssembly thread. + /// + internal async Task ReportSlowTestsOnceAsync(CancellationToken cancellationToken) + { + SlowTestDiagnostic[] diagnostics = _activeTestTracker.GetDueDiagnostics(); + if (diagnostics.Length == 0) + { + return; + } + + using (await _asyncMonitor.LockAsync(TimeoutHelper.DefaultHangTimeSpanTimeout).ConfigureAwait(false)) + { + cancellationToken.ThrowIfCancellationRequested(); + foreach (SlowTestDiagnostic diagnostic in diagnostics) + { + string duration = HumanReadableDurationFormatter.Render(diagnostic.Elapsed, wrapInParentheses: false); + ConsoleLog(string.Format( + CultureInfo.CurrentCulture, + TerminalResources.TerminalProgressSlowTest, + duration, + diagnostic.DisplayName)); + } + } + } + + private async Task ReportSlowTestsAsync(CancellationToken cancellationToken) + { + try + { + while (true) + { + await Task.Delay(_slowTestPollInterval, cancellationToken).ConfigureAwait(false); + await ReportSlowTestsOnceAsync(cancellationToken).ConfigureAwait(false); + } + } + catch (OperationCanceledException) when (cancellationToken.IsCancellationRequested) + { + } + } + public async Task HandleProcessRoleAsync(TestProcessRole processRole, CancellationToken cancellationToken) { if (processRole == TestProcessRole.TestHost) diff --git a/src/Platform/Microsoft.Testing.Platform/OutputDevice/TerminalOutputDevice.Initialization.cs b/src/Platform/Microsoft.Testing.Platform/OutputDevice/TerminalOutputDevice.Initialization.cs index fdc09b8adc..9f9d2056df 100644 --- a/src/Platform/Microsoft.Testing.Platform/OutputDevice/TerminalOutputDevice.Initialization.cs +++ b/src/Platform/Microsoft.Testing.Platform/OutputDevice/TerminalOutputDevice.Initialization.cs @@ -170,8 +170,10 @@ await _policiesService.RegisterOnAbortCallbackAsync( ShowProgress = shouldShowProgress, ShowStdout = showStdout, ShowStderr = showStderr, - HeartbeatSilenceThreshold = GetProgressThreshold(_environment, MTP_PROGRESS_SILENCE_SECONDS, defaultSeconds: 30), - SlowTestThreshold = GetProgressThreshold(_environment, MTP_PROGRESS_SLOW_TEST_SECONDS, defaultSeconds: 60), + HeartbeatSilenceThreshold = ProgressReportingConfiguration.GetThreshold( + _environment, ProgressReportingConfiguration.MTP_PROGRESS_SILENCE_SECONDS, defaultSeconds: 30), + SlowTestThreshold = ProgressReportingConfiguration.GetThreshold( + _environment, ProgressReportingConfiguration.MTP_PROGRESS_SLOW_TEST_SECONDS, defaultSeconds: 60), SlowestTestsCount = slowestTestsCount, }, _loggerFactory.CreateLogger()); } @@ -188,19 +190,6 @@ internal static int GetSlowestTestsCount(ICommandLineOptions commandLineOptions) ? count : 0; - // Reads an integer number of seconds from the given environment variable, falling back to - // when unset or invalid. A value of 0 disables the related - // heartbeat rule (returns TimeSpan.Zero). Negative or non-integer values are ignored. - private static TimeSpan GetProgressThreshold(IEnvironment environment, string variableName, int defaultSeconds) - { - string? raw = environment.GetEnvironmentVariable(variableName); - return !RoslynString.IsNullOrWhiteSpace(raw) - && int.TryParse(raw, NumberStyles.Integer, CultureInfo.InvariantCulture, out int seconds) - && seconds >= 0 - ? TimeSpan.FromSeconds(seconds) - : TimeSpan.FromSeconds(defaultSeconds); - } - // When the option is absent, default to OutputShowMode.Failed when running under a known // LLM/AI environment (less token noise for agents) and to OutputShowMode.All otherwise. // An explicit --show-stdout/--show-stderr value always wins over the LLM-aware default. diff --git a/src/Platform/Microsoft.Testing.Platform/OutputDevice/TerminalOutputDevice.cs b/src/Platform/Microsoft.Testing.Platform/OutputDevice/TerminalOutputDevice.cs index d091b80f3a..09163bef40 100644 --- a/src/Platform/Microsoft.Testing.Platform/OutputDevice/TerminalOutputDevice.cs +++ b/src/Platform/Microsoft.Testing.Platform/OutputDevice/TerminalOutputDevice.cs @@ -24,12 +24,6 @@ internal sealed partial class TerminalOutputDevice : IHotReloadPlatformOutputDev IDisposable, IAsyncInitializableExtension { -#pragma warning disable SA1310 // Field names should not contain underscore - // Opt-in knobs (env vars only) for the silence-driven heartbeat renderer used in non-cursor modes. - private const string MTP_PROGRESS_SILENCE_SECONDS = nameof(MTP_PROGRESS_SILENCE_SECONDS); - private const string MTP_PROGRESS_SLOW_TEST_SECONDS = nameof(MTP_PROGRESS_SLOW_TEST_SECONDS); -#pragma warning restore SA1310 // Field names should not contain underscore - private const char Dash = '-'; // Guards the one-per-process deprecation warning emitted when the legacy --no-progress flag is used. diff --git a/test/UnitTests/Microsoft.Testing.Platform.UnitTests/OutputDevice/ActiveTestTrackerTests.cs b/test/UnitTests/Microsoft.Testing.Platform.UnitTests/OutputDevice/ActiveTestTrackerTests.cs new file mode 100644 index 0000000000..6637e4b654 --- /dev/null +++ b/test/UnitTests/Microsoft.Testing.Platform.UnitTests/OutputDevice/ActiveTestTrackerTests.cs @@ -0,0 +1,136 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT license. See LICENSE file in the project root for full license information. + +using Microsoft.Testing.Platform.Helpers; +using Microsoft.Testing.Platform.OutputDevice; + +namespace Microsoft.Testing.Platform.UnitTests.OutputDevice; + +[TestClass] +public sealed class ActiveTestTrackerTests +{ + private static readonly TimeSpan SlowThreshold = TimeSpan.FromSeconds(60); + + [TestMethod] + public void GetDueDiagnostics_UsesExponentialBackoff() + { + var clock = new FakeClock(); + var tracker = new ActiveTestTracker(SlowThreshold, clock.CreateStopwatch); + tracker.Start("uid", "SlowTest"); + + clock.Advance(TimeSpan.FromSeconds(59)); + Assert.IsEmpty(tracker.GetDueDiagnostics()); + + clock.Advance(TimeSpan.FromSeconds(1)); + SlowTestDiagnostic[] firstDiagnostics = tracker.GetDueDiagnostics(); + Assert.HasCount(1, firstDiagnostics); + SlowTestDiagnostic first = firstDiagnostics[0]; + Assert.AreEqual("uid", first.Uid.Value); + Assert.AreEqual("SlowTest", first.DisplayName); + Assert.AreEqual(TimeSpan.FromSeconds(60), first.Elapsed); + + clock.Advance(TimeSpan.FromSeconds(59)); + Assert.IsEmpty(tracker.GetDueDiagnostics()); + + clock.Advance(TimeSpan.FromSeconds(1)); + SlowTestDiagnostic[] secondDiagnostics = tracker.GetDueDiagnostics(); + Assert.HasCount(1, secondDiagnostics); + SlowTestDiagnostic second = secondDiagnostics[0]; + Assert.AreEqual(TimeSpan.FromSeconds(120), second.Elapsed); + } + + [TestMethod] + public void GetDueDiagnostics_WhenPollIsDelayed_ReportsOnceAndSkipsCatchUpThresholds() + { + var clock = new FakeClock(); + var tracker = new ActiveTestTracker(SlowThreshold, clock.CreateStopwatch); + tracker.Start("uid", "SlowTest"); + + clock.Advance(TimeSpan.FromSeconds(300)); + SlowTestDiagnostic[] diagnostics = tracker.GetDueDiagnostics(); + Assert.HasCount(1, diagnostics); + SlowTestDiagnostic diagnostic = diagnostics[0]; + Assert.AreEqual(TimeSpan.FromSeconds(300), diagnostic.Elapsed); + + Assert.IsEmpty(tracker.GetDueDiagnostics()); + + clock.Advance(TimeSpan.FromSeconds(179)); + Assert.IsEmpty(tracker.GetDueDiagnostics()); + + clock.Advance(TimeSpan.FromSeconds(1)); + Assert.HasCount(1, tracker.GetDueDiagnostics()); + } + + [TestMethod] + public void Start_WhenUidIsAlreadyActive_DoesNotResetElapsedTimeOrBackoff() + { + var clock = new FakeClock(); + var tracker = new ActiveTestTracker(SlowThreshold, clock.CreateStopwatch); + tracker.Start("uid", "OriginalName"); + + clock.Advance(TimeSpan.FromSeconds(60)); + Assert.HasCount(1, tracker.GetDueDiagnostics()); + + tracker.Start("uid", "ReplacementName"); + clock.Advance(TimeSpan.FromSeconds(60)); + + SlowTestDiagnostic[] diagnostics = tracker.GetDueDiagnostics(); + Assert.HasCount(1, diagnostics); + SlowTestDiagnostic diagnostic = diagnostics[0]; + Assert.AreEqual("OriginalName", diagnostic.DisplayName); + Assert.AreEqual(TimeSpan.FromSeconds(120), diagnostic.Elapsed); + } + + [TestMethod] + public void Complete_TracksSameNameTestsIndependentlyByUid() + { + var clock = new FakeClock(); + var tracker = new ActiveTestTracker(SlowThreshold, clock.CreateStopwatch); + tracker.Start("uid-1", "SameName"); + tracker.Start("uid-2", "SameName"); + + tracker.Complete("uid-1"); + clock.Advance(SlowThreshold); + + SlowTestDiagnostic[] diagnostics = tracker.GetDueDiagnostics(); + Assert.HasCount(1, diagnostics); + SlowTestDiagnostic diagnostic = diagnostics[0]; + Assert.AreEqual("uid-2", diagnostic.Uid.Value); + Assert.AreEqual("SameName", diagnostic.DisplayName); + } + + [TestMethod] + public void Start_WhenThresholdIsZero_DoesNotTrackTests() + { + var clock = new FakeClock(); + var tracker = new ActiveTestTracker(TimeSpan.Zero, clock.CreateStopwatch); + + tracker.Start("uid", "Test"); + clock.Advance(TimeSpan.FromDays(1)); + + Assert.IsFalse(tracker.IsEnabled); + Assert.IsEmpty(tracker.GetDueDiagnostics()); + } + + private sealed class FakeClock + { + private TimeSpan _now; + + public void Advance(TimeSpan duration) => _now += duration; + + public IStopwatch CreateStopwatch() => new FakeStopwatch(this, _now); + + private sealed class FakeStopwatch(FakeClock clock, TimeSpan start) : IStopwatch + { + public TimeSpan Elapsed => clock._now - start; + + public void Start() + { + } + + public void Stop() + { + } + } + } +} diff --git a/test/UnitTests/Microsoft.Testing.Platform.UnitTests/OutputDevice/SimplifiedConsoleOutputDeviceTests.cs b/test/UnitTests/Microsoft.Testing.Platform.UnitTests/OutputDevice/SimplifiedConsoleOutputDeviceTests.cs index 723f556f78..f981a5b7ef 100644 --- a/test/UnitTests/Microsoft.Testing.Platform.UnitTests/OutputDevice/SimplifiedConsoleOutputDeviceTests.cs +++ b/test/UnitTests/Microsoft.Testing.Platform.UnitTests/OutputDevice/SimplifiedConsoleOutputDeviceTests.cs @@ -18,6 +18,8 @@ public sealed class SimplifiedConsoleOutputDeviceTests private static readonly IOutputDeviceDataProducer Producer = Mock.Of( producer => producer.Uid == "producer"); + public TestContext TestContext { get; set; } + [TestMethod] public async Task DisplayAsync_SessionMessage_WritesDurableOutput() { @@ -69,10 +71,126 @@ public async Task DisplayAsync_ProgressMessageAfterSessionFinishes_WritesSameVal Assert.AreSequenceEqual(new[] { "Restoring", "Restoring" }, device.Messages); } - private static RecordingSimplifiedOutputDevice CreateOutputDevice(IAsyncMonitor asyncMonitor) + [TestMethod] + public async Task ConsumeAsync_InProgressTest_ReportsOnlyAfterSlowThreshold() + { + using var asyncMonitor = new SystemAsyncMonitor(); + var clock = new FakeClock(); + RecordingSimplifiedOutputDevice device = CreateOutputDevice(asyncMonitor, clock); + + await device.ConsumeAsync( + Mock.Of(), + CreateTestNodeUpdate("uid", "AsyncHang", new InProgressTestNodeStateProperty()), + CancellationToken.None); + + Assert.IsEmpty(device.Messages); + + clock.Advance(TimeSpan.FromSeconds(60)); + await device.ReportDueSlowTestsAsync(); + + Assert.HasCount(1, device.Messages); + string message = device.Messages[0]!; + Assert.Contains("[slow]", message); + Assert.Contains("AsyncHang", message); + Assert.Contains("1m", message); + } + + [TestMethod] + public async Task ConsumeAsync_CompletedTest_IsRemovedFromSlowTestTracking() + { + using var asyncMonitor = new SystemAsyncMonitor(); + var clock = new FakeClock(); + RecordingSimplifiedOutputDevice device = CreateOutputDevice(asyncMonitor, clock); + + await device.ConsumeAsync( + Mock.Of(), + CreateTestNodeUpdate("uid", "CompletedTest", new InProgressTestNodeStateProperty()), + CancellationToken.None); + await device.ConsumeAsync( + Mock.Of(), + CreateTestNodeUpdate("uid", "CompletedTest", new PassedTestNodeStateProperty()), + CancellationToken.None); + + clock.Advance(TimeSpan.FromMinutes(10)); + await device.ReportDueSlowTestsAsync(); + + Assert.IsEmpty(device.Messages); + } + + [TestMethod] + public async Task ConsumeAsync_SameNameTests_AreTrackedIndependentlyByUid() + { + using var asyncMonitor = new SystemAsyncMonitor(); + var clock = new FakeClock(); + RecordingSimplifiedOutputDevice device = CreateOutputDevice(asyncMonitor, clock); + + await device.ConsumeAsync( + Mock.Of(), + CreateTestNodeUpdate("uid-1", "SameName", new InProgressTestNodeStateProperty()), + CancellationToken.None); + await device.ConsumeAsync( + Mock.Of(), + CreateTestNodeUpdate("uid-2", "SameName", new InProgressTestNodeStateProperty()), + CancellationToken.None); + await device.ConsumeAsync( + Mock.Of(), + CreateTestNodeUpdate("uid-1", "SameName", new PassedTestNodeStateProperty()), + CancellationToken.None); + + clock.Advance(TimeSpan.FromSeconds(60)); + await device.ReportDueSlowTestsAsync(); + + Assert.HasCount(1, device.Messages); + string message = device.Messages[0]!; + Assert.Contains("SameName", message); + } + + [TestMethod] + public async Task SessionLifecycle_CancelsAndAwaitsCooperativeReporter() + { + using var asyncMonitor = new SystemAsyncMonitor(); + RecordingSimplifiedOutputDevice device = CreateOutputDevice(asyncMonitor); + ITestSessionContext context = Mock.Of( + x => x.CancellationToken == CancellationToken.None); + + await device.OnTestSessionStartingAsync(context); + await device.OnTestSessionStartingAsync(context); + await device.OnTestSessionFinishingAsync(context); + await device.OnTestSessionFinishingAsync(context); + } + + [TestMethod] + public async Task CooperativeReporter_WhenTestIsDue_EmitsSlowDiagnostic() + { + using var asyncMonitor = new SystemAsyncMonitor(); + var clock = new FakeClock(); + RecordingSimplifiedOutputDevice device = CreateOutputDevice(asyncMonitor, clock, TimeSpan.FromMilliseconds(1)); + ITestSessionContext context = Mock.Of( + x => x.CancellationToken == CancellationToken.None); + + await device.ConsumeAsync( + Mock.Of(), + CreateTestNodeUpdate("uid", "AsyncHang", new InProgressTestNodeStateProperty()), + CancellationToken.None); + clock.Advance(TimeSpan.FromSeconds(60)); + + await device.OnTestSessionStartingAsync(context); + Task completedTask = await Task.WhenAny(device.MessageReported, Task.Delay(TimeSpan.FromSeconds(5), TestContext.CancellationToken)); + await device.OnTestSessionFinishingAsync(context); + + Assert.AreSame(device.MessageReported, completedTask); + Assert.Contains("[slow]", await device.MessageReported); + Assert.Contains("AsyncHang", await device.MessageReported); + } + + private static RecordingSimplifiedOutputDevice CreateOutputDevice( + IAsyncMonitor asyncMonitor, + FakeClock? clock = null, + TimeSpan? slowTestPollInterval = null) { var moduleInfo = new Mock(); moduleInfo.Setup(x => x.GetDisplayName()).Returns("testhost"); + clock ??= new FakeClock(); return new RecordingSimplifiedOutputDevice( Mock.Of(), @@ -81,11 +199,29 @@ private static RecordingSimplifiedOutputDevice CreateOutputDevice(IAsyncMonitor Mock.Of(), Mock.Of(), Mock.Of(), - Mock.Of()); + Mock.Of(), + TimeSpan.FromSeconds(60), + clock.CreateStopwatch, + slowTestPollInterval ?? TimeSpan.FromSeconds(1)); } + private static TestNodeUpdateMessage CreateTestNodeUpdate( + string uid, + string displayName, + TestNodeStateProperty state) + => new( + default, + new TestNode + { + Uid = new TestNodeUid(uid), + DisplayName = displayName, + Properties = new PropertyBag(state), + }); + private sealed class RecordingSimplifiedOutputDevice : SimplifiedConsoleOutputDeviceBase { + private readonly TaskCompletionSource _messageReported = new(TaskCreationOptions.RunContinuationsAsynchronously); + public RecordingSimplifiedOutputDevice( IConsole console, ITestApplicationModuleInfo testApplicationModuleInfo, @@ -93,21 +229,70 @@ public RecordingSimplifiedOutputDevice( IRuntimeFeature runtimeFeature, IEnvironment environment, IPlatformInformation platformInformation, - IStopPoliciesService policiesService) - : base(console, testApplicationModuleInfo, asyncMonitor, runtimeFeature, environment, platformInformation, policiesService) + IStopPoliciesService policiesService, + TimeSpan slowTestThreshold, + Func createStopwatch, + TimeSpan slowTestPollInterval) + : base( + console, + testApplicationModuleInfo, + asyncMonitor, + runtimeFeature, + environment, + platformInformation, + policiesService, + slowTestThreshold, + createStopwatch, + slowTestPollInterval) { } public List Messages { get; } = []; + public Task MessageReported => _messageReported.Task; + public override string DisplayName => nameof(RecordingSimplifiedOutputDevice); public override string Description => nameof(RecordingSimplifiedOutputDevice); - protected override void ConsoleWarn(string? message) => Messages.Add(message); + protected override void ConsoleWarn(string? message) => RecordMessage(message); + + protected override void ConsoleError(string? message) => RecordMessage(message); + + protected override void ConsoleLog(string? message) => RecordMessage(message); + + public Task ReportDueSlowTestsAsync() + => ReportSlowTestsOnceAsync(CancellationToken.None); - protected override void ConsoleError(string? message) => Messages.Add(message); + private void RecordMessage(string? message) + { + Messages.Add(message); + if (message is not null) + { + _messageReported.TrySetResult(message); + } + } + } - protected override void ConsoleLog(string? message) => Messages.Add(message); + private sealed class FakeClock + { + private TimeSpan _now; + + public void Advance(TimeSpan duration) => _now += duration; + + public IStopwatch CreateStopwatch() => new FakeStopwatch(this, _now); + + private sealed class FakeStopwatch(FakeClock clock, TimeSpan start) : IStopwatch + { + public TimeSpan Elapsed => clock._now - start; + + public void Start() + { + } + + public void Stop() + { + } + } } } From 189623a349382aea4f85159a86baa00a8fbeb4ca Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Amaury=20Lev=C3=A9?= Date: Wed, 22 Jul 2026 12:49:41 +0200 Subject: [PATCH 2/8] Share slow-test reporting thresholds Extract exponential threshold state for reuse by browser and WASI diagnostics, terminal heartbeat output, and CI slow-test reporters. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 2eba6c9f-f63f-4726-a0ce-f90ed2404431 --- .../InternalAPI/InternalAPI.Unshipped.txt | 3 ++ .../OutputDevice/ActiveTestTracker.cs | 29 +++-------- .../OutputDevice/SlowTestThresholdState.cs | 34 +++++++++++++ .../SilenceDrivenHeartbeatRenderer.cs | 21 ++++---- .../SlowTestReporterBase.cs | 14 ++---- .../SlowTestThresholdStateTests.cs | 49 +++++++++++++++++++ 6 files changed, 105 insertions(+), 45 deletions(-) create mode 100644 src/Platform/Microsoft.Testing.Platform/OutputDevice/SlowTestThresholdState.cs create mode 100644 test/UnitTests/Microsoft.Testing.Platform.UnitTests/OutputDevice/SlowTestThresholdStateTests.cs diff --git a/src/Platform/Microsoft.Testing.Platform/InternalAPI/InternalAPI.Unshipped.txt b/src/Platform/Microsoft.Testing.Platform/InternalAPI/InternalAPI.Unshipped.txt index bfb5ceb744..c3816233a0 100644 --- a/src/Platform/Microsoft.Testing.Platform/InternalAPI/InternalAPI.Unshipped.txt +++ b/src/Platform/Microsoft.Testing.Platform/InternalAPI/InternalAPI.Unshipped.txt @@ -212,4 +212,7 @@ Microsoft.Testing.Platform.OutputDevice.SlowTestDiagnostic.DisplayName.get -> st Microsoft.Testing.Platform.OutputDevice.SlowTestDiagnostic.Elapsed.get -> System.TimeSpan Microsoft.Testing.Platform.OutputDevice.SlowTestDiagnostic.SlowTestDiagnostic(Microsoft.Testing.Platform.Extensions.Messages.TestNodeUid! uid, string! displayName, System.TimeSpan elapsed) -> void Microsoft.Testing.Platform.OutputDevice.SlowTestDiagnostic.Uid.get -> Microsoft.Testing.Platform.Extensions.Messages.TestNodeUid! +Microsoft.Testing.Platform.OutputDevice.SlowTestThresholdState +Microsoft.Testing.Platform.OutputDevice.SlowTestThresholdState.IsDue(System.TimeSpan elapsed) -> bool +Microsoft.Testing.Platform.OutputDevice.SlowTestThresholdState.SlowTestThresholdState(System.TimeSpan initialThreshold) -> void static Microsoft.Testing.Platform.OutputDevice.ProgressReportingConfiguration.GetThreshold(Microsoft.Testing.Platform.Helpers.IEnvironment! environment, string! variableName, int defaultSeconds) -> System.TimeSpan diff --git a/src/Platform/Microsoft.Testing.Platform/OutputDevice/ActiveTestTracker.cs b/src/Platform/Microsoft.Testing.Platform/OutputDevice/ActiveTestTracker.cs index 2e4c2cedda..07ffde0ab5 100644 --- a/src/Platform/Microsoft.Testing.Platform/OutputDevice/ActiveTestTracker.cs +++ b/src/Platform/Microsoft.Testing.Platform/OutputDevice/ActiveTestTracker.cs @@ -36,7 +36,7 @@ internal void Start(TestNodeUid uid, string displayName) { if (!_activeTests.ContainsKey(uid)) { - _activeTests.Add(uid, new(displayName, _createStopwatch(), _slowTestThreshold.Ticks)); + _activeTests.Add(uid, new(displayName, _createStopwatch(), new(_slowTestThreshold))); } } } @@ -61,14 +61,13 @@ internal SlowTestDiagnostic[] GetDueDiagnostics() var diagnostics = new List(); foreach ((TestNodeUid uid, ActiveTest activeTest) in _activeTests.OrderBy(static pair => pair.Key.Value, StringComparer.Ordinal)) { - long elapsedTicks = activeTest.Stopwatch.Elapsed.Ticks; - if (elapsedTicks < activeTest.NextThresholdTicks) + TimeSpan elapsed = activeTest.Stopwatch.Elapsed; + if (!activeTest.SlowTestThreshold.IsDue(elapsed)) { continue; } - diagnostics.Add(new(uid, activeTest.DisplayName, TimeSpan.FromTicks(elapsedTicks))); - activeTest.NextThresholdTicks = GetNextThreshold(activeTest.NextThresholdTicks, elapsedTicks); + diagnostics.Add(new(uid, activeTest.DisplayName, elapsed)); } return [.. diagnostics]; @@ -83,29 +82,13 @@ internal void Clear() } } - private static long GetNextThreshold(long currentThresholdTicks, long elapsedTicks) - { - long nextThresholdTicks = currentThresholdTicks; - while (nextThresholdTicks <= elapsedTicks) - { - if (nextThresholdTicks > long.MaxValue / 2) - { - return long.MaxValue; - } - - nextThresholdTicks *= 2; - } - - return nextThresholdTicks; - } - - private sealed class ActiveTest(string displayName, IStopwatch stopwatch, long nextThresholdTicks) + private sealed class ActiveTest(string displayName, IStopwatch stopwatch, SlowTestThresholdState slowTestThreshold) { public string DisplayName { get; } = displayName; public IStopwatch Stopwatch { get; } = stopwatch; - public long NextThresholdTicks { get; set; } = nextThresholdTicks; + public SlowTestThresholdState SlowTestThreshold { get; } = slowTestThreshold; } } diff --git a/src/Platform/Microsoft.Testing.Platform/OutputDevice/SlowTestThresholdState.cs b/src/Platform/Microsoft.Testing.Platform/OutputDevice/SlowTestThresholdState.cs new file mode 100644 index 0000000000..221f3e0a10 --- /dev/null +++ b/src/Platform/Microsoft.Testing.Platform/OutputDevice/SlowTestThresholdState.cs @@ -0,0 +1,34 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT license. See LICENSE file in the project root for full license information. + +namespace Microsoft.Testing.Platform.OutputDevice; + +internal sealed class SlowTestThresholdState +{ + private long _nextThresholdTicks; + + internal SlowTestThresholdState(TimeSpan initialThreshold) + => _nextThresholdTicks = initialThreshold.Ticks; + + internal bool IsDue(TimeSpan elapsed) + { + long elapsedTicks = elapsed.Ticks; + if (_nextThresholdTicks <= 0 || elapsedTicks < _nextThresholdTicks) + { + return false; + } + + while (_nextThresholdTicks <= elapsedTicks) + { + if (_nextThresholdTicks > TimeSpan.MaxValue.Ticks / 2) + { + _nextThresholdTicks = TimeSpan.MaxValue.Ticks; + break; + } + + _nextThresholdTicks *= 2; + } + + return true; + } +} diff --git a/src/Platform/Microsoft.Testing.Platform/OutputDevice/Terminal/SilenceDrivenHeartbeatRenderer.cs b/src/Platform/Microsoft.Testing.Platform/OutputDevice/Terminal/SilenceDrivenHeartbeatRenderer.cs index 8b18599d12..fb4d454263 100644 --- a/src/Platform/Microsoft.Testing.Platform/OutputDevice/Terminal/SilenceDrivenHeartbeatRenderer.cs +++ b/src/Platform/Microsoft.Testing.Platform/OutputDevice/Terminal/SilenceDrivenHeartbeatRenderer.cs @@ -24,9 +24,9 @@ internal sealed class SilenceDrivenHeartbeatRenderer : IProgressRenderer private readonly TimeSpan _slowTestThreshold; private readonly Func _createStopwatch; - // Per running-test backoff state: test detail id -> next elapsed threshold (in ticks) at which to emit. + // Per running-test backoff state: test detail id -> next elapsed threshold at which to emit. // Only touched from the single rendering thread inside OnTick. - private readonly Dictionary _slowTestNextThresholdTicks = []; + private readonly Dictionary _slowTestThresholdStates = []; private IStopwatch? _clock; @@ -53,7 +53,7 @@ public SilenceDrivenHeartbeatRenderer(TimeSpan silenceThreshold, TimeSpan slowTe public void OnStart() { - _slowTestNextThresholdTicks.Clear(); + _slowTestThresholdStates.Clear(); IStopwatch clock = _createStopwatch(); Volatile.Write(ref _clock, clock); Interlocked.Exchange(ref _lastActivityTicks, clock.Elapsed.Ticks); @@ -132,8 +132,6 @@ private void EmitSlowTests(ITerminal terminal, TestProgressState?[] progressItem return; } - long slowTicks = _slowTestThreshold.Ticks; - foreach (TestProgressState? item in progressItems) { TestNodeResultsState? results = item?.TestNodeResultsState; @@ -150,19 +148,20 @@ private void EmitSlowTests(ITerminal terminal, TestProgressState?[] progressItem continue; } - long elapsed = detail.Stopwatch.Elapsed.Ticks; - long next = _slowTestNextThresholdTicks.TryGetValue(detail.Id, out long stored) ? stored : slowTicks; - if (elapsed < next) + TimeSpan elapsed = detail.Stopwatch.Elapsed; + SlowTestThresholdState thresholdState = _slowTestThresholdStates.TryGetValue(detail.Id, out SlowTestThresholdState? stored) + ? stored + : new(_slowTestThreshold); + if (!thresholdState.IsDue(elapsed)) { continue; } - // Exponential backoff: next emission at twice the crossed threshold (60s -> 2m -> 4m -> 8m ...). - _slowTestNextThresholdTicks[detail.Id] = next * 2; + _slowTestThresholdStates[detail.Id] = thresholdState; // Report the test's actual elapsed time rather than the scheduled threshold so a delayed // tick (GC pause, debugger break, CPU starvation) does not under-report the runtime. - string duration = HumanReadableDurationFormatter.Render(TimeSpan.FromTicks(elapsed), wrapInParentheses: false); + string duration = HumanReadableDurationFormatter.Render(elapsed, wrapInParentheses: false); terminal.AppendLine(string.Format(CultureInfo.CurrentCulture, TerminalResources.TerminalProgressSlowTest, duration, BuildSlowTestDescription(item, detail))); } } diff --git a/src/Platform/SharedExtensionHelpers/SlowTestReporterBase.cs b/src/Platform/SharedExtensionHelpers/SlowTestReporterBase.cs index 3711a6e3ed..d5d52ed862 100644 --- a/src/Platform/SharedExtensionHelpers/SlowTestReporterBase.cs +++ b/src/Platform/SharedExtensionHelpers/SlowTestReporterBase.cs @@ -232,7 +232,7 @@ internal async Task ScanOnceAsync(DateTimeOffset now, CancellationToken cancella { InProgressTest test = entry.Value; TimeSpan elapsed = now - test.StartTime; - if (elapsed < test.NextEmitThreshold) + if (!test.SlowTestThreshold.IsDue(elapsed)) { continue; } @@ -245,14 +245,6 @@ internal async Task ScanOnceAsync(DateTimeOffset now, CancellationToken cancella continue; } - // Exponential backoff so a genuinely stuck test does not spam the log: T, 2T, 4T, ... - // Clamp at TimeSpan.MaxValue so a very long-running test cannot overflow Ticks * 2 into a - // negative value (which would make the backoff fire on every scan). - long currentTicks = test.NextEmitThreshold.Ticks; - test.NextEmitThreshold = currentTicks > TimeSpan.MaxValue.Ticks / 2 - ? TimeSpan.MaxValue - : TimeSpan.FromTicks(currentTicks * 2); - try { await EmitSlowTestAsync(test.TestName, test.DisplayLabel, elapsed, cancellationToken).ConfigureAwait(false); @@ -271,7 +263,7 @@ public InProgressTest(string testName, string displayLabel, DateTimeOffset start TestName = testName; DisplayLabel = displayLabel; StartTime = startTime; - NextEmitThreshold = threshold; + SlowTestThreshold = new(threshold); } public string TestName { get; } @@ -280,6 +272,6 @@ public InProgressTest(string testName, string displayLabel, DateTimeOffset start public DateTimeOffset StartTime { get; } - public TimeSpan NextEmitThreshold { get; set; } + public SlowTestThresholdState SlowTestThreshold { get; } } } diff --git a/test/UnitTests/Microsoft.Testing.Platform.UnitTests/OutputDevice/SlowTestThresholdStateTests.cs b/test/UnitTests/Microsoft.Testing.Platform.UnitTests/OutputDevice/SlowTestThresholdStateTests.cs new file mode 100644 index 0000000000..06e5f3fae1 --- /dev/null +++ b/test/UnitTests/Microsoft.Testing.Platform.UnitTests/OutputDevice/SlowTestThresholdStateTests.cs @@ -0,0 +1,49 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT license. See LICENSE file in the project root for full license information. + +using Microsoft.Testing.Platform.OutputDevice; + +namespace Microsoft.Testing.Platform.UnitTests.OutputDevice; + +[TestClass] +public sealed class SlowTestThresholdStateTests +{ + [TestMethod] + public void IsDue_UsesExponentialBackoff() + { + var state = new SlowTestThresholdState(TimeSpan.FromSeconds(60)); + + Assert.IsFalse(state.IsDue(TimeSpan.FromSeconds(59))); + Assert.IsTrue(state.IsDue(TimeSpan.FromSeconds(60))); + Assert.IsFalse(state.IsDue(TimeSpan.FromSeconds(119))); + Assert.IsTrue(state.IsDue(TimeSpan.FromSeconds(120))); + } + + [TestMethod] + public void IsDue_WhenPollIsDelayed_SkipsObsoleteThresholds() + { + var state = new SlowTestThresholdState(TimeSpan.FromSeconds(60)); + + Assert.IsTrue(state.IsDue(TimeSpan.FromSeconds(300))); + Assert.IsFalse(state.IsDue(TimeSpan.FromSeconds(300))); + Assert.IsFalse(state.IsDue(TimeSpan.FromSeconds(479))); + Assert.IsTrue(state.IsDue(TimeSpan.FromSeconds(480))); + } + + [TestMethod] + public void IsDue_WhenThresholdIsNotPositive_IsDisabled() + { + Assert.IsFalse(new SlowTestThresholdState(TimeSpan.Zero).IsDue(TimeSpan.MaxValue)); + Assert.IsFalse(new SlowTestThresholdState(TimeSpan.FromSeconds(-1)).IsDue(TimeSpan.MaxValue)); + } + + [TestMethod] + public void IsDue_WhenNextThresholdWouldOverflow_SaturatesAtMaximum() + { + var threshold = TimeSpan.FromTicks((TimeSpan.MaxValue.Ticks / 2) + 1); + var state = new SlowTestThresholdState(threshold); + + Assert.IsTrue(state.IsDue(threshold)); + Assert.IsFalse(state.IsDue(TimeSpan.FromTicks(TimeSpan.MaxValue.Ticks - 1))); + } +} From 21cedf9d2d37f14407d0651a2860804e5d27442c Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Amaury=20Lev=C3=A9?= Date: Fri, 24 Jul 2026 11:22:29 +0200 Subject: [PATCH 3/8] Address browser slow-test review feedback Close empty-result lifecycle tracking, serialize reporter teardown, revalidate diagnostics before emission, reduce cooperative polling allocations, and forward browser slow-test configuration through both launchers. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 215e1000-a407-4d84-82a4-2d3696d566fd --- samples/BrowserPlayground/README.md | 18 ++++- samples/BrowserPlayground/wwwroot/main.js | 14 +++- .../BrowserPlayground/wwwroot/runtests.mjs | 11 ++- .../InternalAPI/InternalAPI.Unshipped.txt | 1 + .../MSTestTestNodeConverter.cs | 10 +++ .../MtpTestResultRecorder.cs | 4 +- .../InternalAPI/InternalAPI.Unshipped.txt | 3 + .../Messages/TestNodeUpdateMessage.cs | 9 +++ .../OutputDevice/ActiveTestTracker.cs | 20 +++++- .../SimplifiedConsoleOutputDeviceBase.cs | 45 +++++++----- .../SilenceDrivenHeartbeatRenderer.cs | 13 +++- .../MSTestTestNodeConverterTests.cs | 5 +- .../OutputDevice/ActiveTestTrackerTests.cs | 14 ++++ .../SimplifiedConsoleOutputDeviceTests.cs | 69 +++++++++++++++++-- 14 files changed, 197 insertions(+), 39 deletions(-) diff --git a/samples/BrowserPlayground/README.md b/samples/BrowserPlayground/README.md index 8b4a78ac83..8a05e79eab 100644 --- a/samples/BrowserPlayground/README.md +++ b/samples/BrowserPlayground/README.md @@ -132,8 +132,22 @@ exponential backoff (60 seconds, 2 minutes, 4 minutes, and so on): ``` Set `MTP_PROGRESS_SLOW_TEST_SECONDS` to a non-negative integer to change the first -reporting threshold; `0` disables these diagnostics. Test starts are tracked silently, -so this does not duplicate normal per-test progress output. +reporting threshold; `0` disables these diagnostics. The browser launcher reads it from +the page query string: + +```text +index.html?MTP_PROGRESS_SLOW_TEST_SECONDS=5 +``` + +The Node launcher forwards the process environment variable into the managed WebAssembly +runtime: + +```powershell +$env:MTP_PROGRESS_SLOW_TEST_SECONDS = '5' +node runtests.mjs +``` + +Test starts are tracked silently, so this does not duplicate normal per-test progress output. The reporter is cooperative: it uses asynchronous delays and does not create a thread, timer thread, or process. It can therefore identify an asynchronously suspended test, diff --git a/samples/BrowserPlayground/wwwroot/main.js b/samples/BrowserPlayground/wwwroot/main.js index a212ad1806..49d54e8f32 100644 --- a/samples/BrowserPlayground/wwwroot/main.js +++ b/samples/BrowserPlayground/wwwroot/main.js @@ -7,12 +7,20 @@ // Microsoft.Testing.Platform. import { dotnet } from './_framework/dotnet.js'; -const { runMain } = await dotnet +const slowTestThresholdEnvironmentVariable = 'MTP_PROGRESS_SLOW_TEST_SECONDS'; +const runtimeBuilder = dotnet // A browser page has no argv, so Microsoft.Testing.Platform command-line options are // taken from the page's query string, e.g.: // index.html?arg=--minimum-expected-tests&arg=1 - .withApplicationArgumentsFromQuery() - .create(); + .withApplicationArgumentsFromQuery(); + +const slowTestThreshold = new URLSearchParams(globalThis.location.search) + .get(slowTestThresholdEnvironmentVariable); +if (slowTestThreshold !== null) { + runtimeBuilder.withEnvironmentVariable(slowTestThresholdEnvironmentVariable, slowTestThreshold); +} + +const { runMain } = await runtimeBuilder.create(); // runMain() invokes Program.Main and resolves to its exit code (0 = all tests passed, // non-zero = failures / policy violation). diff --git a/samples/BrowserPlayground/wwwroot/runtests.mjs b/samples/BrowserPlayground/wwwroot/runtests.mjs index cf1ff2a7ac..da55fe7ab5 100644 --- a/samples/BrowserPlayground/wwwroot/runtests.mjs +++ b/samples/BrowserPlayground/wwwroot/runtests.mjs @@ -15,9 +15,14 @@ // e.g. node runtests.mjs --minimum-expected-tests 1 import { dotnet } from './_framework/dotnet.js'; -const { runMain } = await dotnet - .withApplicationArguments(...process.argv.slice(2)) - .create(); +const slowTestThresholdEnvironmentVariable = 'MTP_PROGRESS_SLOW_TEST_SECONDS'; +const runtimeBuilder = dotnet.withApplicationArguments(...process.argv.slice(2)); +const slowTestThreshold = process.env[slowTestThresholdEnvironmentVariable]; +if (slowTestThreshold !== undefined) { + runtimeBuilder.withEnvironmentVariable(slowTestThresholdEnvironmentVariable, slowTestThreshold); +} + +const { runMain } = await runtimeBuilder.create(); // runMain() boots the same bundle under Node and resolves to the exit code of the sample's // Program.Main (defined by the top-level statements in Program.cs). diff --git a/src/Adapter/MSTest.TestAdapter/InternalAPI/InternalAPI.Unshipped.txt b/src/Adapter/MSTest.TestAdapter/InternalAPI/InternalAPI.Unshipped.txt index f35780f05c..7062e0bd2d 100644 --- a/src/Adapter/MSTest.TestAdapter/InternalAPI/InternalAPI.Unshipped.txt +++ b/src/Adapter/MSTest.TestAdapter/InternalAPI/InternalAPI.Unshipped.txt @@ -51,6 +51,7 @@ static Microsoft.Testing.Extensions.RunSettingsProviderHelper.CanReadFile(Micros static Microsoft.Testing.Extensions.RunSettingsProviderHelper.FindInvalidTestParameter(string![]! arguments) -> string? static Microsoft.Testing.Extensions.RunSettingsProviderHelper.HasEnvironmentVariables(System.Xml.Linq.XDocument! runSettings) -> bool static Microsoft.Testing.Extensions.RunSettingsProviderHelper.TryLoadRunSettingsAsync(Microsoft.Testing.Platform.CommandLine.ICommandLineOptions! commandLineOptions, Microsoft.Testing.Platform.Helpers.IFileSystem! fileSystem, Microsoft.Testing.Platform.Helpers.IEnvironment! environment, string! runSettingsOptionName) -> System.Threading.Tasks.Task! +static Microsoft.VisualStudio.TestTools.UnitTesting.MSTestTestNodeConverter.ToEmptyResultTestNode(Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.ObjectModel.UnitTestElement! element, bool isTrxEnabled) -> Microsoft.Testing.Platform.Extensions.Messages.TestNode! Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.MSTestEngine Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.MSTestEngine.Cancel() -> void Microsoft.VisualStudio.TestPlatform.MSTest.TestAdapter.MSTestEngine.DiscoverAsync(System.Collections.Generic.IEnumerable! sources, string? settingsXml, Microsoft.VisualStudio.TestPlatform.MSTestAdapter.PlatformServices.Interface.IAdapterMessageLogger! logger, Microsoft.VisualStudio.TestPlatform.MSTestAdapter.PlatformServices.Interface.IUnitTestElementSink! elementSink, Microsoft.VisualStudio.TestPlatform.MSTestAdapter.PlatformServices.Interface.ITestElementFilterProvider? filterProvider, Microsoft.VisualStudio.TestPlatform.MSTestAdapter.PlatformServices.Interface.IConfiguration? configuration, Microsoft.VisualStudio.TestPlatform.MSTestAdapter.PlatformServices.Interface.ITestSourceHandler! testSourceHandler, bool isMTP) -> System.Threading.Tasks.Task! diff --git a/src/Adapter/MSTest.TestAdapter/TestingPlatformAdapter/MSTestTestNodeConverter.cs b/src/Adapter/MSTest.TestAdapter/TestingPlatformAdapter/MSTestTestNodeConverter.cs index 5f02a7b0a9..484e8dafb3 100644 --- a/src/Adapter/MSTest.TestAdapter/TestingPlatformAdapter/MSTestTestNodeConverter.cs +++ b/src/Adapter/MSTest.TestAdapter/TestingPlatformAdapter/MSTestTestNodeConverter.cs @@ -52,6 +52,16 @@ public static TestNode ToInProgressTestNode(UnitTestElement element, bool isTrxE return testNode; } + /// + /// Builds a state-neutral node update that signals execution completed without producing a result. + /// + public static TestNode ToEmptyResultTestNode(UnitTestElement element, bool isTrxEnabled) + { + TestNode testNode = CreateBaseTestNode(element, isTrxEnabled, displayNameOverride: null, out _); + testNode.Properties.Add(TestNodeExecutionCompletedProperty.CachedInstance); + return testNode; + } + /// /// Builds a completed carrying the outcome, timing, output and (optionally) TRX /// properties for a single executed test result. diff --git a/src/Adapter/MSTest.TestAdapter/TestingPlatformAdapter/MtpTestResultRecorder.cs b/src/Adapter/MSTest.TestAdapter/TestingPlatformAdapter/MtpTestResultRecorder.cs index 7b22aebe07..42c310104e 100644 --- a/src/Adapter/MSTest.TestAdapter/TestingPlatformAdapter/MtpTestResultRecorder.cs +++ b/src/Adapter/MSTest.TestAdapter/TestingPlatformAdapter/MtpTestResultRecorder.cs @@ -44,10 +44,8 @@ public Task RecordStartAsync(UnitTestElement testElement) return PublishAsync(testNode); } - // Mirrors the VSTest recorder: an empty result maps to RecordEnd(TestOutcome.None), which does not publish any - // test node update to Microsoft.Testing.Platform. So there is nothing to report here. public Task RecordEmptyResultAsync(UnitTestElement testElement) - => Task.CompletedTask; + => PublishAsync(MSTestTestNodeConverter.ToEmptyResultTestNode(testElement, _isTrxEnabled)); public async Task RecordResultAsync(UnitTestElement testElement, FrameworkTestResult unitTestResult, DateTimeOffset startTime, DateTimeOffset endTime) { diff --git a/src/Platform/Microsoft.Testing.Platform/InternalAPI/InternalAPI.Unshipped.txt b/src/Platform/Microsoft.Testing.Platform/InternalAPI/InternalAPI.Unshipped.txt index c3816233a0..a7754e4056 100644 --- a/src/Platform/Microsoft.Testing.Platform/InternalAPI/InternalAPI.Unshipped.txt +++ b/src/Platform/Microsoft.Testing.Platform/InternalAPI/InternalAPI.Unshipped.txt @@ -202,6 +202,7 @@ Microsoft.Testing.Platform.OutputDevice.ActiveTestTracker.ActiveTestTracker(Syst Microsoft.Testing.Platform.OutputDevice.ActiveTestTracker.Clear() -> void Microsoft.Testing.Platform.OutputDevice.ActiveTestTracker.Complete(Microsoft.Testing.Platform.Extensions.Messages.TestNodeUid! uid) -> void Microsoft.Testing.Platform.OutputDevice.ActiveTestTracker.GetDueDiagnostics() -> Microsoft.Testing.Platform.OutputDevice.SlowTestDiagnostic![]! +Microsoft.Testing.Platform.OutputDevice.ActiveTestTracker.IsActive(Microsoft.Testing.Platform.Extensions.Messages.TestNodeUid! uid) -> bool Microsoft.Testing.Platform.OutputDevice.ActiveTestTracker.IsEnabled.get -> bool Microsoft.Testing.Platform.OutputDevice.ActiveTestTracker.Start(Microsoft.Testing.Platform.Extensions.Messages.TestNodeUid! uid, string! displayName) -> void Microsoft.Testing.Platform.OutputDevice.ProgressReportingConfiguration @@ -216,3 +217,5 @@ Microsoft.Testing.Platform.OutputDevice.SlowTestThresholdState Microsoft.Testing.Platform.OutputDevice.SlowTestThresholdState.IsDue(System.TimeSpan elapsed) -> bool Microsoft.Testing.Platform.OutputDevice.SlowTestThresholdState.SlowTestThresholdState(System.TimeSpan initialThreshold) -> void static Microsoft.Testing.Platform.OutputDevice.ProgressReportingConfiguration.GetThreshold(Microsoft.Testing.Platform.Helpers.IEnvironment! environment, string! variableName, int defaultSeconds) -> System.TimeSpan +Microsoft.Testing.Platform.Extensions.Messages.TestNodeExecutionCompletedProperty +static Microsoft.Testing.Platform.Extensions.Messages.TestNodeExecutionCompletedProperty.CachedInstance.get -> Microsoft.Testing.Platform.Extensions.Messages.TestNodeExecutionCompletedProperty! diff --git a/src/Platform/Microsoft.Testing.Platform/Messages/TestNodeUpdateMessage.cs b/src/Platform/Microsoft.Testing.Platform/Messages/TestNodeUpdateMessage.cs index 5cfe5b8b05..843868189c 100644 --- a/src/Platform/Microsoft.Testing.Platform/Messages/TestNodeUpdateMessage.cs +++ b/src/Platform/Microsoft.Testing.Platform/Messages/TestNodeUpdateMessage.cs @@ -62,3 +62,12 @@ public override string ToString() return builder.ToString(); } } + +internal sealed class TestNodeExecutionCompletedProperty : IProperty +{ + private TestNodeExecutionCompletedProperty() + { + } + + internal static TestNodeExecutionCompletedProperty CachedInstance { get; } = new(); +} diff --git a/src/Platform/Microsoft.Testing.Platform/OutputDevice/ActiveTestTracker.cs b/src/Platform/Microsoft.Testing.Platform/OutputDevice/ActiveTestTracker.cs index 07ffde0ab5..7c9aa7e4ce 100644 --- a/src/Platform/Microsoft.Testing.Platform/OutputDevice/ActiveTestTracker.cs +++ b/src/Platform/Microsoft.Testing.Platform/OutputDevice/ActiveTestTracker.cs @@ -49,6 +49,14 @@ internal void Complete(TestNodeUid uid) } } + internal bool IsActive(TestNodeUid uid) + { + lock (_lock) + { + return _activeTests.ContainsKey(uid); + } + } + internal SlowTestDiagnostic[] GetDueDiagnostics() { lock (_lock) @@ -58,8 +66,8 @@ internal SlowTestDiagnostic[] GetDueDiagnostics() return []; } - var diagnostics = new List(); - foreach ((TestNodeUid uid, ActiveTest activeTest) in _activeTests.OrderBy(static pair => pair.Key.Value, StringComparer.Ordinal)) + List? diagnostics = null; + foreach ((TestNodeUid uid, ActiveTest activeTest) in _activeTests) { TimeSpan elapsed = activeTest.Stopwatch.Elapsed; if (!activeTest.SlowTestThreshold.IsDue(elapsed)) @@ -67,9 +75,15 @@ internal SlowTestDiagnostic[] GetDueDiagnostics() continue; } - diagnostics.Add(new(uid, activeTest.DisplayName, elapsed)); + (diagnostics ??= []).Add(new(uid, activeTest.DisplayName, elapsed)); + } + + if (diagnostics is null) + { + return []; } + diagnostics.Sort(static (left, right) => StringComparer.Ordinal.Compare(left.Uid.Value, right.Uid.Value)); return [.. diagnostics]; } } diff --git a/src/Platform/Microsoft.Testing.Platform/OutputDevice/SimplifiedConsoleOutputDeviceBase.cs b/src/Platform/Microsoft.Testing.Platform/OutputDevice/SimplifiedConsoleOutputDeviceBase.cs index efe1a7bf35..1a4d223e11 100644 --- a/src/Platform/Microsoft.Testing.Platform/OutputDevice/SimplifiedConsoleOutputDeviceBase.cs +++ b/src/Platform/Microsoft.Testing.Platform/OutputDevice/SimplifiedConsoleOutputDeviceBase.cs @@ -39,11 +39,12 @@ internal abstract class SimplifiedConsoleOutputDeviceBase : IPlatformOutputDevic private readonly string? _targetFramework; private readonly string _assemblyName; + // Browser and WASI hosts run one test session per application. The engine calls this handler twice for that + // session because the output device implements two extension roles, so only the first callback starts the reporter. private bool _firstCallTo_OnSessionStartingAsync = true; private bool _bannerDisplayed; private volatile bool _wasCancelled; - private CancellationTokenSource? _slowTestReporterCancellationTokenSource; - private Task? _slowTestReporterTask; + private SlowTestReporterState? _slowTestReporterState; private int _passedTests; private int _failedTests; @@ -234,29 +235,25 @@ public async Task DisplayAfterSessionEndRunAsync(CancellationToken cancellationT public async Task OnTestSessionFinishingAsync(ITestSessionContext testSessionContext) { - CancellationTokenSource? cancellationTokenSource = _slowTestReporterCancellationTokenSource; - Task? reporterTask = _slowTestReporterTask; - _slowTestReporterCancellationTokenSource = null; - _slowTestReporterTask = null; + SlowTestReporterState? reporterState = Interlocked.Exchange(ref _slowTestReporterState, null); #if NET - if (cancellationTokenSource is { } cts) + if (reporterState is not null) { - await cts.CancelAsync().ConfigureAwait(false); + await reporterState.CancellationTokenSource.CancelAsync().ConfigureAwait(false); } #else #pragma warning disable VSTHRD103 // CancellationTokenSource.CancelAsync is not available on this target framework. - cancellationTokenSource?.Cancel(); + reporterState?.CancellationTokenSource.Cancel(); #pragma warning restore VSTHRD103 #endif - if (reporterTask is not null) + if (reporterState is not null) { - await reporterTask.ConfigureAwait(false); + await reporterState.Task.ConfigureAwait(false); + reporterState.CancellationTokenSource.Dispose(); } - cancellationTokenSource?.Dispose(); - using (await _asyncMonitor.LockAsync(TimeoutHelper.DefaultHangTimeSpanTimeout).ConfigureAwait(false)) { _progressMessages.Clear(); @@ -277,8 +274,8 @@ public Task OnTestSessionStartingAsync(ITestSessionContext testSessionContext) _firstCallTo_OnSessionStartingAsync = false; if (_activeTestTracker.IsEnabled) { - _slowTestReporterCancellationTokenSource = CancellationTokenSource.CreateLinkedTokenSource(cancellationToken); - _slowTestReporterTask = ReportSlowTestsAsync(_slowTestReporterCancellationTokenSource.Token); + var cancellationTokenSource = CancellationTokenSource.CreateLinkedTokenSource(cancellationToken); + _slowTestReporterState = new(cancellationTokenSource, ReportSlowTestsAsync(cancellationTokenSource.Token)); } } @@ -387,6 +384,7 @@ public Task ConsumeAsync(IDataProducer dataProducer, IData value, CancellationTo // field access, so the win here is code-path simplification and consistency with the established single-pass pattern. TimingProperty? timingProp = null; TestNodeStateProperty? nodeStateProp = null; + bool executionCompleted = false; PropertyBag.PropertyBagEnumerator enumerator = testNodeStateChanged.TestNode.Properties.GetStructEnumerator(); while (enumerator.MoveNext()) { @@ -394,6 +392,7 @@ public Task ConsumeAsync(IDataProducer dataProducer, IData value, CancellationTo { case TimingProperty t: timingProp = t; break; case TestNodeStateProperty s: nodeStateProp = s; break; + case TestNodeExecutionCompletedProperty: executionCompleted = true; break; } } @@ -404,7 +403,8 @@ public Task ConsumeAsync(IDataProducer dataProducer, IData value, CancellationTo _activeTestTracker.Start(testNodeStateChanged.TestNode.Uid, testNodeStateChanged.TestNode.DisplayName); } #pragma warning disable CS0618, MTP0001 // Type or member is obsolete - else if (nodeStateProp is PassedTestNodeStateProperty or ErrorTestNodeStateProperty or CancelledTestNodeStateProperty + else if (executionCompleted + || nodeStateProp is PassedTestNodeStateProperty or ErrorTestNodeStateProperty or CancelledTestNodeStateProperty #pragma warning restore CS0618, MTP0001 // Type or member is obsolete or FailedTestNodeStateProperty or TimeoutTestNodeStateProperty or SkippedTestNodeStateProperty) { @@ -486,6 +486,11 @@ internal async Task ReportSlowTestsOnceAsync(CancellationToken cancellationToken cancellationToken.ThrowIfCancellationRequested(); foreach (SlowTestDiagnostic diagnostic in diagnostics) { + if (!_activeTestTracker.IsActive(diagnostic.Uid)) + { + continue; + } + string duration = HumanReadableDurationFormatter.Render(diagnostic.Elapsed, wrapInParentheses: false); ConsoleLog(string.Format( CultureInfo.CurrentCulture, @@ -508,9 +513,17 @@ private async Task ReportSlowTestsAsync(CancellationToken cancellationToken) } catch (OperationCanceledException) when (cancellationToken.IsCancellationRequested) { + return; } } + private sealed class SlowTestReporterState(CancellationTokenSource cancellationTokenSource, Task task) + { + internal CancellationTokenSource CancellationTokenSource { get; } = cancellationTokenSource; + + internal Task Task { get; } = task; + } + public async Task HandleProcessRoleAsync(TestProcessRole processRole, CancellationToken cancellationToken) { if (processRole == TestProcessRole.TestHost) diff --git a/src/Platform/Microsoft.Testing.Platform/OutputDevice/Terminal/SilenceDrivenHeartbeatRenderer.cs b/src/Platform/Microsoft.Testing.Platform/OutputDevice/Terminal/SilenceDrivenHeartbeatRenderer.cs index fb4d454263..c4117394a3 100644 --- a/src/Platform/Microsoft.Testing.Platform/OutputDevice/Terminal/SilenceDrivenHeartbeatRenderer.cs +++ b/src/Platform/Microsoft.Testing.Platform/OutputDevice/Terminal/SilenceDrivenHeartbeatRenderer.cs @@ -149,9 +149,16 @@ private void EmitSlowTests(ITerminal terminal, TestProgressState?[] progressItem } TimeSpan elapsed = detail.Stopwatch.Elapsed; - SlowTestThresholdState thresholdState = _slowTestThresholdStates.TryGetValue(detail.Id, out SlowTestThresholdState? stored) - ? stored - : new(_slowTestThreshold); + if (!_slowTestThresholdStates.TryGetValue(detail.Id, out SlowTestThresholdState? thresholdState)) + { + if (elapsed < _slowTestThreshold) + { + continue; + } + + thresholdState = new(_slowTestThreshold); + } + if (!thresholdState.IsDue(elapsed)) { continue; diff --git a/test/UnitTests/MSTestAdapter.UnitTests/MSTestTestNodeConverterTests.cs b/test/UnitTests/MSTestAdapter.UnitTests/MSTestTestNodeConverterTests.cs index 836f63acbb..ba089286ec 100644 --- a/test/UnitTests/MSTestAdapter.UnitTests/MSTestTestNodeConverterTests.cs +++ b/test/UnitTests/MSTestAdapter.UnitTests/MSTestTestNodeConverterTests.cs @@ -367,14 +367,15 @@ public async Task MtpTestResultRecorder_RecordStart_PublishesInProgressNode() message.TestNode.Properties.Any().Should().BeTrue(); } - public async Task MtpTestResultRecorder_RecordEmptyResult_PublishesNothing() + public async Task MtpTestResultRecorder_RecordEmptyResult_PublishesExecutionCompletedNode() { var messageBus = new CapturingMessageBus(); var recorder = new MtpTestResultRecorder(messageBus, new StubDataProducer(), new SessionUid("s"), isTrxEnabled: false, new MSTestSettings()); await recorder.RecordEmptyResultAsync(CreateElement()); - messageBus.Published.Should().BeEmpty(); + var message = (TestNodeUpdateMessage)messageBus.Published.Single(); + message.TestNode.Properties.Any().Should().BeFalse(); } public async Task MtpTestResultRecorder_RecordResult_PublishesResultNodeAndReturnsFailedFlag() diff --git a/test/UnitTests/Microsoft.Testing.Platform.UnitTests/OutputDevice/ActiveTestTrackerTests.cs b/test/UnitTests/Microsoft.Testing.Platform.UnitTests/OutputDevice/ActiveTestTrackerTests.cs index 6637e4b654..f420913d1b 100644 --- a/test/UnitTests/Microsoft.Testing.Platform.UnitTests/OutputDevice/ActiveTestTrackerTests.cs +++ b/test/UnitTests/Microsoft.Testing.Platform.UnitTests/OutputDevice/ActiveTestTrackerTests.cs @@ -99,6 +99,20 @@ public void Complete_TracksSameNameTestsIndependentlyByUid() Assert.AreEqual("SameName", diagnostic.DisplayName); } + [TestMethod] + public void GetDueDiagnostics_SortsOnlyDueTestsByUid() + { + var clock = new FakeClock(); + var tracker = new ActiveTestTracker(SlowThreshold, clock.CreateStopwatch); + tracker.Start("uid-b", "Second"); + tracker.Start("uid-a", "First"); + + clock.Advance(SlowThreshold); + + SlowTestDiagnostic[] diagnostics = tracker.GetDueDiagnostics(); + Assert.AreSequenceEqual(new[] { "uid-a", "uid-b" }, diagnostics.Select(diagnostic => diagnostic.Uid.Value)); + } + [TestMethod] public void Start_WhenThresholdIsZero_DoesNotTrackTests() { diff --git a/test/UnitTests/Microsoft.Testing.Platform.UnitTests/OutputDevice/SimplifiedConsoleOutputDeviceTests.cs b/test/UnitTests/Microsoft.Testing.Platform.UnitTests/OutputDevice/SimplifiedConsoleOutputDeviceTests.cs index f981a5b7ef..372771a9e4 100644 --- a/test/UnitTests/Microsoft.Testing.Platform.UnitTests/OutputDevice/SimplifiedConsoleOutputDeviceTests.cs +++ b/test/UnitTests/Microsoft.Testing.Platform.UnitTests/OutputDevice/SimplifiedConsoleOutputDeviceTests.cs @@ -117,6 +117,35 @@ await device.ConsumeAsync( Assert.IsEmpty(device.Messages); } + [TestMethod] + public async Task ConsumeAsync_EmptyResultFollowedBySlowTest_ReportsOnlySlowTest() + { + using var asyncMonitor = new SystemAsyncMonitor(); + var clock = new FakeClock(); + RecordingSimplifiedOutputDevice device = CreateOutputDevice(asyncMonitor, clock); + + await device.ConsumeAsync( + Mock.Of(), + CreateTestNodeUpdate("dropped-uid", "DroppedTest", new InProgressTestNodeStateProperty()), + CancellationToken.None); + await device.ConsumeAsync( + Mock.Of(), + CreateTestNodeUpdate("dropped-uid", "DroppedTest", TestNodeExecutionCompletedProperty.CachedInstance), + CancellationToken.None); + await device.ConsumeAsync( + Mock.Of(), + CreateTestNodeUpdate("slow-uid", "SlowTest", new InProgressTestNodeStateProperty()), + CancellationToken.None); + + clock.Advance(TimeSpan.FromSeconds(60)); + await device.ReportDueSlowTestsAsync(); + + Assert.HasCount(1, device.Messages); + string message = device.Messages[0]!; + Assert.Contains("SlowTest", message); + Assert.DoesNotContain("DroppedTest", message); + } + [TestMethod] public async Task ConsumeAsync_SameNameTests_AreTrackedIndependentlyByUid() { @@ -155,8 +184,40 @@ public async Task SessionLifecycle_CancelsAndAwaitsCooperativeReporter() await device.OnTestSessionStartingAsync(context); await device.OnTestSessionStartingAsync(context); - await device.OnTestSessionFinishingAsync(context); - await device.OnTestSessionFinishingAsync(context); + await Task.WhenAll( + device.OnTestSessionFinishingAsync(context), + device.OnTestSessionFinishingAsync(context)); + } + + [TestMethod] + public async Task ReportSlowTestsOnceAsync_TestCompletesWhileWaitingForOutputLock_DoesNotReportIt() + { + var lockRequested = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously); + var lockGranted = new TaskCompletionSource(TaskCreationOptions.RunContinuationsAsynchronously); + var asyncMonitor = new Mock(); + asyncMonitor + .Setup(monitor => monitor.LockAsync(It.IsAny())) + .Callback(() => lockRequested.TrySetResult(null)) + .Returns(lockGranted.Task); + var clock = new FakeClock(); + RecordingSimplifiedOutputDevice device = CreateOutputDevice(asyncMonitor.Object, clock); + + await device.ConsumeAsync( + Mock.Of(), + CreateTestNodeUpdate("uid", "CompletedWhileWaiting", new InProgressTestNodeStateProperty()), + CancellationToken.None); + clock.Advance(TimeSpan.FromSeconds(60)); + + Task reportTask = device.ReportDueSlowTestsAsync(); + await lockRequested.Task; + await device.ConsumeAsync( + Mock.Of(), + CreateTestNodeUpdate("uid", "CompletedWhileWaiting", new PassedTestNodeStateProperty()), + CancellationToken.None); + lockGranted.SetResult(Mock.Of()); + await reportTask; + + Assert.IsEmpty(device.Messages); } [TestMethod] @@ -208,14 +269,14 @@ private static RecordingSimplifiedOutputDevice CreateOutputDevice( private static TestNodeUpdateMessage CreateTestNodeUpdate( string uid, string displayName, - TestNodeStateProperty state) + IProperty property) => new( default, new TestNode { Uid = new TestNodeUid(uid), DisplayName = displayName, - Properties = new PropertyBag(state), + Properties = new PropertyBag(property), }); private sealed class RecordingSimplifiedOutputDevice : SimplifiedConsoleOutputDeviceBase From 9829ac919ebd4fdf2829ed001396419edaffb2ce Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Amaury=20Lev=C3=A9?= Date: Fri, 24 Jul 2026 12:53:48 +0200 Subject: [PATCH 4/8] Address remaining slow-test review feedback Verify the exact outcome-less completion marker in adapter tests and stabilize terminal reporter access with a runtime invariant check and non-null local alias. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 215e1000-a407-4d84-82a4-2d3696d566fd --- .../Microsoft.Testing.Platform.csproj | 1 + .../TerminalOutputDevice.DataConsumption.cs | 25 ++++++++++--------- .../MSTestTestNodeConverterTests.cs | 1 + 3 files changed, 15 insertions(+), 12 deletions(-) diff --git a/src/Platform/Microsoft.Testing.Platform/Microsoft.Testing.Platform.csproj b/src/Platform/Microsoft.Testing.Platform/Microsoft.Testing.Platform.csproj index f250559b9a..c8e5704709 100644 --- a/src/Platform/Microsoft.Testing.Platform/Microsoft.Testing.Platform.csproj +++ b/src/Platform/Microsoft.Testing.Platform/Microsoft.Testing.Platform.csproj @@ -79,6 +79,7 @@ This package provides the core platform and the .NET implementation of the proto + diff --git a/src/Platform/Microsoft.Testing.Platform/OutputDevice/TerminalOutputDevice.DataConsumption.cs b/src/Platform/Microsoft.Testing.Platform/OutputDevice/TerminalOutputDevice.DataConsumption.cs index f4c89c74a8..c48de6b9bf 100644 --- a/src/Platform/Microsoft.Testing.Platform/OutputDevice/TerminalOutputDevice.DataConsumption.cs +++ b/src/Platform/Microsoft.Testing.Platform/OutputDevice/TerminalOutputDevice.DataConsumption.cs @@ -138,6 +138,7 @@ public Task ConsumeAsync(IDataProducer dataProducer, IData value, CancellationTo { RoslynDebug.Assert(_terminalTestReporter is not null); cancellationToken.ThrowIfCancellationRequested(); + TerminalTestReporter terminalTestReporter = _terminalTestReporter ?? throw ApplicationStateGuard.Unreachable(); // Under --server (e.g. `dotnet test` with `--server dotnettestcli`) the terminal device does not // buffer or render anything: data flows to the SDK through the dotnet-test pipe instead, and the @@ -182,7 +183,7 @@ public Task ConsumeAsync(IDataProducer dataProducer, IData value, CancellationTo case TestNodeStateProperty s: nodeState = s; break; case TestNodeExecutionCompletedProperty: executionCompleted = true; break; case FileArtifactProperty fa: - _terminalTestReporter.ArtifactAdded( + terminalTestReporter.ArtifactAdded( outOfProcess: _processRole != TestProcessRole.TestHost, assembly: _assemblyName, targetFramework: _targetFramework, @@ -200,7 +201,7 @@ public Task ConsumeAsync(IDataProducer dataProducer, IData value, CancellationTo if (executionCompleted) { - _terminalTestReporter.TestCompletedWithoutResult( + terminalTestReporter.TestCompletedWithoutResult( InProcessExecutionId, testNodeStateChanged.TestNode.Uid.Value); break; @@ -209,14 +210,14 @@ public Task ConsumeAsync(IDataProducer dataProducer, IData value, CancellationTo switch (nodeState) { case InProgressTestNodeStateProperty: - _terminalTestReporter.TestInProgress( + terminalTestReporter.TestInProgress( InProcessExecutionId, testNodeStateChanged.TestNode.Uid.Value, testNodeStateChanged.TestNode.DisplayName); break; case ErrorTestNodeStateProperty errorState: - _terminalTestReporter.TestCompleted( + terminalTestReporter.TestCompleted( InProcessExecutionId, testNodeStateChanged.TestNode.Uid.Value, testNodeStateChanged.TestNode.DisplayName, @@ -232,7 +233,7 @@ public Task ConsumeAsync(IDataProducer dataProducer, IData value, CancellationTo break; case FailedTestNodeStateProperty failedState: - _terminalTestReporter.TestCompleted( + terminalTestReporter.TestCompleted( InProcessExecutionId, testNodeStateChanged.TestNode.Uid.Value, testNodeStateChanged.TestNode.DisplayName, @@ -248,7 +249,7 @@ public Task ConsumeAsync(IDataProducer dataProducer, IData value, CancellationTo break; case TimeoutTestNodeStateProperty timeoutState: - _terminalTestReporter.TestCompleted( + terminalTestReporter.TestCompleted( InProcessExecutionId, testNodeStateChanged.TestNode.Uid.Value, testNodeStateChanged.TestNode.DisplayName, @@ -266,7 +267,7 @@ public Task ConsumeAsync(IDataProducer dataProducer, IData value, CancellationTo #pragma warning disable CS0618, MTP0001 // Type or member is obsolete case CancelledTestNodeStateProperty cancelledState: #pragma warning restore CS0618, MTP0001 // Type or member is obsolete - _terminalTestReporter.TestCompleted( + terminalTestReporter.TestCompleted( InProcessExecutionId, testNodeStateChanged.TestNode.Uid.Value, testNodeStateChanged.TestNode.DisplayName, @@ -282,7 +283,7 @@ public Task ConsumeAsync(IDataProducer dataProducer, IData value, CancellationTo break; case PassedTestNodeStateProperty: - _terminalTestReporter.TestCompleted( + terminalTestReporter.TestCompleted( InProcessExecutionId, testNodeStateChanged.TestNode.Uid.Value, testNodeStateChanged.TestNode.DisplayName, @@ -298,7 +299,7 @@ public Task ConsumeAsync(IDataProducer dataProducer, IData value, CancellationTo break; case SkippedTestNodeStateProperty skippedState: - _terminalTestReporter.TestCompleted( + terminalTestReporter.TestCompleted( InProcessExecutionId, testNodeStateChanged.TestNode.Uid.Value, testNodeStateChanged.TestNode.DisplayName, @@ -314,7 +315,7 @@ public Task ConsumeAsync(IDataProducer dataProducer, IData value, CancellationTo break; case DiscoveredTestNodeStateProperty: - _terminalTestReporter.TestDiscovered(InProcessExecutionId, testNodeStateChanged.TestNode.DisplayName); + terminalTestReporter.TestDiscovered(InProcessExecutionId, testNodeStateChanged.TestNode.DisplayName); break; } @@ -322,7 +323,7 @@ public Task ConsumeAsync(IDataProducer dataProducer, IData value, CancellationTo case SessionFileArtifact artifact: { - _terminalTestReporter.ArtifactAdded( + terminalTestReporter.ArtifactAdded( outOfProcess: _processRole != TestProcessRole.TestHost, assembly: _assemblyName, targetFramework: _targetFramework, @@ -335,7 +336,7 @@ public Task ConsumeAsync(IDataProducer dataProducer, IData value, CancellationTo break; case FileArtifact artifact: { - _terminalTestReporter.ArtifactAdded( + terminalTestReporter.ArtifactAdded( outOfProcess: _processRole != TestProcessRole.TestHost, assembly: _assemblyName, targetFramework: _targetFramework, diff --git a/test/UnitTests/MSTestAdapter.UnitTests/MSTestTestNodeConverterTests.cs b/test/UnitTests/MSTestAdapter.UnitTests/MSTestTestNodeConverterTests.cs index ba089286ec..1a8dad27df 100644 --- a/test/UnitTests/MSTestAdapter.UnitTests/MSTestTestNodeConverterTests.cs +++ b/test/UnitTests/MSTestAdapter.UnitTests/MSTestTestNodeConverterTests.cs @@ -375,6 +375,7 @@ public async Task MtpTestResultRecorder_RecordEmptyResult_PublishesExecutionComp await recorder.RecordEmptyResultAsync(CreateElement()); var message = (TestNodeUpdateMessage)messageBus.Published.Single(); + message.TestNode.Properties.Any().Should().BeTrue(); message.TestNode.Properties.Any().Should().BeFalse(); } From 34e4abb362da9db98f0feb2b1ecdc179ba6244bf Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Amaury=20Lev=C3=A9?= Date: Fri, 24 Jul 2026 13:22:00 +0200 Subject: [PATCH 5/8] Complete outcome-less test lifecycle handling Clear outcome-less completion from hang, crash, and video diagnostics, and validate slow-test snapshots against the exact active execution to avoid same-UID ABA reports. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 215e1000-a407-4d84-82a4-2d3696d566fd --- .../CrashDumpSequenceLogger.cs | 27 ++++---- .../HangDumpActivityIndicator.cs | 6 +- ...ideoRecorderSessionHandler.DataConsumer.cs | 14 +++- .../InternalAPI/InternalAPI.Unshipped.txt | 5 +- .../Microsoft.Testing.Platform.csproj | 1 + .../OutputDevice/ActiveTestTracker.cs | 18 +++-- .../SimplifiedConsoleOutputDeviceBase.cs | 2 +- .../CrashDumpSequenceLoggerTests.cs | 48 +++++++++++++ .../HangDumpTests.cs | 47 +++++++++++++ ...rosoft.Testing.Extensions.UnitTests.csproj | 3 + .../VideoRecorderSessionHandlerTests.cs | 69 +++++++++++++++++++ .../SimplifiedConsoleOutputDeviceTests.cs | 37 ++++++++++ 12 files changed, 252 insertions(+), 25 deletions(-) create mode 100644 test/UnitTests/Microsoft.Testing.Extensions.UnitTests/VideoRecorderSessionHandlerTests.cs diff --git a/src/Platform/Microsoft.Testing.Extensions.CrashDump/CrashDumpSequenceLogger.cs b/src/Platform/Microsoft.Testing.Extensions.CrashDump/CrashDumpSequenceLogger.cs index ed892803fd..b656274e88 100644 --- a/src/Platform/Microsoft.Testing.Extensions.CrashDump/CrashDumpSequenceLogger.cs +++ b/src/Platform/Microsoft.Testing.Extensions.CrashDump/CrashDumpSequenceLogger.cs @@ -164,24 +164,27 @@ public async Task ConsumeAsync(IDataProducer dataProducer, IData value, Cancella } TestNodeStateProperty? state = update.TestNode.Properties.SingleOrDefault(); - if (state is null) + bool executionCompleted = update.TestNode.Properties.Any(); + if (state is null && !executionCompleted) { return; } - string? line = state switch - { - InProgressTestNodeStateProperty => FormatLine(StartedEvent, _clock.UtcNow, update.TestNode.Uid, update.TestNode.DisplayName), + string? line = executionCompleted + ? FormatLine(EndedEvent, _clock.UtcNow, update.TestNode.Uid, "Completed") + : state switch + { + InProgressTestNodeStateProperty => FormatLine(StartedEvent, _clock.UtcNow, update.TestNode.Uid, update.TestNode.DisplayName), #pragma warning disable CS0618, MTP0001 // Type or member is obsolete - keep parity with HangDumpActivityIndicator's terminal-state set. - PassedTestNodeStateProperty => FormatLine(EndedEvent, _clock.UtcNow, update.TestNode.Uid, "Passed"), - FailedTestNodeStateProperty => FormatLine(EndedEvent, _clock.UtcNow, update.TestNode.Uid, "Failed"), - ErrorTestNodeStateProperty => FormatLine(EndedEvent, _clock.UtcNow, update.TestNode.Uid, "Error"), - SkippedTestNodeStateProperty => FormatLine(EndedEvent, _clock.UtcNow, update.TestNode.Uid, "Skipped"), - CancelledTestNodeStateProperty => FormatLine(EndedEvent, _clock.UtcNow, update.TestNode.Uid, "Cancelled"), - TimeoutTestNodeStateProperty => FormatLine(EndedEvent, _clock.UtcNow, update.TestNode.Uid, "Timeout"), + PassedTestNodeStateProperty => FormatLine(EndedEvent, _clock.UtcNow, update.TestNode.Uid, "Passed"), + FailedTestNodeStateProperty => FormatLine(EndedEvent, _clock.UtcNow, update.TestNode.Uid, "Failed"), + ErrorTestNodeStateProperty => FormatLine(EndedEvent, _clock.UtcNow, update.TestNode.Uid, "Error"), + SkippedTestNodeStateProperty => FormatLine(EndedEvent, _clock.UtcNow, update.TestNode.Uid, "Skipped"), + CancelledTestNodeStateProperty => FormatLine(EndedEvent, _clock.UtcNow, update.TestNode.Uid, "Cancelled"), + TimeoutTestNodeStateProperty => FormatLine(EndedEvent, _clock.UtcNow, update.TestNode.Uid, "Timeout"), #pragma warning restore CS0618, MTP0001 - _ => null, - }; + _ => null, + }; if (line is null) { diff --git a/src/Platform/Microsoft.Testing.Extensions.HangDump/HangDumpActivityIndicator.cs b/src/Platform/Microsoft.Testing.Extensions.HangDump/HangDumpActivityIndicator.cs index 0299ec571c..8ed681b06b 100644 --- a/src/Platform/Microsoft.Testing.Extensions.HangDump/HangDumpActivityIndicator.cs +++ b/src/Platform/Microsoft.Testing.Extensions.HangDump/HangDumpActivityIndicator.cs @@ -130,6 +130,7 @@ public async Task ConsumeAsync(IDataProducer dataProducer, IData value, Cancella } TestNodeStateProperty? state = nodeChangedMessage.TestNode.Properties.SingleOrDefault(); + bool executionCompleted = nodeChangedMessage.TestNode.Properties.Any(); if (state is InProgressTestNodeStateProperty) { if (_traceLevelEnabled) @@ -140,9 +141,10 @@ public async Task ConsumeAsync(IDataProducer dataProducer, IData value, Cancella _testsCurrentExecutionState.TryAdd(nodeChangedMessage.TestNode.Uid, (nodeChangedMessage.TestNode.DisplayName, typeof(InProgressTestNodeStateProperty), _clock.UtcNow)); } #pragma warning disable CS0618, MTP0001 // Type or member is obsolete - else if (state is PassedTestNodeStateProperty or ErrorTestNodeStateProperty or CancelledTestNodeStateProperty + else if ((executionCompleted + || state is PassedTestNodeStateProperty or ErrorTestNodeStateProperty or CancelledTestNodeStateProperty #pragma warning restore CS0618, MTP0001 // Type or member is obsolete - or FailedTestNodeStateProperty or TimeoutTestNodeStateProperty or SkippedTestNodeStateProperty + or FailedTestNodeStateProperty or TimeoutTestNodeStateProperty or SkippedTestNodeStateProperty) && _testsCurrentExecutionState.TryRemove(nodeChangedMessage.TestNode.Uid, out (string Name, Type Type, DateTimeOffset StartTime) record) && _traceLevelEnabled) { diff --git a/src/Platform/Microsoft.Testing.Extensions.VideoRecorder/VideoRecorderSessionHandler.DataConsumer.cs b/src/Platform/Microsoft.Testing.Extensions.VideoRecorder/VideoRecorderSessionHandler.DataConsumer.cs index 583f7c591c..a79a4c68f5 100644 --- a/src/Platform/Microsoft.Testing.Extensions.VideoRecorder/VideoRecorderSessionHandler.DataConsumer.cs +++ b/src/Platform/Microsoft.Testing.Extensions.VideoRecorder/VideoRecorderSessionHandler.DataConsumer.cs @@ -17,6 +17,18 @@ public Task ConsumeAsync(IDataProducer dataProducer, IData value, CancellationTo return Task.CompletedTask; } + string testUid = update.TestNode.Uid.Value; + if (update.TestNode.Properties.Any()) + { + lock (_stateGate) + { + _inFlight.Remove(testUid); + } + + TryPruneOldSegments(); + return Task.CompletedTask; + } + // A node carries a single state property in practice; use FirstOrDefault rather than // SingleOrDefault so a malformed producer can't throw out of the consumer pump. TestNodeStateProperty? state = update.TestNode.Properties.FirstOrDefault(); @@ -25,8 +37,6 @@ public Task ConsumeAsync(IDataProducer dataProducer, IData value, CancellationTo return Task.CompletedTask; } - string testUid = update.TestNode.Uid.Value; - if (state is InProgressTestNodeStateProperty) { lock (_stateGate) diff --git a/src/Platform/Microsoft.Testing.Platform/InternalAPI/InternalAPI.Unshipped.txt b/src/Platform/Microsoft.Testing.Platform/InternalAPI/InternalAPI.Unshipped.txt index 9e89b6a77f..e603e3ebd5 100644 --- a/src/Platform/Microsoft.Testing.Platform/InternalAPI/InternalAPI.Unshipped.txt +++ b/src/Platform/Microsoft.Testing.Platform/InternalAPI/InternalAPI.Unshipped.txt @@ -279,7 +279,7 @@ Microsoft.Testing.Platform.OutputDevice.ActiveTestTracker.ActiveTestTracker(Syst Microsoft.Testing.Platform.OutputDevice.ActiveTestTracker.Clear() -> void Microsoft.Testing.Platform.OutputDevice.ActiveTestTracker.Complete(Microsoft.Testing.Platform.Extensions.Messages.TestNodeUid! uid) -> void Microsoft.Testing.Platform.OutputDevice.ActiveTestTracker.GetDueDiagnostics() -> Microsoft.Testing.Platform.OutputDevice.SlowTestDiagnostic![]! -Microsoft.Testing.Platform.OutputDevice.ActiveTestTracker.IsActive(Microsoft.Testing.Platform.Extensions.Messages.TestNodeUid! uid) -> bool +Microsoft.Testing.Platform.OutputDevice.ActiveTestTracker.IsActive(Microsoft.Testing.Platform.OutputDevice.SlowTestDiagnostic! diagnostic) -> bool Microsoft.Testing.Platform.OutputDevice.ActiveTestTracker.IsEnabled.get -> bool Microsoft.Testing.Platform.OutputDevice.ActiveTestTracker.Start(Microsoft.Testing.Platform.Extensions.Messages.TestNodeUid! uid, string! displayName) -> void Microsoft.Testing.Platform.OutputDevice.ProgressReportingConfiguration @@ -288,7 +288,8 @@ Microsoft.Testing.Platform.OutputDevice.SimplifiedConsoleOutputDeviceBase.Simpli Microsoft.Testing.Platform.OutputDevice.SlowTestDiagnostic Microsoft.Testing.Platform.OutputDevice.SlowTestDiagnostic.DisplayName.get -> string! Microsoft.Testing.Platform.OutputDevice.SlowTestDiagnostic.Elapsed.get -> System.TimeSpan -Microsoft.Testing.Platform.OutputDevice.SlowTestDiagnostic.SlowTestDiagnostic(Microsoft.Testing.Platform.Extensions.Messages.TestNodeUid! uid, string! displayName, System.TimeSpan elapsed) -> void +Microsoft.Testing.Platform.OutputDevice.SlowTestDiagnostic.Generation.get -> long +Microsoft.Testing.Platform.OutputDevice.SlowTestDiagnostic.SlowTestDiagnostic(Microsoft.Testing.Platform.Extensions.Messages.TestNodeUid! uid, string! displayName, System.TimeSpan elapsed, long generation) -> void Microsoft.Testing.Platform.OutputDevice.SlowTestDiagnostic.Uid.get -> Microsoft.Testing.Platform.Extensions.Messages.TestNodeUid! Microsoft.Testing.Platform.OutputDevice.SlowTestThresholdState Microsoft.Testing.Platform.OutputDevice.SlowTestThresholdState.IsDue(System.TimeSpan elapsed) -> bool diff --git a/src/Platform/Microsoft.Testing.Platform/Microsoft.Testing.Platform.csproj b/src/Platform/Microsoft.Testing.Platform/Microsoft.Testing.Platform.csproj index c8e5704709..13af3f73d6 100644 --- a/src/Platform/Microsoft.Testing.Platform/Microsoft.Testing.Platform.csproj +++ b/src/Platform/Microsoft.Testing.Platform/Microsoft.Testing.Platform.csproj @@ -62,6 +62,7 @@ This package provides the core platform and the .NET implementation of the proto +