From 11720b63f1bf26b924b1e4d9f5f3c079863bda93 Mon Sep 17 00:00:00 2001 From: Reuben Bond Date: Thu, 30 Jul 2026 10:36:01 -0700 Subject: [PATCH] Add periodic simulation progress output Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 160c250e-b226-4ce4-88a2-8024aa9aa161 --- Directory.Packages.props | 1 + README.md | 26 +- .../Clockwork.Testing.csproj | 23 +- ...kworkProgressCommandLineOptionsProvider.cs | 223 ++++++++++++++++++ .../Clockwork.Simulation.Testing.props | 8 + src/Clockwork/AssemblyInfo.cs | 1 + .../Cluster/SimulationCluster.Adaptive.cs | 14 +- src/Clockwork/Cluster/SimulationCluster.cs | 22 +- .../Execution/SimulationDriveLoop.cs | 17 +- .../SimulationProgressEnvironment.cs | 78 ++++++ .../Execution/SimulationProgressReporter.cs | 115 +++++++++ .../Clockwork.Testing.Tests.csproj | 2 + ...ProgressCommandLineOptionsProviderTests.cs | 111 +++++++++ tests/Clockwork.Tests/Clockwork.Tests.csproj | 3 + .../SimulationProgressReporterTests.cs | 140 +++++++++++ 15 files changed, 774 insertions(+), 10 deletions(-) create mode 100644 src/Clockwork.Testing/ClockworkProgressCommandLineOptionsProvider.cs create mode 100644 src/Clockwork.Testing/buildTransitive/Clockwork.Simulation.Testing.props create mode 100644 src/Clockwork/Execution/SimulationProgressEnvironment.cs create mode 100644 src/Clockwork/Execution/SimulationProgressReporter.cs create mode 100644 tests/Clockwork.Testing.Tests/ClockworkProgressCommandLineOptionsProviderTests.cs create mode 100644 tests/Clockwork.Tests/SimulationProgressReporterTests.cs diff --git a/Directory.Packages.props b/Directory.Packages.props index 3e2cb6b..b40dc6b 100644 --- a/Directory.Packages.props +++ b/Directory.Packages.props @@ -8,6 +8,7 @@ + diff --git a/README.md b/README.md index 2a1a522..2a46833 100644 --- a/README.md +++ b/README.md @@ -49,7 +49,9 @@ dotnet run --project tests\Clockwork.Tests\Clockwork.Tests.csproj -- --timeout 6 dotnet pack src/Clockwork/Clockwork.csproj --configuration Release ``` -The NuGet package ID is `Clockwork.Simulation`. Until packages are published, clone the repository or add it as a Git submodule and reference `src/Clockwork/Clockwork.csproj`. +The core NuGet package ID is `Clockwork.Simulation`; test-runner integration and replay helpers are +in `Clockwork.Simulation.Testing`. Until packages are published, clone the repository or add it as a +Git submodule and reference the corresponding project under `src`. ## Instrumented simulation test projects @@ -244,6 +246,28 @@ including the stop reason, counters, limits, and pending-work snapshot. They sha engine, so time advancement and stuck detection remain consistent. Every drive method requires a `CancellationToken` and observes it between simulation dispatches. +### Live simulation progress + +Set `CLOCKWORK_PROGRESS_INTERVAL` to a positive wall-clock interval to report exact live drive-loop +counters to standard error from every active cluster: + +```powershell +$env:CLOCKWORK_PROGRESS_INTERVAL = "5s" +dotnet run --project tests\Clockwork.Tests\Clockwork.Tests.csproj +``` + +Test projects which reference `Clockwork.Simulation.Testing` and use Microsoft Testing Platform can +set the same interval when invoking their generated test executable: + +```powershell +dotnet run --project tests\Clockwork.Tests\Clockwork.Tests.csproj -- --clockwork-progress 5s +``` + +Each line includes the runtime id and seed, wall-clock elapsed time, drive-loop iterations, scheduled +steps executed, virtual-time advances, simulated elapsed time, pending scheduler operations, and +runnable/waiting/blocked queue counts. Reporting observes the simulation without scheduling simulated +work, so enabling it does not change deterministic execution. + ## Execution results and diagnostics Every drive method returns a `SimulationExecutionResult` describing exactly why the run stopped: diff --git a/src/Clockwork.Testing/Clockwork.Testing.csproj b/src/Clockwork.Testing/Clockwork.Testing.csproj index 9bdccc3..bdf5f28 100644 --- a/src/Clockwork.Testing/Clockwork.Testing.csproj +++ b/src/Clockwork.Testing/Clockwork.Testing.csproj @@ -1,17 +1,36 @@ - Replay-aware test helpers for deterministic Clockwork scenarios, including in-memory log capture, stable test identity seeds, failure artifacts, and environment-driven replay. + Test helpers and Microsoft Testing Platform integration for deterministic Clockwork scenarios, including live progress, in-memory log capture, stable test identity seeds, failure artifacts, and environment-driven replay. Clockwork.Testing - false + Clockwork.Simulation.Testing + 0.1.0 + simulation;testing;distributed-systems;deterministic;microsoft-testing-platform + MIT + README.md + https://github.com/ReubenBond/Clockwork + true + false + + + + + + + + diff --git a/src/Clockwork.Testing/ClockworkProgressCommandLineOptionsProvider.cs b/src/Clockwork.Testing/ClockworkProgressCommandLineOptionsProvider.cs new file mode 100644 index 0000000..a4a2c72 --- /dev/null +++ b/src/Clockwork.Testing/ClockworkProgressCommandLineOptionsProvider.cs @@ -0,0 +1,223 @@ +using System.Globalization; +using System.Text; +using Microsoft.Testing.Platform.Builder; +using Microsoft.Testing.Platform.CommandLine; +using Microsoft.Testing.Platform.Extensions; +using Microsoft.Testing.Platform.Extensions.CommandLine; +using Microsoft.Testing.Platform.Extensions.OutputDevice; +using Microsoft.Testing.Platform.Extensions.TestHost; +using Microsoft.Testing.Platform.Extensions.TestHostControllers; +using Microsoft.Testing.Platform.OutputDevice; +using Microsoft.Testing.Platform.Services; + +namespace Clockwork.Testing; + +/// Registers Clockwork's Microsoft Testing Platform command-line options. +public static class TestingPlatformBuilderHook +{ + /// Adds Clockwork test-runner extensions to the application builder. + /// The test application builder. + /// The test application command-line arguments. + public static void AddExtensions(ITestApplicationBuilder testApplicationBuilder, string[] _) + { + ArgumentNullException.ThrowIfNull(testApplicationBuilder); + testApplicationBuilder.CommandLine.AddProvider(static () => new ClockworkProgressCommandLineOptionsProvider()); + testApplicationBuilder.TestHost.AddTestHostApplicationLifetime( + static serviceProvider => new ClockworkProgressOutputLifetime(serviceProvider.GetOutputDevice())); + testApplicationBuilder.TestHostControllers.AddEnvironmentVariableProvider( + static serviceProvider => new ClockworkProgressEnvironmentVariableProvider( + serviceProvider.GetCommandLineOptions())); + } +} + +internal sealed class ClockworkProgressCommandLineOptionsProvider : ICommandLineOptionsProvider +{ + internal const string OptionName = "clockwork-progress"; + + private static readonly CommandLineOption[] s_options = + [ + new( + OptionName, + "Report live simulation iterations, executed steps, time advances, simulated time, and pending work at this wall-clock interval (for example, 5s).", + ArgumentArity.ExactlyOne, + isHidden: false), + ]; + + public string Uid => "ClockworkProgressCommandLineOptionsProvider"; + + public string Version => "0.1.0"; + + public string DisplayName => "Clockwork simulation progress"; + + public string Description => "Enables periodic progress output from active Clockwork simulation drive loops."; + + public IReadOnlyCollection GetCommandLineOptions() => s_options; + + public Task IsEnabledAsync() => Task.FromResult(true); + + public Task ValidateOptionArgumentsAsync(CommandLineOption commandOption, string[] arguments) + { + if (commandOption.Name != OptionName) + { + return ValidationResult.ValidTask; + } + + return arguments is [var value] && SimulationProgressEnvironment.TryParseInterval(value, out _) + ? ValidationResult.ValidTask + : ValidationResult.InvalidTask( + $"--{OptionName} must be followed by a positive duration such as '5s', '500ms', '2m', or '00:00:05'."); + } + + public Task ValidateCommandLineOptionsAsync(ICommandLineOptions commandLineOptions) + { + if (!commandLineOptions.TryGetOptionArgumentList(OptionName, out string[]? arguments)) + { + return ValidationResult.ValidTask; + } + + if (arguments is not [var value] || + !SimulationProgressEnvironment.TryParseInterval(value, out TimeSpan interval)) + { + return ValidationResult.InvalidTask( + $"--{OptionName} must be followed by a positive duration such as '5s', '500ms', '2m', or '00:00:05'."); + } + + Environment.SetEnvironmentVariable( + SimulationProgressEnvironment.Interval, + interval.ToString("c", CultureInfo.InvariantCulture)); + return ValidationResult.ValidTask; + } +} + +internal sealed class ClockworkProgressEnvironmentVariableProvider : ITestHostEnvironmentVariableProvider +{ + private readonly string? _value; + private readonly string? _validationError; + + public ClockworkProgressEnvironmentVariableProvider(ICommandLineOptions commandLineOptions) + { + ArgumentNullException.ThrowIfNull(commandLineOptions); + + string? value = commandLineOptions.TryGetOptionArgumentList( + ClockworkProgressCommandLineOptionsProvider.OptionName, + out string[]? arguments) + ? arguments is [var argument] ? argument : null + : Environment.GetEnvironmentVariable(SimulationProgressEnvironment.Interval); + + if (string.IsNullOrWhiteSpace(value)) + { + return; + } + + _value = value; + if (!SimulationProgressEnvironment.TryParseInterval(value, out _)) + { + _validationError = + $"{SimulationProgressEnvironment.Interval} must be a positive duration such as " + + $"'5s', '500ms', '2m', or '00:00:05', not '{value}'."; + } + } + + public string Uid => "ClockworkProgressEnvironmentVariableProvider"; + + public string Version => "0.1.0"; + + public string DisplayName => "Clockwork simulation progress environment"; + + public string Description => "Forwards Clockwork progress configuration to orchestrated test hosts."; + + public Task IsEnabledAsync() => Task.FromResult(_value is not null); + + public Task UpdateAsync(IEnvironmentVariables environmentVariables) + { + ArgumentNullException.ThrowIfNull(environmentVariables); + if (_value is not null) + { + environmentVariables.SetVariable(new EnvironmentVariable( + SimulationProgressEnvironment.Interval, + _value, + isSecret: false, + isLocked: true)); + } + + return Task.CompletedTask; + } + + public Task ValidateTestHostEnvironmentVariablesAsync( + IReadOnlyEnvironmentVariables environmentVariables) + { + ArgumentNullException.ThrowIfNull(environmentVariables); + if (_validationError is not null) + { + return ValidationResult.InvalidTask(_validationError); + } + + if (_value is null) + { + return ValidationResult.ValidTask; + } + + return environmentVariables.TryGetVariable( + SimulationProgressEnvironment.Interval, + out OwnedEnvironmentVariable? configured) && + configured.Value == _value + ? ValidationResult.ValidTask + : ValidationResult.InvalidTask( + $"Unable to pass {SimulationProgressEnvironment.Interval} to the test host."); + } +} + +internal sealed class ClockworkProgressOutputLifetime : + ITestHostApplicationLifetime, + IOutputDeviceDataProducer, + IDisposable +{ + private readonly TextWriter _writer; + + public ClockworkProgressOutputLifetime(IOutputDevice outputDevice) + { + ArgumentNullException.ThrowIfNull(outputDevice); + _writer = new OutputDeviceTextWriter(outputDevice, this); + } + + public string Uid => "ClockworkProgressOutputLifetime"; + + public string Version => "0.1.0"; + + public string DisplayName => "Clockwork simulation progress output"; + + public string Description => "Routes Clockwork progress through the Microsoft Testing Platform output device."; + + public Task IsEnabledAsync() => Task.FromResult(true); + + public Task BeforeRunAsync(CancellationToken cancellationToken) + { + SimulationProgressOutput.SetWriter(_writer); + return Task.CompletedTask; + } + + public Task AfterRunAsync(int exitCode, CancellationToken cancellationToken) + { + SimulationProgressOutput.SetWriter(null); + return Task.CompletedTask; + } + + public void Dispose() + { + SimulationProgressOutput.SetWriter(null); + _writer.Dispose(); + } + + private sealed class OutputDeviceTextWriter( + IOutputDevice outputDevice, + IOutputDeviceDataProducer producer) : TextWriter + { + public override Encoding Encoding => Encoding.UTF8; + + public override void WriteLine(string? value) => + outputDevice.DisplayAsync( + producer, + new TextOutputDeviceData(value ?? string.Empty), + CancellationToken.None).GetAwaiter().GetResult(); + } +} diff --git a/src/Clockwork.Testing/buildTransitive/Clockwork.Simulation.Testing.props b/src/Clockwork.Testing/buildTransitive/Clockwork.Simulation.Testing.props new file mode 100644 index 0000000..2131021 --- /dev/null +++ b/src/Clockwork.Testing/buildTransitive/Clockwork.Simulation.Testing.props @@ -0,0 +1,8 @@ + + + + Clockwork.Simulation.Testing + Clockwork.Testing.TestingPlatformBuilderHook + + + diff --git a/src/Clockwork/AssemblyInfo.cs b/src/Clockwork/AssemblyInfo.cs index 3e2faee..99cb7a5 100644 --- a/src/Clockwork/AssemblyInfo.cs +++ b/src/Clockwork/AssemblyInfo.cs @@ -3,3 +3,4 @@ [assembly: InternalsVisibleTo("Clockwork.Tests")] [assembly: InternalsVisibleTo("Clockwork.Runtime.Tests")] [assembly: InternalsVisibleTo("Clockwork.Benchmarks")] +[assembly: InternalsVisibleTo("Clockwork.Testing")] diff --git a/src/Clockwork/Cluster/SimulationCluster.Adaptive.cs b/src/Clockwork/Cluster/SimulationCluster.Adaptive.cs index 08926f2..8b1f270 100644 --- a/src/Clockwork/Cluster/SimulationCluster.Adaptive.cs +++ b/src/Clockwork/Cluster/SimulationCluster.Adaptive.cs @@ -62,6 +62,10 @@ public SimulationExecutionResult RunUntil( ArgumentNullException.ThrowIfNull(budget); using var control = Scheduler.EnterControlScope(); using var _ = Guard.Enter(); + SimulationProgressReporter? progressReporter = SimulationProgressReporter.CreateFromEnvironment( + RuntimeIdentity, + CapturePendingWorkSummary, + () => Scheduler.PendingOperationCount); return RunAdaptiveCore( budget, (batchMaxIterations, consecutiveTimeAdvances) => ExecuteDriveLoop( @@ -71,7 +75,8 @@ public SimulationExecutionResult RunUntil( observeTeardownCancellation: false, initialConsecutiveTimeAdvances: consecutiveTimeAdvances, absoluteEndTime: null, - cancellationToken: cancellationToken)); + cancellationToken: cancellationToken, + progressReporter: progressReporter)); } /// @@ -103,6 +108,10 @@ public SimulationExecutionResult RunUntilIdle( ArgumentNullException.ThrowIfNull(budget); using var control = Scheduler.EnterControlScope(); using var _ = Guard.Enter(); + SimulationProgressReporter? progressReporter = SimulationProgressReporter.CreateFromEnvironment( + RuntimeIdentity, + CapturePendingWorkSummary, + () => Scheduler.PendingOperationCount); return RunAdaptiveCore( budget, (batchMaxIterations, consecutiveTimeAdvances) => ExecuteDriveLoop( @@ -112,7 +121,8 @@ public SimulationExecutionResult RunUntilIdle( observeTeardownCancellation: true, initialConsecutiveTimeAdvances: consecutiveTimeAdvances, absoluteEndTime: null, - cancellationToken: cancellationToken)); + cancellationToken: cancellationToken, + progressReporter: progressReporter)); } #pragma warning restore CA1068 diff --git a/src/Clockwork/Cluster/SimulationCluster.cs b/src/Clockwork/Cluster/SimulationCluster.cs index 43d2aa5..17acb49 100644 --- a/src/Clockwork/Cluster/SimulationCluster.cs +++ b/src/Clockwork/Cluster/SimulationCluster.cs @@ -647,10 +647,20 @@ private SimulationExecutionResult ExecuteDriveLoop( bool observeTeardownCancellation, int initialConsecutiveTimeAdvances, DateTimeOffset? absoluteEndTime, - CancellationToken cancellationToken) + CancellationToken cancellationToken, + SimulationProgressReporter? progressReporter = null, + bool enableProgress = true) { using var control = Scheduler.EnterControlScope(); using var _ = Guard.Enter(); + if (enableProgress && _disposalFailures is null) + { + progressReporter ??= SimulationProgressReporter.CreateFromEnvironment( + RuntimeIdentity, + CapturePendingWorkSummary, + () => Scheduler.PendingOperationCount); + } + var options = new SimulationDriveLoopOptions( condition, maxSimulatedTimeAdvance, @@ -659,8 +669,11 @@ private SimulationExecutionResult ExecuteDriveLoop( observeTeardownCancellation, initialConsecutiveTimeAdvances, absoluteEndTime, - cancellationToken); - return _driveLoop.Execute(options); + cancellationToken, + progressReporter is null ? null : progressReporter.Report); + SimulationExecutionResult result = _driveLoop.Execute(options); + progressReporter?.CompleteBatch(result); + return result; } /// @@ -896,7 +909,8 @@ private void DrainAttachmentWorkToQuiescence( observeTeardownCancellation: false, initialConsecutiveTimeAdvances: 0, absoluteEndTime: null, - cancellationToken: CancellationToken.None); + cancellationToken: CancellationToken.None, + enableProgress: false); if (contexts.Any(static context => context.HasPendingAttachmentWork)) { AddDisposalFailure( diff --git a/src/Clockwork/Execution/SimulationDriveLoop.cs b/src/Clockwork/Execution/SimulationDriveLoop.cs index 81e1a69..8581fb8 100644 --- a/src/Clockwork/Execution/SimulationDriveLoop.cs +++ b/src/Clockwork/Execution/SimulationDriveLoop.cs @@ -20,6 +20,7 @@ namespace Clockwork; /// scheduler's virtual time never advances beyond it. /// /// The caller-controlled token checked before each loop iteration. +/// An optional observer invoked after every completed drive-loop iteration. internal readonly record struct SimulationDriveLoopOptions( Func? Condition, TimeSpan MaxSimulatedTimeAdvance, @@ -28,7 +29,8 @@ internal readonly record struct SimulationDriveLoopOptions( bool ObserveTeardownCancellation, int InitialConsecutiveTimeAdvances, DateTimeOffset? EndTime, - CancellationToken CancellationToken); + CancellationToken CancellationToken, + Action? Progress = null); /// /// @@ -88,6 +90,7 @@ public SimulationExecutionResult Execute(SimulationDriveLoopOptions options) { stepsExecuted++; consecutiveTimeAdvances = 0; // Reset the stuck-detection counter when real work happens. + ReportProgress(iteration + 1); continue; } @@ -140,6 +143,7 @@ public SimulationExecutionResult Execute(SimulationDriveLoopOptions options) consecutiveTimeAdvances++; totalTimeAdvances++; + ReportProgress(iteration + 1); if (consecutiveTimeAdvances > options.MaxConsecutiveTimeAdvances) { @@ -206,5 +210,16 @@ SimulationExecutionResult Complete( new SimulationExecutionLimits(options.MaxIterations, options.MaxSimulatedTimeAdvance, options.MaxConsecutiveTimeAdvances), attemptedTimeAdvance); } + + void ReportProgress(int iterations) + { + options.Progress?.Invoke(new SimulationProgressSnapshot( + iterations, + stepsExecuted, + totalTimeAdvances, + consecutiveTimeAdvances, + startTime, + getUtcNow())); + } } } diff --git a/src/Clockwork/Execution/SimulationProgressEnvironment.cs b/src/Clockwork/Execution/SimulationProgressEnvironment.cs new file mode 100644 index 0000000..d171b86 --- /dev/null +++ b/src/Clockwork/Execution/SimulationProgressEnvironment.cs @@ -0,0 +1,78 @@ +using System.Globalization; + +namespace Clockwork; + +/// Environment variables which control periodic simulation progress reporting. +public static class SimulationProgressEnvironment +{ + /// + /// Enables progress output when set to a positive duration such as 5s, 500ms, + /// 2m, or 00:00:05. + /// + public const string Interval = "CLOCKWORK_PROGRESS_INTERVAL"; + + internal static TimeSpan? GetInterval() + { + string? value = Environment.GetEnvironmentVariable(Interval); + if (string.IsNullOrWhiteSpace(value)) + { + return null; + } + + if (TryParseInterval(value, out TimeSpan interval)) + { + return interval; + } + + throw new InvalidOperationException( + $"{Interval} must be a positive duration such as '5s', '500ms', '2m', or '00:00:05', not '{value}'."); + } + + internal static bool TryParseInterval(string? value, out TimeSpan interval) + { + interval = default; + if (string.IsNullOrWhiteSpace(value)) + { + return false; + } + + string text = value.Trim(); + if (text.Contains(':') && + TimeSpan.TryParse(text, CultureInfo.InvariantCulture, out interval) && + interval > TimeSpan.Zero) + { + return true; + } + + (string Suffix, Func Convert)[] suffixes = + [ + ("ms", TimeSpan.FromMilliseconds), + ("s", TimeSpan.FromSeconds), + ("m", TimeSpan.FromMinutes), + ("h", TimeSpan.FromHours), + ]; + + foreach (var (suffix, convert) in suffixes) + { + if (!text.EndsWith(suffix, StringComparison.OrdinalIgnoreCase) || + !double.TryParse(text[..^suffix.Length], NumberStyles.Float, CultureInfo.InvariantCulture, out double amount) || + !double.IsFinite(amount) || + amount <= 0) + { + continue; + } + + try + { + interval = convert(amount); + return interval > TimeSpan.Zero; + } + catch (OverflowException) + { + return false; + } + } + + return false; + } +} diff --git a/src/Clockwork/Execution/SimulationProgressReporter.cs b/src/Clockwork/Execution/SimulationProgressReporter.cs new file mode 100644 index 0000000..683a336 --- /dev/null +++ b/src/Clockwork/Execution/SimulationProgressReporter.cs @@ -0,0 +1,115 @@ +using System.Globalization; +using Clockwork.Runtime.Execution; + +namespace Clockwork; + +internal readonly record struct SimulationProgressSnapshot( + int Iterations, + int StepsExecuted, + int TimeAdvanceCount, + int ConsecutiveTimeAdvanceCount, + DateTimeOffset StartTime, + DateTimeOffset CurrentTime); + +internal static class SimulationProgressOutput +{ + private const string AppContextKey = "Clockwork.SimulationProgressOutput"; + + public static TextWriter Writer => AppContext.GetData(AppContextKey) as TextWriter ?? Console.Error; + + public static void SetWriter(TextWriter? writer) => AppContext.SetData(AppContextKey, writer); +} + +internal sealed class SimulationProgressReporter +{ + private readonly TimeSpan _interval; + private readonly SimulationRuntimeIdentity _runtime; + private readonly TextWriter _output; + private readonly Func _getWallTime; + private readonly Func _capturePendingWork; + private readonly Func _getPendingOperationCount; + private TimeSpan _lastReportTime; + private DateTimeOffset? _simulationStartTime; + private int _completedIterations; + private int _completedSteps; + private int _completedTimeAdvances; + + internal SimulationProgressReporter( + TimeSpan interval, + SimulationRuntimeIdentity runtime, + TextWriter output, + Func getWallTime, + Func capturePendingWork, + Func getPendingOperationCount) + { + ArgumentOutOfRangeException.ThrowIfLessThanOrEqual(interval, TimeSpan.Zero); + ArgumentNullException.ThrowIfNull(runtime); + ArgumentNullException.ThrowIfNull(output); + ArgumentNullException.ThrowIfNull(getWallTime); + ArgumentNullException.ThrowIfNull(capturePendingWork); + ArgumentNullException.ThrowIfNull(getPendingOperationCount); + + _interval = interval; + _runtime = runtime; + _output = output; + _getWallTime = getWallTime; + _capturePendingWork = capturePendingWork; + _getPendingOperationCount = getPendingOperationCount; + _lastReportTime = getWallTime(); + } + + public static SimulationProgressReporter? CreateFromEnvironment( + SimulationRuntimeIdentity runtime, + Func capturePendingWork, + Func getPendingOperationCount) + { + TimeSpan? interval = SimulationProgressEnvironment.GetInterval(); + if (interval is null) + { + return null; + } + + var stopwatch = System.Diagnostics.Stopwatch.StartNew(); + return new SimulationProgressReporter( + interval.Value, + runtime, + SimulationProgressOutput.Writer, + () => stopwatch.Elapsed, + capturePendingWork, + getPendingOperationCount); + } + + public void Report(SimulationProgressSnapshot snapshot) + { + TimeSpan wallTime = _getWallTime(); + if (wallTime - _lastReportTime < _interval) + { + return; + } + + _lastReportTime = wallTime; + SimulationPendingWorkSummary pending = _capturePendingWork(); + int iterations = _completedIterations + snapshot.Iterations; + int steps = _completedSteps + snapshot.StepsExecuted; + int timeAdvances = _completedTimeAdvances + snapshot.TimeAdvanceCount; + _simulationStartTime ??= snapshot.StartTime; + TimeSpan simulatedTime = snapshot.CurrentTime - _simulationStartTime.Value; + + _output.WriteLine(string.Create( + CultureInfo.InvariantCulture, + $"[Clockwork] runtime={_runtime.Id:N} seed={_runtime.Seed} wall={wallTime:c} " + + $"iterations={iterations} steps={steps} timeAdvances={timeAdvances} " + + $"consecutiveTimeAdvances={snapshot.ConsecutiveTimeAdvanceCount} simulated={simulatedTime:c} " + + $"operations={_getPendingOperationCount()} runnable={pending.RunnableCount} " + + $"waiting={pending.WaitingCount} blocked={pending.BlockedCount}")); + } + + public void CompleteBatch(SimulationExecutionResult result) + { + ArgumentNullException.ThrowIfNull(result); + _simulationStartTime ??= result.StartTime; + _completedIterations += result.Iterations; + _completedSteps += result.StepsExecuted; + _completedTimeAdvances += result.TimeAdvanceCount; + } +} diff --git a/tests/Clockwork.Testing.Tests/Clockwork.Testing.Tests.csproj b/tests/Clockwork.Testing.Tests/Clockwork.Testing.Tests.csproj index 623e8a2..bfa7f81 100644 --- a/tests/Clockwork.Testing.Tests/Clockwork.Testing.Tests.csproj +++ b/tests/Clockwork.Testing.Tests/Clockwork.Testing.Tests.csproj @@ -16,4 +16,6 @@ + + diff --git a/tests/Clockwork.Testing.Tests/ClockworkProgressCommandLineOptionsProviderTests.cs b/tests/Clockwork.Testing.Tests/ClockworkProgressCommandLineOptionsProviderTests.cs new file mode 100644 index 0000000..2594b9e --- /dev/null +++ b/tests/Clockwork.Testing.Tests/ClockworkProgressCommandLineOptionsProviderTests.cs @@ -0,0 +1,111 @@ +using System.Diagnostics.CodeAnalysis; +using Clockwork.Testing; +using Microsoft.Testing.Platform.CommandLine; +using Microsoft.Testing.Platform.Extensions; +using Microsoft.Testing.Platform.Extensions.CommandLine; +using Microsoft.Testing.Platform.Extensions.TestHostControllers; + +namespace Clockwork.Testing.Tests; + +[Collection("Clockwork progress environment")] +public sealed class ClockworkProgressCommandLineOptionsProviderTests +{ + [Fact] + public void ExposesClockworkProgressOption() + { + var provider = new ClockworkProgressCommandLineOptionsProvider(); + + CommandLineOption option = Assert.Single(provider.GetCommandLineOptions()); + + Assert.Equal("clockwork-progress", option.Name); + Assert.Equal(ArgumentArity.ExactlyOne, option.Arity); + Assert.False(option.IsHidden); + } + + [Theory] + [InlineData("5s", true)] + [InlineData("500ms", true)] + [InlineData("00:00:05", true)] + [InlineData("0s", false)] + [InlineData("invalid", false)] + public async Task ValidatesProgressInterval(string value, bool expectedValid) + { + var provider = new ClockworkProgressCommandLineOptionsProvider(); + CommandLineOption option = Assert.Single(provider.GetCommandLineOptions()); + + var result = await provider.ValidateOptionArgumentsAsync(option, [value]); + + Assert.Equal(expectedValid, result.IsValid); + } + + [Fact] + public async Task CommandLineIntervalOverridesEnvironmentForTheTestProcess() + { + string? previous = Environment.GetEnvironmentVariable(SimulationProgressEnvironment.Interval); + try + { + Environment.SetEnvironmentVariable(SimulationProgressEnvironment.Interval, "1s"); + var provider = new ClockworkProgressCommandLineOptionsProvider(); + var options = new StubCommandLineOptions("clockwork-progress", "5s"); + + var result = await provider.ValidateCommandLineOptionsAsync(options); + + Assert.True(result.IsValid); + Assert.Equal( + "00:00:05", + Environment.GetEnvironmentVariable(SimulationProgressEnvironment.Interval)); + } + finally + { + Environment.SetEnvironmentVariable(SimulationProgressEnvironment.Interval, previous); + } + } + + [Fact] + public async Task ForwardsCommandLineIntervalToAnOrchestratedTestHost() + { + var provider = new ClockworkProgressEnvironmentVariableProvider( + new StubCommandLineOptions("clockwork-progress", "5s")); + var environment = new StubEnvironmentVariables(provider); + + await provider.UpdateAsync(environment); + ValidationResult result = await provider.ValidateTestHostEnvironmentVariablesAsync(environment); + + Assert.True(await provider.IsEnabledAsync()); + Assert.True(result.IsValid); + Assert.Equal("5s", environment.Value); + } + + private sealed class StubCommandLineOptions(string name, string value) : ICommandLineOptions + { + public bool IsOptionSet(string optionName) => optionName == name; + + public bool TryGetOptionArgumentList(string optionName, [NotNullWhen(true)] out string[]? arguments) + { + arguments = optionName == name ? [value] : null; + return arguments is not null; + } + } + + private sealed class StubEnvironmentVariables(IExtension owner) : IEnvironmentVariables + { + public string? Value { get; private set; } + + public void SetVariable(EnvironmentVariable environmentVariable) => Value = environmentVariable.Value; + + public void RemoveVariable(string variable) => Value = null; + + public bool TryGetVariable( + string variable, + [NotNullWhen(true)] out OwnedEnvironmentVariable? environmentVariable) + { + environmentVariable = Value is null + ? null + : new OwnedEnvironmentVariable(owner, variable, Value, isSecret: false, isLocked: true); + return environmentVariable is not null; + } + } +} + +[CollectionDefinition("Clockwork progress environment", DisableParallelization = true)] +public sealed class ClockworkProgressEnvironmentGroup; diff --git a/tests/Clockwork.Tests/Clockwork.Tests.csproj b/tests/Clockwork.Tests/Clockwork.Tests.csproj index 7bf52c4..b90a5b1 100644 --- a/tests/Clockwork.Tests/Clockwork.Tests.csproj +++ b/tests/Clockwork.Tests/Clockwork.Tests.csproj @@ -15,5 +15,8 @@ + + + diff --git a/tests/Clockwork.Tests/SimulationProgressReporterTests.cs b/tests/Clockwork.Tests/SimulationProgressReporterTests.cs new file mode 100644 index 0000000..480e1ec --- /dev/null +++ b/tests/Clockwork.Tests/SimulationProgressReporterTests.cs @@ -0,0 +1,140 @@ +using Clockwork.Runtime.Execution; + +namespace Clockwork.Tests; + +public sealed class SimulationProgressReporterTests +{ + [Theory] + [InlineData("500ms", 500)] + [InlineData("5s", 5_000)] + [InlineData("2m", 120_000)] + [InlineData("1h", 3_600_000)] + [InlineData("00:00:05", 5_000)] + public void ParsesSupportedProgressIntervals(string value, double expectedMilliseconds) + { + Assert.True(SimulationProgressEnvironment.TryParseInterval(value, out TimeSpan interval)); + Assert.Equal(expectedMilliseconds, interval.TotalMilliseconds); + } + + [Theory] + [InlineData("")] + [InlineData("0s")] + [InlineData("-1s")] + [InlineData("5")] + [InlineData("soon")] + public void RejectsInvalidProgressIntervals(string value) => + Assert.False(SimulationProgressEnvironment.TryParseInterval(value, out _)); + + [Fact] + public void ReportsExactLiveCountersAfterTheConfiguredWallClockInterval() + { + TimeSpan wallTime = TimeSpan.Zero; + var output = new StringWriter(); + var runtime = new SimulationRuntimeIdentity( + Guid.Parse("00112233-4455-6677-8899-aabbccddeeff"), + Seed: 17, + Description: "test"); + var reporter = new SimulationProgressReporter( + TimeSpan.FromSeconds(5), + runtime, + output, + () => wallTime, + () => new SimulationPendingWorkSummary(1, 2, 3, []), + () => 4); + var snapshot = new SimulationProgressSnapshot( + Iterations: 9, + StepsExecuted: 7, + TimeAdvanceCount: 2, + ConsecutiveTimeAdvanceCount: 1, + StartTime: DateTimeOffset.UnixEpoch, + CurrentTime: DateTimeOffset.UnixEpoch + TimeSpan.FromMinutes(10)); + + wallTime = TimeSpan.FromSeconds(4); + reporter.Report(snapshot); + Assert.Equal(string.Empty, output.ToString()); + + wallTime = TimeSpan.FromSeconds(5); + reporter.Report(snapshot); + + string line = output.ToString(); + Assert.Contains("[Clockwork] runtime=00112233445566778899aabbccddeeff seed=17", line, StringComparison.Ordinal); + Assert.Contains("wall=00:00:05", line, StringComparison.Ordinal); + Assert.Contains("iterations=9 steps=7 timeAdvances=2 consecutiveTimeAdvances=1", line, StringComparison.Ordinal); + Assert.Contains("simulated=00:10:00", line, StringComparison.Ordinal); + Assert.Contains("operations=4 runnable=1 waiting=2 blocked=3", line, StringComparison.Ordinal); + } + + [Fact] + public void CarriesCountersAndSimulatedTimeAcrossAdaptiveBatches() + { + TimeSpan wallTime = TimeSpan.Zero; + var output = new StringWriter(); + var reporter = new SimulationProgressReporter( + TimeSpan.FromSeconds(5), + new SimulationRuntimeIdentity(Guid.Empty, Seed: 1), + output, + () => wallTime, + () => SimulationPendingWorkSummary.Empty, + () => 0); + reporter.CompleteBatch(new SimulationExecutionResult( + SimulationExecutionReason.MaxIterationsReached, + DateTimeOffset.UnixEpoch, + DateTimeOffset.UnixEpoch + TimeSpan.FromMinutes(1), + iterations: 10, + stepsExecuted: 8, + timeAdvanceCount: 2, + consecutiveTimeAdvanceCount: 0, + SimulationPendingWorkSummary.Empty, + new SimulationExecutionLimits(10, TimeSpan.FromMinutes(10), 10_000), + attemptedTimeAdvance: null)); + + wallTime = TimeSpan.FromSeconds(5); + reporter.Report(new SimulationProgressSnapshot( + Iterations: 3, + StepsExecuted: 2, + TimeAdvanceCount: 1, + ConsecutiveTimeAdvanceCount: 1, + StartTime: DateTimeOffset.UnixEpoch + TimeSpan.FromMinutes(1), + CurrentTime: DateTimeOffset.UnixEpoch + TimeSpan.FromMinutes(2))); + + string line = output.ToString(); + Assert.Contains("iterations=13 steps=10 timeAdvances=3", line, StringComparison.Ordinal); + Assert.Contains("simulated=00:02:00", line, StringComparison.Ordinal); + } + + [Fact] + public void DriveLoopPublishesProgressAfterACompletedIteration() + { + var ran = false; + var snapshots = new List(); + var loop = new SimulationDriveLoop( + () => DateTimeOffset.UnixEpoch, + _ => + { + ran = true; + return true; + }, + () => null, + _ => { }, + () => SimulationPendingWorkSummary.Empty, + () => false, + CancellationToken.None); + + SimulationExecutionResult result = loop.Execute(new SimulationDriveLoopOptions( + Condition: () => ran, + MaxSimulatedTimeAdvance: TimeSpan.FromMinutes(1), + MaxIterations: 10, + MaxConsecutiveTimeAdvances: 10, + ObserveTeardownCancellation: false, + InitialConsecutiveTimeAdvances: 0, + EndTime: null, + CancellationToken: TestContext.Current.CancellationToken, + Progress: snapshots.Add)); + + SimulationProgressSnapshot snapshot = Assert.Single(snapshots); + Assert.Equal(1, snapshot.Iterations); + Assert.Equal(1, snapshot.StepsExecuted); + Assert.Equal(0, snapshot.TimeAdvanceCount); + Assert.Equal(SimulationExecutionReason.ConditionMet, result.Reason); + } +}