diff --git a/src/ModularPipelines/Context/Command.cs b/src/ModularPipelines/Context/Command.cs index ca9e0f0b18..3c8b9ca02e 100644 --- a/src/ModularPipelines/Context/Command.cs +++ b/src/ModularPipelines/Context/Command.cs @@ -119,6 +119,7 @@ private async Task Of( var standardError = string.Empty; var inputToLog = GetInputToLog(command, execOpts); + var loggingFailures = new DeferredCommandLoggingFailures(); // Only create timeout token if ExecutionTimeout is specified to avoid unnecessary allocations using var timeoutCancellationToken = CreateTimeoutCancellationToken(execOpts); @@ -133,6 +134,12 @@ private async Task Of( var registration = linkedCancellationToken.Token.Register( () => ScheduleForcefulCancellation(forcefulCancellationToken, execOpts.GracefulShutdownTimeout)); + loggingFailures.Capture( + () => _commandLogger.LogCommandStart( + options, + execOpts, + inputToLog, + command.WorkingDirPath)); await using (registration.ConfigureAwait(false)) { CliWrap.CommandResult result; @@ -177,8 +184,7 @@ await WaitForForcefulCancellationAsync( standardOutput = standardOutputBuffer.ToString(); standardError = standardErrorBuffer.ToString(); - var failure = CombineWithCompletionFailure( - e, + loggingFailures.Capture( () => LogCommandCompletion( options, execOpts, @@ -191,6 +197,7 @@ await WaitForForcefulCancellationAsync( completeStandardErrorBuffer, deferredOutputLogger, command.WorkingDirPath)); + var failure = loggingFailures.CombineWith(e); throw new CommandException( CreateFailureResult( @@ -213,8 +220,7 @@ await WaitForForcefulCancellationAsync( standardOutput = standardOutputBuffer.ToString(); standardError = standardErrorBuffer.ToString(); - var failure = CombineWithCompletionFailure( - e, + loggingFailures.Capture( () => LogCommandCompletion( options, execOpts, @@ -227,6 +233,7 @@ await WaitForForcefulCancellationAsync( completeStandardErrorBuffer, deferredOutputLogger, command.WorkingDirPath)); + var failure = loggingFailures.CombineWith(e); if (ShouldPreserveCallerCancellation(e, failure, cancellationToken)) { @@ -254,9 +261,8 @@ await WaitForForcefulCancellationAsync( standardOutput, standardError); - try - { - LogCommandCompletion( + loggingFailures.Capture( + () => LogCommandCompletion( options, execOpts, inputToLog, @@ -267,13 +273,12 @@ await WaitForForcefulCancellationAsync( completeStandardOutputBuffer, completeStandardErrorBuffer, deferredOutputLogger, - command.WorkingDirPath); - } - catch (Exception completionFailure) when (commandFailure is not null) + command.WorkingDirPath)); + if (commandFailure is not null && loggingFailures.HasFailures) { throw new CommandException( commandFailure.Result, - new AggregateException(commandFailure, completionFailure)); + loggingFailures.CombineWith(commandFailure)); } if (commandFailure is not null) @@ -281,25 +286,11 @@ await WaitForForcefulCancellationAsync( throw commandFailure; } + loggingFailures.Throw(); return new CommandResult(command, result, standardOutput, standardError); } } - private static Exception CombineWithCompletionFailure( - Exception executionFailure, - Action complete) - { - try - { - complete(); - return executionFailure; - } - catch (Exception completionFailure) - { - return new AggregateException(executionFailure, completionFailure); - } - } - private static bool ShouldPreserveCallerCancellation( Exception executionFailure, Exception combinedFailure, @@ -945,7 +936,7 @@ private void LogCommandCompletion( { var deferredOutput = deferredOutputLogger?.Complete(); var hasStreamedOutput = deferredOutput?.HasStreamedOutput == true; - _commandLogger.Log( + _commandLogger.LogCommandCompletion( options, executionOptions, input, diff --git a/src/ModularPipelines/Context/LoggingCommandLineExecutor.cs b/src/ModularPipelines/Context/LoggingCommandLineExecutor.cs index 93a6390214..12ad4019b4 100644 --- a/src/ModularPipelines/Context/LoggingCommandLineExecutor.cs +++ b/src/ModularPipelines/Context/LoggingCommandLineExecutor.cs @@ -1,3 +1,4 @@ +using System.Diagnostics; using ModularPipelines.Context.Domains.Shell; using ModularPipelines.Logging; using ModularPipelines.Models; @@ -26,7 +27,7 @@ internal sealed class LoggingCommandLineExecutor : ICommandLineExecutor private readonly ICommandLogger _commandLogger; /// - /// Initializes a new instance of the class. + /// Initialises a new instance of the class. /// /// The inner executor to wrap. /// The command logger for consistent logging. @@ -46,20 +47,50 @@ public async Task ExecuteAsync( { var workingDirectory = options?.WorkingDirectory ?? Environment.CurrentDirectory; var inputToLog = GetInputToLog(commandLine, options); + var stopwatch = Stopwatch.StartNew(); + var loggingFailures = new DeferredCommandLoggingFailures(); + loggingFailures.Capture( + () => _commandLogger.LogCommandStart( + options: null, + execOpts: options, + inputToLog: inputToLog, + commandWorkingDirPath: workingDirectory)); - var result = await _inner.ExecuteAsync(commandLine, options, cancellationToken).ConfigureAwait(false); + CommandResult result; + try + { + result = await _inner.ExecuteAsync(commandLine, options, cancellationToken).ConfigureAwait(false); + } + catch (Exception executionFailure) + { + loggingFailures.Capture( + () => LogCompletion( + options, + inputToLog, + workingDirectory, + exitCode: -1, + runTime: stopwatch.Elapsed, + standardOutput: string.Empty, + standardError: executionFailure.Message)); - // Delegate to CommandLogger for consistent logging across all command execution paths - _commandLogger.Log( - options: null, // Raw command line execution doesn't use CommandLineToolOptions - execOpts: options, - inputToLog: inputToLog, - exitCode: result.ExitCode, - runTime: result.Duration, - standardOutput: result.StandardOutput, - standardError: result.StandardError, - commandWorkingDirPath: workingDirectory); + if (!loggingFailures.HasFailures) + { + throw; + } + throw loggingFailures.CombineWith(executionFailure); + } + + loggingFailures.Capture( + () => LogCompletion( + options, + inputToLog, + workingDirectory, + result.ExitCode, + result.Duration, + result.StandardOutput, + result.StandardError)); + loggingFailures.Throw(); return result; } @@ -70,4 +101,24 @@ private static string GetInputToLog(CommandLine commandLine, CommandExecutionOpt ? options.InputLoggingManipulator(input) : input; } + + private void LogCompletion( + CommandExecutionOptions? options, + string inputToLog, + string workingDirectory, + int exitCode, + TimeSpan runTime, + string standardOutput, + string standardError) + { + _commandLogger.LogCommandCompletion( + options: null, + execOpts: options, + inputToLog: inputToLog, + exitCode: exitCode, + runTime: runTime, + standardOutput: standardOutput, + standardError: standardError, + commandWorkingDirPath: workingDirectory); + } } diff --git a/src/ModularPipelines/Logging/CommandLogger.cs b/src/ModularPipelines/Logging/CommandLogger.cs index 86d145eb44..b3fe689abb 100644 --- a/src/ModularPipelines/Logging/CommandLogger.cs +++ b/src/ModularPipelines/Logging/CommandLogger.cs @@ -27,20 +27,13 @@ public CommandLogger(IModuleLoggerProvider moduleLoggerProvider, private ILogger Logger => _moduleLoggerProvider.GetLogger(); - public void Log( + public void LogCommandStart( CommandLineToolOptions? options, CommandExecutionOptions? execOpts, string? inputToLog, - int? exitCode, - TimeSpan? runTime, - string standardOutput, - string standardError, string commandWorkingDirPath) { - // Determine effective logging options var effectiveOptions = GetEffectiveLoggingOptions(options, execOpts); - - // Silent = no logging at all if (effectiveOptions.Verbosity == CommandLogVerbosity.Silent) { return; @@ -52,8 +45,63 @@ public void Log( return; } - // Use compact logging format for cleaner output - LogCompact(effectiveOptions, execOpts, commandWorkingDirPath, inputToLog, exitCode, runTime, standardOutput, standardError); + var obfuscatedInput = ShouldShowInput(effectiveOptions) + ? _secretObfuscator.Obfuscate(inputToLog, null) + : LoggingConstants.CommandMask; + Logger.LogInformation( + "{WorkingDirectory}> {Input}", + commandWorkingDirPath, + obfuscatedInput); + } + + public void LogCommandCompletion( + CommandLineToolOptions? options, + CommandExecutionOptions? execOpts, + string? inputToLog, + int? exitCode, + TimeSpan? runTime, + string standardOutput, + string standardError, + string commandWorkingDirPath) + { + var effectiveOptions = GetEffectiveLoggingOptions(options, execOpts); + if (effectiveOptions.Verbosity == CommandLogVerbosity.Silent + || execOpts?.InternalDryRun == true) + { + return; + } + + var (outputToLog, errorToLog) = ManipulateOutput( + execOpts?.OutputLoggingManipulator, + standardOutput, + standardError); + var isSuccess = exitCode == 0; + + LogCapturedOutput(effectiveOptions, outputToLog.Trim(), isSuccess); + LogCapturedError(effectiveOptions, errorToLog, exitCode); + LogCommandStatus(effectiveOptions, inputToLog, isSuccess, exitCode, runTime); + } + + public void Log( + CommandLineToolOptions? options, + CommandExecutionOptions? execOpts, + string? inputToLog, + int? exitCode, + TimeSpan? runTime, + string standardOutput, + string standardError, + string commandWorkingDirPath) + { + LogCommandStart(options, execOpts, inputToLog, commandWorkingDirPath); + LogCommandCompletion( + options, + execOpts, + inputToLog, + exitCode, + runTime, + standardOutput, + standardError, + commandWorkingDirPath); } void ICommandOutputLogger.LogStandardOutputLine( @@ -117,51 +165,6 @@ private void LogOutputLine( obfuscatedOutput); } - private void LogCompact( - CommandLoggingOptions options, - CommandExecutionOptions? execOpts, - string workingDirectory, - string? input, - int? exitCode, - TimeSpan? runTime, - string standardOutput, - string standardError) - { - var isSuccess = exitCode == 0; - var obfuscatedInput = ShouldShowInput(options) - ? _secretObfuscator.Obfuscate(input, null) - : LoggingConstants.CommandMask; - - var commandMessage = new StringBuilder(); - commandMessage.Append(workingDirectory); - commandMessage.Append("> "); - commandMessage.Append(obfuscatedInput); - - var standardOutputToLog = execOpts?.OutputLoggingManipulator is not null - ? execOpts.OutputLoggingManipulator(standardOutput) - : standardOutput; - var standardErrorToLog = execOpts?.OutputLoggingManipulator is not null - ? execOpts.OutputLoggingManipulator(standardError) - : standardError; - - var trimmedOutput = standardOutputToLog.Trim(); - var hasShortOutput = ShouldInlineOutput(options, trimmedOutput); - var hasInlineOutput = hasShortOutput && isSuccess; - var inlineOutput = hasInlineOutput - ? $" → {_secretObfuscator.Obfuscate(trimmedOutput, null)}" - : string.Empty; - var commandStatus = BuildCommandStatus(options, isSuccess, exitCode, runTime); - - Logger.LogInformation( - "{CommandMessage}{CommandOutput}{CommandStatus}", - commandMessage.ToString(), - inlineOutput, - commandStatus); - - LogCapturedOutput(options, trimmedOutput, hasInlineOutput); - LogCapturedError(options, standardErrorToLog, exitCode); - } - private static bool ShouldInlineOutput(CommandLoggingOptions options, string output) { return !string.IsNullOrEmpty(output) @@ -171,6 +174,19 @@ private static bool ShouldInlineOutput(CommandLoggingOptions options, string out && options.ShowStandardOutput; } + private static (string Output, string Error) ManipulateOutput( + Func? manipulator, + string standardOutput, + string standardError) + { + if (manipulator is null) + { + return (standardOutput, standardError); + } + + return (manipulator(standardOutput), manipulator(standardError)); + } + private static string BuildCommandStatus( CommandLoggingOptions options, bool isSuccess, @@ -208,10 +224,17 @@ private static string BuildCommandStatus( private void LogCapturedOutput( CommandLoggingOptions options, string output, - bool wasInlined) + bool isSuccess) { - if (wasInlined - || string.IsNullOrWhiteSpace(output) + if (isSuccess && ShouldInlineOutput(options, output)) + { + Logger.LogInformation( + " → {CommandOutput}", + _secretObfuscator.Obfuscate(output, null)); + return; + } + + if (string.IsNullOrWhiteSpace(output) || options.Verbosity < CommandLogVerbosity.Normal || !options.ShowStandardOutput) { @@ -237,6 +260,32 @@ private void LogCapturedError( Logger.LogWarning(" ✗ {CommandError}", _secretObfuscator.Obfuscate(error, null)); } + private void LogCommandStatus( + CommandLoggingOptions options, + string? inputToLog, + bool isSuccess, + int? exitCode, + TimeSpan? runTime) + { + var commandStatus = BuildCommandStatus(options, isSuccess, exitCode, runTime); + if (string.IsNullOrEmpty(commandStatus) + && options.Verbosity >= CommandLogVerbosity.Normal) + { + commandStatus = isSuccess ? "✓" : "✗"; + } + + if (!string.IsNullOrEmpty(commandStatus)) + { + var obfuscatedInput = ShouldShowInput(options) + ? _secretObfuscator.Obfuscate(inputToLog, null) + : LoggingConstants.CommandMask; + Logger.LogInformation( + "{CommandStatus} {Input}", + commandStatus.TrimStart(), + obfuscatedInput); + } + } + private static bool ShouldShowInput(CommandLoggingOptions options) { // ShowCommandArguments controls whether to show full command or obfuscated diff --git a/src/ModularPipelines/Logging/DeferredCommandLoggingFailures.cs b/src/ModularPipelines/Logging/DeferredCommandLoggingFailures.cs new file mode 100644 index 0000000000..9154f0eaa3 --- /dev/null +++ b/src/ModularPipelines/Logging/DeferredCommandLoggingFailures.cs @@ -0,0 +1,40 @@ +using System.Runtime.ExceptionServices; + +namespace ModularPipelines.Logging; + +internal sealed class DeferredCommandLoggingFailures +{ + private readonly List _failures = []; + + public bool HasFailures => _failures.Count > 0; + + public void Capture(Action log) + { + try + { + log(); + } + catch (Exception exception) + { + _failures.Add(exception); + } + } + + public Exception CombineWith(Exception primaryFailure) => + _failures.Count == 0 + ? primaryFailure + : new AggregateException([primaryFailure, .. _failures]); + + public void Throw() + { + if (_failures.Count == 1) + { + ExceptionDispatchInfo.Capture(_failures[0]).Throw(); + } + + if (_failures.Count > 1) + { + throw new AggregateException(_failures); + } + } +} diff --git a/src/ModularPipelines/Logging/ICommandLogger.cs b/src/ModularPipelines/Logging/ICommandLogger.cs index 2278de30bb..c7f20c22ba 100644 --- a/src/ModularPipelines/Logging/ICommandLogger.cs +++ b/src/ModularPipelines/Logging/ICommandLogger.cs @@ -18,7 +18,54 @@ namespace ModularPipelines.Logging; public interface ICommandLogger { /// - /// Logs the details of a command execution. + /// Logs a command immediately before execution starts. + /// + /// The command line tool options used for execution. Can be null for raw command line execution. + /// The command execution options containing logging settings. + /// The input command to log. + /// The working directory where the command will execute. + void LogCommandStart( + CommandLineToolOptions? options, + CommandExecutionOptions? execOpts, + string? inputToLog, + string commandWorkingDirPath) + { + } + + /// + /// Logs command output and status after execution finishes. + /// + /// The command line tool options used for execution. Can be null for raw command line execution. + /// The command execution options containing logging settings. + /// The input command to log. + /// The exit code returned by the command. + /// The time taken to execute the command. + /// The standard output from the command. + /// The standard error from the command. + /// The working directory where the command executed. + void LogCommandCompletion( + CommandLineToolOptions? options, + CommandExecutionOptions? execOpts, + string? inputToLog, + int? exitCode, + TimeSpan? runTime, + string standardOutput, + string standardError, + string commandWorkingDirPath) + { + Log( + options, + execOpts, + inputToLog, + exitCode, + runTime, + standardOutput, + standardError, + commandWorkingDirPath); + } + + /// + /// Logs the details of a completed command execution. /// /// The command line tool options used for execution. Can be null for raw command line execution. /// The command execution options containing logging settings. Logging behavior is controlled via . diff --git a/test/ModularPipelines.UnitTests/Commands/CommandLoggerTests.cs b/test/ModularPipelines.UnitTests/Commands/CommandLoggerTests.cs index fbecb89513..dc2a68402c 100644 --- a/test/ModularPipelines.UnitTests/Commands/CommandLoggerTests.cs +++ b/test/ModularPipelines.UnitTests/Commands/CommandLoggerTests.cs @@ -338,6 +338,54 @@ await result.T.ExecuteCommandLineToolAsync( return file; } + [Test] + public async Task Command_Header_Precedes_Streamed_Output_And_Completion() + { + var marker = $"ordered-output-{Guid.NewGuid():N}"; + var file = await RunPowershellCommandWithLoggingOptions( + $"Write-Output '{marker}'; Start-Sleep -Milliseconds 750", + new CommandLoggingOptions { Verbosity = CommandLogVerbosity.Detailed }); + + var logFile = await File.ReadAllTextAsync(file); + var headerIndex = logFile.IndexOf( + $"{Environment.CurrentDirectory}> pwsh", + StringComparison.Ordinal); + var outputIndex = logFile.IndexOf($"↳ {marker}", StringComparison.Ordinal); + var completionIndex = logFile.LastIndexOf("✓ [", StringComparison.Ordinal); + + await Assert.That(headerIndex).IsGreaterThanOrEqualTo(0); + await Assert.That(outputIndex).IsGreaterThan(headerIndex); + await Assert.That(completionIndex).IsGreaterThan(outputIndex); + + var lines = logFile.Split(Environment.NewLine); + var headerLine = lines.Single(line => + line.Contains($"{Environment.CurrentDirectory}> pwsh", StringComparison.Ordinal)); + var completionLine = lines.Last(line => + line.Contains("✓ [", StringComparison.Ordinal)); + await Assert.That(headerLine).DoesNotContain("✓"); + await Assert.That(completionLine).Contains("pwsh"); + } + + [Test] + public async Task Failed_Command_Logs_Error_Before_Completion() + { + var marker = $"ordered-error-{Guid.NewGuid():N}"; + var file = await RunPowershellCommandWithLoggingOptions( + $"[Console]::Error.WriteLine('{marker}'); Start-Sleep -Milliseconds 750; exit 7", + new CommandLoggingOptions { Verbosity = CommandLogVerbosity.Detailed }); + + var logFile = await File.ReadAllTextAsync(file); + var headerIndex = logFile.IndexOf( + $"{Environment.CurrentDirectory}> pwsh", + StringComparison.Ordinal); + var errorIndex = logFile.IndexOf($"↳ {marker}", StringComparison.Ordinal); + var completionIndex = logFile.LastIndexOf("✗ [", StringComparison.Ordinal); + + await Assert.That(headerIndex).IsGreaterThanOrEqualTo(0); + await Assert.That(errorIndex).IsGreaterThan(headerIndex); + await Assert.That(completionIndex).IsGreaterThan(errorIndex); + } + [Test] public async Task Command_Output_Is_Logged_Before_Command_Completes() { @@ -398,6 +446,69 @@ public async Task Deferred_Logging_Failure_After_Success_Is_Not_A_Command_Failur await Assert.That(loggingProvider.ThrowCount).IsEqualTo(1); } + [Test] + public async Task HeaderLoggingFailureDoesNotPreventCommandExecution() + { + var marker = $"header-failure-{Guid.NewGuid():N}"; + var sideEffectFile = Path.Combine( + TestContext.WorkingDirectory, + Guid.NewGuid().ToString("N") + ".txt"); + using var loggingProvider = + new SelectiveThrowingLoggerProvider($"{Environment.CurrentDirectory}> {marker}"); + var (commandContext, _) = await GetService((_, collection) => + { + collection.Configure( + options => options.MinLevel = LogLevel.Information); + collection.AddLogging(builder => builder.AddProvider(loggingProvider)); + }); + + var exception = await Assert.ThrowsAsync(() => + commandContext.ExecuteCommandLineToolAsync( + new PowershellScriptOptions( + $"[System.IO.File]::WriteAllText('{sideEffectFile}', 'executed')"), + new CommandExecutionOptions + { + InputLoggingManipulator = _ => marker, + })); + + using (Assert.Multiple()) + { + await Assert.That(exception!.Flatten().InnerExceptions) + .Contains(failure => + failure is InvalidOperationException + && failure.Message == "Logging failed."); + await Assert.That(await File.ReadAllTextAsync(sideEffectFile)).IsEqualTo("executed"); + await Assert.That(loggingProvider.ThrowCount).IsEqualTo(1); + } + } + + [Test] + public async Task InvalidExecutionTimeoutDoesNotLogCommandStart() + { + var marker = $"invalid-timeout-{Guid.NewGuid():N}"; + var file = Path.Combine( + TestContext.WorkingDirectory, + Guid.NewGuid().ToString("N") + ".txt"); + var result = await GetService((_, collection) => + { + collection.Configure( + options => options.MinLevel = LogLevel.Information); + collection.AddLogging(builder => builder.AddFile(file)); + }); + + await Assert.ThrowsAsync(() => + result.T.ExecuteCommandLineToolAsync( + new PowershellScriptOptions("Write-Output 'not-executed'"), + new CommandExecutionOptions + { + ExecutionTimeout = TimeSpan.FromMilliseconds(-2), + InputLoggingManipulator = _ => marker, + })); + await result.Host.DisposeAsync(); + + await Assert.That(await File.ReadAllTextAsync(file)).DoesNotContain(marker); + } + [Test] public async Task Deferred_Logging_Failure_After_NonZero_Exit_Preserves_Command_Failure() { diff --git a/test/ModularPipelines.UnitTests/Context/LoggingCommandLineExecutorTests.cs b/test/ModularPipelines.UnitTests/Context/LoggingCommandLineExecutorTests.cs new file mode 100644 index 0000000000..4d3f3b6b1a --- /dev/null +++ b/test/ModularPipelines.UnitTests/Context/LoggingCommandLineExecutorTests.cs @@ -0,0 +1,140 @@ +using ModularPipelines.Context; +using ModularPipelines.Logging; +using ModularPipelines.Models; +using ModularPipelines.Options; + +namespace ModularPipelines.UnitTests.Context; + +public class LoggingCommandLineExecutorTests +{ + [Test] + public async Task InnerFailureStillLogsCompletion() + { + var expectedException = new InvalidOperationException("Execution failed."); + var logger = new RecordingCommandLogger(); + var executor = new LoggingCommandLineExecutor( + new StubCommandLineExecutor( + (_, _, _) => Task.FromException(expectedException)), + logger); + + var exception = await Assert.ThrowsAsync( + () => executor.ExecuteAsync(new CommandLine("tool", []))); + + using (Assert.Multiple()) + { + await Assert.That(exception).IsSameReferenceAs(expectedException); + await Assert.That(logger.Events).Count().IsEqualTo(2); + await Assert.That(logger.Events[0]).IsEqualTo("start"); + await Assert.That(logger.Events[1]).IsEqualTo("completion"); + await Assert.That(logger.CompletionExitCode).IsEqualTo(-1); + await Assert.That(logger.CompletionError).IsEqualTo(expectedException.Message); + } + } + + [Test] + public async Task StartLoggingFailureDoesNotPreventExecution() + { + var expectedException = new InvalidOperationException("Logging failed."); + var executed = false; + var logger = new RecordingCommandLogger + { + StartFailure = expectedException, + }; + var result = CreateResult(); + var executor = new LoggingCommandLineExecutor( + new StubCommandLineExecutor((_, _, _) => + { + executed = true; + return Task.FromResult(result); + }), + logger); + + var exception = await Assert.ThrowsAsync( + () => executor.ExecuteAsync(new CommandLine("tool", []))); + + using (Assert.Multiple()) + { + await Assert.That(executed).IsTrue(); + await Assert.That(exception).IsSameReferenceAs(expectedException); + await Assert.That(logger.Events).Count().IsEqualTo(2); + await Assert.That(logger.Events[1]).IsEqualTo("completion"); + } + } + + private static CommandResult CreateResult() + { + var timestamp = DateTimeOffset.UtcNow; + return new CommandResult( + "tool", + Environment.CurrentDirectory, + string.Empty, + string.Empty, + new Dictionary(), + timestamp, + timestamp, + TimeSpan.Zero, + 0); + } + + private sealed class StubCommandLineExecutor( + Func> execute) + : ICommandLineExecutor + { + public Task ExecuteAsync( + CommandLine commandLine, + CommandExecutionOptions? options = null, + CancellationToken cancellationToken = default) => + execute(commandLine, options, cancellationToken); + } + + private sealed class RecordingCommandLogger : ICommandLogger + { + public List Events { get; } = []; + + public Exception? StartFailure { get; init; } + + public int? CompletionExitCode { get; private set; } + + public string? CompletionError { get; private set; } + + public void LogCommandStart( + CommandLineToolOptions? options, + CommandExecutionOptions? execOpts, + string? inputToLog, + string commandWorkingDirPath) + { + Events.Add("start"); + if (StartFailure is not null) + { + throw StartFailure; + } + } + + public void LogCommandCompletion( + CommandLineToolOptions? options, + CommandExecutionOptions? execOpts, + string? inputToLog, + int? exitCode, + TimeSpan? runTime, + string standardOutput, + string standardError, + string commandWorkingDirPath) + { + Events.Add("completion"); + CompletionExitCode = exitCode; + CompletionError = standardError; + } + + public void Log( + CommandLineToolOptions? options, + CommandExecutionOptions? execOpts, + string? inputToLog, + int? exitCode, + TimeSpan? runTime, + string standardOutput, + string standardError, + string commandWorkingDirPath) + { + } + } +} diff --git a/test/ModularPipelines.UnitTests/Logging/SpectreConsoleLoggerTests.cs b/test/ModularPipelines.UnitTests/Logging/SpectreConsoleLoggerTests.cs index feec41f611..3ba7c84f1c 100644 --- a/test/ModularPipelines.UnitTests/Logging/SpectreConsoleLoggerTests.cs +++ b/test/ModularPipelines.UnitTests/Logging/SpectreConsoleLoggerTests.cs @@ -87,8 +87,9 @@ public async Task Logs_Inline_Output_With_Command_Output_Placeholder() string.Empty, "C:\\repo"); - await Assert.That(logger.Properties["CommandOutput"]?.ToString()).Contains("short output"); - await Assert.That(logger.Properties["CommandMessage"]?.ToString()).DoesNotContain("short output"); + var outputEntry = logger.Entries.Single(properties => properties.ContainsKey("CommandOutput")); + await Assert.That(outputEntry["CommandOutput"]?.ToString()).Contains("short output"); + await Assert.That(outputEntry.Values.Select(x => x?.ToString())).DoesNotContain("tool --version"); } [Test] @@ -154,8 +155,7 @@ private static Exception CaptureException() private sealed class CapturingModuleLogger : IModuleLogger { - public IReadOnlyDictionary Properties { get; private set; } - = new Dictionary(); + public List> Entries { get; } = []; public void Log( LogLevel logLevel, @@ -169,7 +169,7 @@ public void Log( throw new InvalidOperationException("Expected structured log state."); } - Properties = properties.ToDictionary(x => x.Key, x => x.Value); + Entries.Add(properties.ToDictionary(x => x.Key, x => x.Value)); } public bool IsEnabled(LogLevel logLevel) => true;