diff --git a/libraries/src/AWS.Lambda.Powertools.Common/Core/ConsoleWrapper.cs b/libraries/src/AWS.Lambda.Powertools.Common/Core/ConsoleWrapper.cs index 869d2780..4a124d94 100644 --- a/libraries/src/AWS.Lambda.Powertools.Common/Core/ConsoleWrapper.cs +++ b/libraries/src/AWS.Lambda.Powertools.Common/Core/ConsoleWrapper.cs @@ -8,7 +8,6 @@ public class ConsoleWrapper : IConsoleWrapper { private static bool _override; private static TextWriter _testOutputStream; - private static bool _outputResetPerformed = false; private static bool _inTestMode = false; /// @@ -20,7 +19,7 @@ public void WriteLine(string message) } else { - EnsureConsoleOutputOnce(); + EnsureConsoleOutput(); Console.WriteLine(message); } } @@ -34,7 +33,7 @@ public void Debug(string message) } else { - EnsureConsoleOutputOnce(); + EnsureConsoleOutput(); System.Diagnostics.Debug.WriteLine(message); } } @@ -50,9 +49,9 @@ public void Error(string message) { if (!_override) { - var errordOutput = new StreamWriter(Console.OpenStandardError()); - errordOutput.AutoFlush = true; - Console.SetError(errordOutput); + var errorOutput = new StreamWriter(Console.OpenStandardError()); + errorOutput.AutoFlush = true; + Console.SetError(errorOutput); } Console.Error.WriteLine(message); } @@ -70,23 +69,69 @@ public static void SetOut(TextWriter consoleOut) Console.SetOut(consoleOut); } - private static void EnsureConsoleOutputOnce() + private static void EnsureConsoleOutput() { - if (_outputResetPerformed) return; - OverrideLambdaLogger(); - _outputResetPerformed = true; + // Check if we need to override console output for Lambda environment + if (ShouldOverrideConsole()) + { + OverrideLambdaLogger(); + } + } + + private static bool ShouldOverrideConsole() + { + // Don't override if we're in test mode + if (_inTestMode) return false; + + // Always override in Lambda environment to prevent Lambda's log wrapping + var isLambda = !string.IsNullOrEmpty(Environment.GetEnvironmentVariable("AWS_LAMBDA_FUNCTION_NAME")); + + return isLambda && (!_override || HasLambdaReInterceptedConsole()); + } + + internal static bool HasLambdaReInterceptedConsole() + { + return HasLambdaReInterceptedConsole(() => Console.Out); } - private static void OverrideLambdaLogger() + internal static bool HasLambdaReInterceptedConsole(Func consoleOutAccessor) { - if (_override) + // Lambda might re-intercept console between init and handler execution + try + { + var currentOut = consoleOutAccessor(); + // Check if current output stream looks like it might be Lambda's wrapper + var typeName = currentOut.GetType().FullName ?? ""; + return typeName.Contains("Lambda") || typeName == "System.IO.TextWriter+SyncTextWriter"; + } + catch + { + return true; // Assume re-interception if we can't determine + } + } + + internal static void OverrideLambdaLogger() + { + OverrideLambdaLogger(() => Console.OpenStandardOutput()); + } + + internal static void OverrideLambdaLogger(Func standardOutputOpener) + { + try + { + // Force override of LambdaLogger + var standardOutput = new StreamWriter(standardOutputOpener()) + { + AutoFlush = true + }; + Console.SetOut(standardOutput); + _override = true; + } + catch (Exception) { - return; + // Log the failure but don't throw - degraded functionality is better than crash + _override = false; } - // Force override of LambdaLogger - var standardOutput = new StreamWriter(Console.OpenStandardOutput()); - standardOutput.AutoFlush = true; - Console.SetOut(standardOutput); } internal static void WriteLine(string logLevel, string message) @@ -102,7 +147,6 @@ public static void ResetForTest() _override = false; _inTestMode = false; _testOutputStream = null; - _outputResetPerformed = false; } /// @@ -110,6 +154,7 @@ public static void ResetForTest() /// public static void ClearOutputResetFlag() { - _outputResetPerformed = false; + // This method is kept for backward compatibility but no longer needed + // since we removed the _outputResetPerformed flag } } \ No newline at end of file diff --git a/libraries/tests/AWS.Lambda.Powertools.Common.Tests/ConsoleWrapperTests.cs b/libraries/tests/AWS.Lambda.Powertools.Common.Tests/ConsoleWrapperTests.cs index 1fa0f7b5..25cea21d 100644 --- a/libraries/tests/AWS.Lambda.Powertools.Common.Tests/ConsoleWrapperTests.cs +++ b/libraries/tests/AWS.Lambda.Powertools.Common.Tests/ConsoleWrapperTests.cs @@ -1,119 +1,248 @@ using System; using System.IO; +using NSubstitute; using Xunit; namespace AWS.Lambda.Powertools.Common.Tests; public class ConsoleWrapperTests : IDisposable { - private StringWriter _writer; + private readonly TextWriter _originalOut; + private readonly TextWriter _originalError; + private readonly StringWriter _testWriter; public ConsoleWrapperTests() { - // Setup a new StringWriter for each test - _writer = new StringWriter(); - // Reset static state for clean testing + // Store original console outputs + _originalOut = Console.Out; + _originalError = Console.Error; + + // Setup test writer + _testWriter = new StringWriter(); + + // Reset ConsoleWrapper state before each test ConsoleWrapper.ResetForTest(); + + // Clear any Lambda environment variables + Environment.SetEnvironmentVariable("AWS_LAMBDA_FUNCTION_NAME", null); + } + + public void Dispose() + { + // Restore original console outputs + Console.SetOut(_originalOut); + Console.SetError(_originalError); + + // Reset ConsoleWrapper state after each test + ConsoleWrapper.ResetForTest(); + + // Clear any test environment variables + Environment.SetEnvironmentVariable("AWS_LAMBDA_FUNCTION_NAME", null); + + _testWriter?.Dispose(); } [Fact] - public void WriteLine_Should_Write_To_Console() + public void WriteLine_GivenInTestMode_WhenCalled_ThenWritesToTestOutputStream() { - // Arrange - var consoleWrapper = new ConsoleWrapper(); - ConsoleWrapper.SetOut(_writer); + // Given + ConsoleWrapper.SetOut(_testWriter); + var wrapper = new ConsoleWrapper(); + const string message = "test message"; + + // When + wrapper.WriteLine(message); - // Act - consoleWrapper.WriteLine("test message"); + // Then + Assert.Equal($"{message}{Environment.NewLine}", _testWriter.ToString()); + } - // Assert - Assert.Equal($"test message{Environment.NewLine}", _writer.ToString()); + [Fact] + public void WriteLine_GivenNotInLambdaEnvironment_WhenCalled_ThenWritesToConsoleDirectly() + { + // Given + var wrapper = new ConsoleWrapper(); + var consoleOutput = new StringWriter(); + Console.SetOut(consoleOutput); + const string message = "test message"; + + // When + wrapper.WriteLine(message); + + // Then + Assert.Equal($"{message}{Environment.NewLine}", consoleOutput.ToString()); + consoleOutput.Dispose(); } [Fact] - public void Error_Should_Write_To_Error_Console() + public void WriteLine_GivenInLambdaEnvironment_WhenCalled_ThenOverridesConsoleOutput() { - // Arrange - var consoleWrapper = new ConsoleWrapper(); - ConsoleWrapper.SetOut(_writer); - Console.SetError(_writer); + // Given + Environment.SetEnvironmentVariable("AWS_LAMBDA_FUNCTION_NAME", "test-function"); + var wrapper = new ConsoleWrapper(); + const string message = "test message"; + + // When + wrapper.WriteLine(message); + + // Then + // Should not throw and should have attempted to override console + Assert.NotNull(Console.Out); + } + + [Fact] + public void WriteLine_GivenMultipleCallsInLambda_WhenConsoleIsReIntercepted_ThenReOverridesConsole() + { + // Given + Environment.SetEnvironmentVariable("AWS_LAMBDA_FUNCTION_NAME", "test-function"); + var wrapper = new ConsoleWrapper(); + + // When - First call should override console + wrapper.WriteLine("First message"); + + // Simulate Lambda re-intercepting console by setting it to a wrapped writer + var lambdaInterceptedWriter = new StringWriter(); + Console.SetOut(lambdaInterceptedWriter); + + // Second call should detect and re-override + wrapper.WriteLine("Second message"); + + // Then + // Should not throw and console should be overridden again + Assert.NotNull(Console.Out); + lambdaInterceptedWriter.Dispose(); + } + + [Fact] + public void WriteLine_GivenLambdaEnvironmentWithConsoleOverrideFailing_WhenCalled_ThenDoesNotThrow() + { + // Given + Environment.SetEnvironmentVariable("AWS_LAMBDA_FUNCTION_NAME", "test-function"); + var wrapper = new ConsoleWrapper(); + + // When & Then - Should not throw even if console override fails + var exception = Record.Exception(() => wrapper.WriteLine("Test message")); + Assert.Null(exception); + } + + [Fact] + public void Debug_GivenInTestMode_WhenCalled_ThenWritesToTestOutputStream() + { + // Given + ConsoleWrapper.SetOut(_testWriter); + var wrapper = new ConsoleWrapper(); + const string message = "debug message"; + + // When + wrapper.Debug(message); + + // Then + Assert.Equal($"{message}{Environment.NewLine}", _testWriter.ToString()); + } - // Act - consoleWrapper.Error("error message"); - _writer.Flush(); + [Fact] + public void Debug_GivenNotInTestMode_WhenCalled_ThenDoesNotThrow() + { + // Given + var wrapper = new ConsoleWrapper(); + ConsoleWrapper.ResetForTest(); // Ensure we're not in test mode - // Assert - Assert.Equal($"error message{Environment.NewLine}", _writer.ToString()); + // When & Then - Just verify it doesn't throw + var exception = Record.Exception(() => wrapper.Debug("debug message")); + Assert.Null(exception); } [Fact] - public void SetOut_Should_Override_Console_Output() + public void Error_GivenInTestMode_WhenCalled_ThenWritesToTestOutputStream() { - // Arrange - var consoleWrapper = new ConsoleWrapper(); - ConsoleWrapper.SetOut(_writer); + // Given + ConsoleWrapper.SetOut(_testWriter); + var wrapper = new ConsoleWrapper(); + const string message = "error message"; - // Act - consoleWrapper.WriteLine("test message"); + // When + wrapper.Error(message); - // Assert - Assert.Equal($"test message{Environment.NewLine}", _writer.ToString()); + // Then + Assert.Equal($"{message}{Environment.NewLine}", _testWriter.ToString()); } [Fact] - public void OverrideLambdaLogger_Should_Override_Console_Out() + public void Error_GivenNotInTestMode_WhenCalled_ThenDoesNotThrow() { - // Arrange - var consoleWrapper = new ConsoleWrapper(); - ConsoleWrapper.SetOut(_writer); + // Given + var wrapper = new ConsoleWrapper(); + ConsoleWrapper.ResetForTest(); // Ensure we're not in test mode - // Act - consoleWrapper.WriteLine("test message"); + // When & Then - The Error method creates its own StreamWriter, + // so we just verify it doesn't throw + var exception = Record.Exception(() => wrapper.Error("error message")); + Assert.Null(exception); + } - // Assert - Assert.Equal($"test message{Environment.NewLine}", _writer.ToString()); + [Fact] + public void Error_GivenNotOverridden_WhenCalled_ThenDoesNotThrow() + { + // Given + var wrapper = new ConsoleWrapper(); + ConsoleWrapper.ResetForTest(); // Reset to ensure _override is false + + // When & Then - Just verify it doesn't throw + var exception = Record.Exception(() => wrapper.Error("error without override")); + Assert.Null(exception); } [Fact] - public void WriteLine_WritesMessageToConsole() + public void SetOut_GivenTextWriter_WhenCalled_ThenEnablesTestMode() { - // Arrange - var consoleWrapper = new ConsoleWrapper(); - ConsoleWrapper.SetOut(_writer); + // Given + var testOutput = new StringWriter(); - // Act - consoleWrapper.WriteLine("Test message"); + // When + ConsoleWrapper.SetOut(testOutput); - // Assert - var output = _writer.ToString(); - Assert.Contains("Test message", output); + // Then + var wrapper = new ConsoleWrapper(); + wrapper.WriteLine("test"); + Assert.Equal($"test{Environment.NewLine}", testOutput.ToString()); + testOutput.Dispose(); } [Fact] - public void SetOut_OverridesConsoleOutput() + public void ResetForTest_GivenTestModeEnabled_WhenCalled_ThenResetsToNormalMode() { - // Act - ConsoleWrapper.SetOut(_writer); - Console.WriteLine("Test override"); + // Given + var testOutput = new StringWriter(); + ConsoleWrapper.SetOut(testOutput); + + // When + ConsoleWrapper.ResetForTest(); - // Assert - var output = _writer.ToString(); - Assert.Contains("Test override", output); + // Then + var wrapper = new ConsoleWrapper(); + var consoleOutput = new StringWriter(); + Console.SetOut(consoleOutput); + wrapper.WriteLine("test"); + Assert.Equal($"test{Environment.NewLine}", consoleOutput.ToString()); + Assert.Empty(testOutput.ToString()); + testOutput.Dispose(); + consoleOutput.Dispose(); } [Fact] - public void StaticWriteLine_FormatsLogMessageCorrectly() + public void WriteLineStatic_GivenLogLevelAndMessage_WhenCalled_ThenFormatsWithTimestamp() { - // Arrange - ConsoleWrapper.SetOut(_writer); - var logLevel = "INFO"; - var message = "Test log message"; + // Given + ConsoleWrapper.SetOut(_testWriter); + const string logLevel = "INFO"; + const string message = "Test log message"; try { - // Act - Using reflection to call internal static method + // When - Using reflection to call internal static method var method = typeof(ConsoleWrapper) - .GetMethod("WriteLine", System.Reflection.BindingFlags.NonPublic | System.Reflection.BindingFlags.Static); + .GetMethod("WriteLine", + System.Reflection.BindingFlags.NonPublic | System.Reflection.BindingFlags.Static); if (method == null) { @@ -124,21 +253,18 @@ public void StaticWriteLine_FormatsLogMessageCorrectly() method.Invoke(null, new object[] { logLevel, message }); - // Assert - var output = _writer.ToString(); - - // Simple assertions that always work + // Then + var output = _testWriter.ToString(); Assert.Contains(logLevel, output); Assert.Contains(message, output); - // Verify basic structure without parsing timestamp var lines = output.Split(Environment.NewLine, StringSplitOptions.RemoveEmptyEntries); Assert.True(lines.Length > 0, "Output should contain at least one line"); var parts = lines[0].Split('\t'); Assert.True(parts.Length >= 3, "Output should contain at least 3 tab-separated parts"); - - // Check that parts[0] contains a timestamp-like string (contains numbers, colons, etc.) + + // Check that parts[0] contains a timestamp-like string Assert.Matches(@"[\d\-:TZ.]", parts[0]); Assert.Equal(logLevel, parts[1]); Assert.Equal(message, parts[2]); @@ -151,81 +277,59 @@ public void StaticWriteLine_FormatsLogMessageCorrectly() } [Fact] - public void ClearOutputResetFlag_ResetsFlag() + public void ClearOutputResetFlag_GivenAnyState_WhenCalled_ThenDoesNotThrow() { - // Arrange - var consoleWrapper = new ConsoleWrapper(); - ConsoleWrapper.SetOut(_writer); - - // Act - consoleWrapper.WriteLine("First message"); // Should set the reset flag - ConsoleWrapper.ClearOutputResetFlag(); - consoleWrapper.WriteLine("Second message"); // Should set it again + // Given - any state - // Assert - Assert.Equal($"First message{Environment.NewLine}Second message{Environment.NewLine}", _writer.ToString()); + // When & Then - Should not throw (kept for backward compatibility) + var exception = Record.Exception(() => ConsoleWrapper.ClearOutputResetFlag()); + Assert.Null(exception); } [Fact] - public void Debug_InTestMode_WritesToTestOutputStream() + public void ClearOutputResetFlag_GivenMultipleCalls_WhenCalled_ThenAllowsRepeatedWrites() { - // Arrange - var consoleWrapper = new ConsoleWrapper(); - ConsoleWrapper.SetOut(_writer); + // Given + var wrapper = new ConsoleWrapper(); + ConsoleWrapper.SetOut(_testWriter); - // Act - consoleWrapper.Debug("debug message"); + // When + wrapper.WriteLine("First message"); + ConsoleWrapper.ClearOutputResetFlag(); + wrapper.WriteLine("Second message"); - // Assert - Assert.Equal($"debug message{Environment.NewLine}", _writer.ToString()); + // Then + Assert.Equal($"First message{Environment.NewLine}Second message{Environment.NewLine}", _testWriter.ToString()); } + // from here + [Fact] - public void Debug_NotInTestMode_WritesToDebugConsole() + public void HasLambdaReInterceptedConsole_WhenConsoleOutAccessThrows_ThenReturnsTrueFromCatchBlock() { - // Since capturing Debug output is difficult in a unit test - // We'll use a mock or just verify the path doesn't throw - - // Arrange - var consoleWrapper = new ConsoleWrapper(); - ConsoleWrapper.ResetForTest(); // Ensure we're not in test mode + // Given - A function that throws when called (simulating Console.Out access failure) + Func throwingAccessor = () => throw new InvalidOperationException("Console.Out access failed"); - // Act & Assert - Just verify it doesn't throw - var exception = Record.Exception(() => consoleWrapper.Debug("debug message")); - Assert.Null(exception); - } + // When - Call the internal method with the throwing accessor + var result = ConsoleWrapper.HasLambdaReInterceptedConsole(throwingAccessor); - [Fact] - public void Error_DoesNotThrowWhenNotOverridden() - { - // Arrange - var consoleWrapper = new ConsoleWrapper(); - ConsoleWrapper.ResetForTest(); // Reset to ensure _override is false - - // Act & Assert - Just verify it doesn't throw - var exception = Record.Exception(() => consoleWrapper.Error("error without override")); - Assert.Null(exception); + // Then - Should return true from the catch block (lines 102-105) + Assert.True(result); } [Fact] - public void Error_UsesTestOutputStreamWhenInTestMode() + public void OverrideLambdaLogger_WhenOpenStandardOutputThrows_ThenSetsOverrideToFalse() { - // Arrange - var consoleWrapper = new ConsoleWrapper(); - - // Set test mode - ConsoleWrapper.SetOut(_writer); + // Given + ConsoleWrapper.ResetForTest(); - // Act - consoleWrapper.Error("error in test mode"); + // A function that throws when called (simulating Console.OpenStandardOutput failure) + Func throwingOpener = () => throw new UnauthorizedAccessException("Cannot open standard output"); - // Assert - Assert.Contains("error in test mode", _writer.ToString()); - } + // When - Call the internal method with the throwing opener + var exception = Record.Exception(() => ConsoleWrapper.OverrideLambdaLogger(throwingOpener)); - public void Dispose() - { - ConsoleWrapper.ResetForTest(); - _writer?.Dispose(); + // Then - Should not throw (catch block handles it on lines 120-123) + Assert.Null(exception); } } \ No newline at end of file