From 9ac8468ba60517c201bb14ccb6aac5cb641901d8 Mon Sep 17 00:00:00 2001 From: Victor Johnsson Date: Wed, 8 Apr 2026 12:52:54 +0200 Subject: [PATCH] Buffer console logs during interactive prompts Pause terminal debug logging while interactive prompts are active so prompt UI stays readable, then replay buffered lines when the prompt completes. Apply prompt scopes to all ConsoleInteractionService prompt methods and add tests covering buffering and nested scope flush behavior. --- .../Interaction/ConsoleInteractionService.cs | 12 +++ .../SpectreConsoleLoggerProvider.cs | 77 ++++++++++++++++++- .../SpectreConsoleLoggerProviderTests.cs | 48 ++++++++++++ 3 files changed, 136 insertions(+), 1 deletion(-) diff --git a/src/Aspire.Cli/Interaction/ConsoleInteractionService.cs b/src/Aspire.Cli/Interaction/ConsoleInteractionService.cs index 4e51e67cbe6..40eb05181b2 100644 --- a/src/Aspire.Cli/Interaction/ConsoleInteractionService.cs +++ b/src/Aspire.Cli/Interaction/ConsoleInteractionService.cs @@ -150,6 +150,10 @@ public async Task PromptForStringAsync(string promptText, string? defaul throw new InvalidOperationException(InteractionServiceStrings.InteractiveInputNotSupported); } + // Buffer console logs while interactive prompts are active so + // background debug output doesn't drown the prompt UI. + using var promptScope = SpectreConsoleLoggerProvider.BeginInteractivePromptScope(); + MessageLogger.LogInformation("Prompt: {PromptText} (default: {DefaultValue}, secret: {IsSecret})", promptText, isSecret ? "****" : defaultValue ?? "(none)", isSecret); var prompt = new TextPrompt(promptText) @@ -197,6 +201,10 @@ public async Task PromptForSelectionAsync(string promptText, IEnumerable> PromptForSelectionsAsync(string promptTex throw new EmptyChoicesException(string.Format(CultureInfo.CurrentCulture, InteractionServiceStrings.NoItemsAvailableForSelection, promptText)); } + // Buffer console logs while interactive prompts are active so + // background debug output doesn't drown the prompt UI. + using var promptScope = SpectreConsoleLoggerProvider.BeginInteractivePromptScope(); + var preSelectedSet = preSelected is not null ? new HashSet(preSelected) : null; var safeFormatter = MakeSafeFormatter(choiceFormatter); diff --git a/src/Aspire.Cli/Interaction/SpectreConsoleLoggerProvider.cs b/src/Aspire.Cli/Interaction/SpectreConsoleLoggerProvider.cs index 09966e95fb6..3958f090c5b 100644 --- a/src/Aspire.Cli/Interaction/SpectreConsoleLoggerProvider.cs +++ b/src/Aspire.Cli/Interaction/SpectreConsoleLoggerProvider.cs @@ -8,6 +8,11 @@ namespace Aspire.Cli.Interaction; internal class SpectreConsoleLoggerProvider : ILoggerProvider { + // Shared buffering state for console logs emitted while interactive prompts are active. + private static readonly object s_logBufferLock = new(); + private static readonly Queue<(TextWriter Writer, string Message)> s_bufferedMessages = new(); + private static int s_interactivePromptDepth; + private readonly TextWriter _output; /// @@ -19,6 +24,76 @@ public SpectreConsoleLoggerProvider(TextWriter output) _output = output; } + // Depth-based scope to support nested prompts. Logs flush when the outermost scope ends. + internal static IDisposable BeginInteractivePromptScope() + { + lock (s_logBufferLock) + { + s_interactivePromptDepth++; + } + + return new InteractivePromptScope(); + } + + internal static void WriteOrBuffer(TextWriter output, string message) + { + lock (s_logBufferLock) + { + // During an active prompt, queue log lines instead of writing immediately. + if (s_interactivePromptDepth > 0) + { + s_bufferedMessages.Enqueue((output, message)); + return; + } + } + + output.WriteLine(message); + } + + private static void EndInteractivePromptScope() + { + List<(TextWriter Writer, string Message)> messagesToFlush = []; + + lock (s_logBufferLock) + { + if (s_interactivePromptDepth > 0) + { + s_interactivePromptDepth--; + } + + if (s_interactivePromptDepth > 0) + { + return; + } + + // Drain under lock to preserve ordering across concurrent writers. + while (s_bufferedMessages.Count > 0) + { + messagesToFlush.Add(s_bufferedMessages.Dequeue()); + } + } + + // Write outside the lock to avoid holding the global lock during I/O. + foreach (var (writer, message) in messagesToFlush) + { + writer.WriteLine(message); + } + } + + private sealed class InteractivePromptScope : IDisposable + { + private int _disposed; + + public void Dispose() + { + // Ensure scope close is applied only once for idempotent disposal. + if (Interlocked.Exchange(ref _disposed, 1) == 0) + { + EndInteractivePromptScope(); + } + } + } + public ILogger CreateLogger(string categoryName) { return new SpectreConsoleLogger(_output, categoryName); @@ -61,7 +136,7 @@ public void Log(LogLevel logLevel, EventId eventId, TState state, Except var logMessage = $"[{timestamp}] [{GetLogLevelString(logLevel)}] {shortCategoryName}: {formattedMessage}"; // Write to the configured output (stderr by default) - output.WriteLine(logMessage); + SpectreConsoleLoggerProvider.WriteOrBuffer(output, logMessage); } private static string GetLogLevelString(LogLevel logLevel) => logLevel switch diff --git a/tests/Aspire.Cli.Tests/Interaction/SpectreConsoleLoggerProviderTests.cs b/tests/Aspire.Cli.Tests/Interaction/SpectreConsoleLoggerProviderTests.cs index c14f45e6616..bf1e7df4468 100644 --- a/tests/Aspire.Cli.Tests/Interaction/SpectreConsoleLoggerProviderTests.cs +++ b/tests/Aspire.Cli.Tests/Interaction/SpectreConsoleLoggerProviderTests.cs @@ -101,4 +101,52 @@ public void SpectreConsoleLogger_Log_IncludesTimestampInHHmmssFormat() // The format should be: [HH:mm:ss] [dbug] Test: Test debug message Assert.Matches(@"\[\d{2}:\d{2}:\d{2}\] \[dbug\] Test: Test debug message", outputString); } + + [Fact] + public void SpectreConsoleLogger_Log_BuffersWhileInteractivePromptScopeIsActive() + { + // Arrange + var output = new StringWriter(); + var logger = new SpectreConsoleLogger(output, "Aspire.Cli.Test"); + + // Act + using (SpectreConsoleLoggerProvider.BeginInteractivePromptScope()) + { + logger.LogInformation("buffered while prompting"); + + // Assert + Assert.DoesNotContain("buffered while prompting", output.ToString()); + } + + // Assert + Assert.Contains("[info] Test: buffered while prompting", output.ToString()); + } + + [Fact] + public void SpectreConsoleLogger_Log_FlushesOnlyAfterOuterPromptScopeEnds() + { + // Arrange + var output = new StringWriter(); + var logger = new SpectreConsoleLogger(output, "Aspire.Cli.Test"); + + // Act + using (SpectreConsoleLoggerProvider.BeginInteractivePromptScope()) + { + logger.LogInformation("first"); + + using (SpectreConsoleLoggerProvider.BeginInteractivePromptScope()) + { + logger.LogInformation("second"); + } + + Assert.DoesNotContain("first", output.ToString()); + Assert.DoesNotContain("second", output.ToString()); + } + + // Assert + var flushedOutput = output.ToString(); + Assert.Contains("[info] Test: first", flushedOutput); + Assert.Contains("[info] Test: second", flushedOutput); + Assert.True(flushedOutput.IndexOf("first", StringComparison.Ordinal) < flushedOutput.IndexOf("second", StringComparison.Ordinal)); + } }