diff --git a/libraries/src/AWS.Lambda.Powertools.Common/Core/ConsoleWrapper.cs b/libraries/src/AWS.Lambda.Powertools.Common/Core/ConsoleWrapper.cs index 4a124d94d..f3a012244 100644 --- a/libraries/src/AWS.Lambda.Powertools.Common/Core/ConsoleWrapper.cs +++ b/libraries/src/AWS.Lambda.Powertools.Common/Core/ConsoleWrapper.cs @@ -9,6 +9,9 @@ public class ConsoleWrapper : IConsoleWrapper private static bool _override; private static TextWriter _testOutputStream; private static bool _inTestMode = false; + private static StreamWriter _stdoutWriter; + private static StreamWriter _stderrWriter; + private static readonly object _lock = new object(); /// public void WriteLine(string message) @@ -47,12 +50,7 @@ public void Error(string message) } else { - if (!_override) - { - var errorOutput = new StreamWriter(Console.OpenStandardError()); - errorOutput.AutoFlush = true; - Console.SetError(errorOutput); - } + EnsureStderrOutput(); Console.Error.WriteLine(message); } } @@ -78,6 +76,37 @@ private static void EnsureConsoleOutput() } } + private static void EnsureStderrOutput() + { + EnsureStderrOutput(() => Console.OpenStandardError()); + } + + internal static void EnsureStderrOutput(Func standardErrorOpener) + { + if (_inTestMode) return; + + var isLambda = !string.IsNullOrEmpty(Environment.GetEnvironmentVariable("AWS_LAMBDA_FUNCTION_NAME")); + if (!isLambda) return; + + lock (_lock) + { + if (_stderrWriter != null) return; + + try + { + _stderrWriter = new StreamWriter(standardErrorOpener()) + { + AutoFlush = true + }; + Console.SetError(_stderrWriter); + } + catch (Exception) + { + // Degraded functionality is better than crash + } + } + } + private static bool ShouldOverrideConsole() { // Don't override if we're in test mode @@ -96,13 +125,27 @@ internal static bool HasLambdaReInterceptedConsole() internal static bool HasLambdaReInterceptedConsole(Func consoleOutAccessor) { - // Lambda might re-intercept console between init and handler execution + // Lambda might re-intercept console between init and handler execution. + // We need to detect when Lambda replaces our writer with its own, + // but NOT trigger on the SyncTextWriter wrapper that Console.SetOut + // always applies around our StreamWriter — that's still ours. 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"; + + // If it explicitly contains "Lambda", Lambda has re-intercepted + if (typeName.Contains("Lambda")) + return true; + + // If we have a cached writer, check if Console.Out still wraps it. + // Console.SetOut wraps in SyncTextWriter, so seeing SyncTextWriter + // does NOT mean Lambda re-intercepted — it's our own writer wrapped. + // Only if _stdoutWriter is null (never set) do we need to override. + lock (_lock) + { + return _stdoutWriter == null; + } } catch { @@ -117,20 +160,32 @@ internal static void OverrideLambdaLogger() internal static void OverrideLambdaLogger(Func standardOutputOpener) { - try + lock (_lock) { - // Force override of LambdaLogger - var standardOutput = new StreamWriter(standardOutputOpener()) + try { - AutoFlush = true - }; - Console.SetOut(standardOutput); - _override = true; - } - catch (Exception) - { - // Log the failure but don't throw - degraded functionality is better than crash - _override = false; + // Reuse existing writer if we already have one — avoids FD leak + if (_stdoutWriter != null) + { + // Re-set Console.Out in case Lambda replaced it + Console.SetOut(_stdoutWriter); + _override = true; + return; + } + + // First time: create a single long-lived writer for stdout + _stdoutWriter = new StreamWriter(standardOutputOpener()) + { + AutoFlush = true + }; + Console.SetOut(_stdoutWriter); + _override = true; + } + catch (Exception) + { + // Log the failure but don't throw - degraded functionality is better than crash + _override = false; + } } } @@ -147,6 +202,8 @@ public static void ResetForTest() _override = false; _inTestMode = false; _testOutputStream = null; + _stdoutWriter = null; + _stderrWriter = null; } /// @@ -157,4 +214,4 @@ public static void ClearOutputResetFlag() // 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/src/AWS.Lambda.Powertools.Logging/Serializers/PowertoolsLoggingSerializer.cs b/libraries/src/AWS.Lambda.Powertools.Logging/Serializers/PowertoolsLoggingSerializer.cs index 6cc93c515..cb949e374 100644 --- a/libraries/src/AWS.Lambda.Powertools.Logging/Serializers/PowertoolsLoggingSerializer.cs +++ b/libraries/src/AWS.Lambda.Powertools.Logging/Serializers/PowertoolsLoggingSerializer.cs @@ -20,7 +20,7 @@ internal class PowertoolsLoggingSerializer { private JsonSerializerOptions _currentOptions; private LoggerOutputCase _currentOutputCase; - private JsonSerializerOptions _jsonOptions; + private volatile JsonSerializerOptions _jsonOptions; private readonly object _lock = new(); private readonly ConcurrentBag _additionalContexts = new(); @@ -59,11 +59,9 @@ internal void ConfigureNamingPolicy(LoggerOutputCase loggerOutputCase) { _currentOutputCase = loggerOutputCase; - // Only rebuild options if they already exist - if (_jsonOptions != null) - { - SetOutputCase(); - } + // Force a full rebuild on next access instead of mutating existing options, + // because JsonSerializerOptions becomes read-only after first serialization. + _jsonOptions = null; } } } @@ -175,27 +173,29 @@ private void BuildJsonSerializerOptions(JsonSerializerOptions options = null) { lock (_lock) { - // Create a completely new options instance regardless - _jsonOptions = new JsonSerializerOptions(); + // Build into a local variable so _jsonOptions is never visible in a partially-configured state. + // Another thread doing a lock-free read in GetSerializerOptions() could see a non-null _jsonOptions, + // use it for serialization (making it read-only), and then subsequent mutations here would throw. + var newOptions = new JsonSerializerOptions(); // Copy any properties from the original options if provided if (options != null) { // Copy standard properties - _jsonOptions.DefaultIgnoreCondition = options.DefaultIgnoreCondition; - _jsonOptions.PropertyNameCaseInsensitive = options.PropertyNameCaseInsensitive; - _jsonOptions.PropertyNamingPolicy = options.PropertyNamingPolicy; - _jsonOptions.DictionaryKeyPolicy = options.DictionaryKeyPolicy; - _jsonOptions.WriteIndented = options.WriteIndented; - _jsonOptions.ReferenceHandler = options.ReferenceHandler; - _jsonOptions.MaxDepth = options.MaxDepth; - _jsonOptions.IgnoreReadOnlyFields = options.IgnoreReadOnlyFields; - _jsonOptions.IgnoreReadOnlyProperties = options.IgnoreReadOnlyProperties; - _jsonOptions.IncludeFields = options.IncludeFields; - _jsonOptions.NumberHandling = options.NumberHandling; - _jsonOptions.ReadCommentHandling = options.ReadCommentHandling; - _jsonOptions.UnknownTypeHandling = options.UnknownTypeHandling; - _jsonOptions.AllowTrailingCommas = options.AllowTrailingCommas; + newOptions.DefaultIgnoreCondition = options.DefaultIgnoreCondition; + newOptions.PropertyNameCaseInsensitive = options.PropertyNameCaseInsensitive; + newOptions.PropertyNamingPolicy = options.PropertyNamingPolicy; + newOptions.DictionaryKeyPolicy = options.DictionaryKeyPolicy; + newOptions.WriteIndented = options.WriteIndented; + newOptions.ReferenceHandler = options.ReferenceHandler; + newOptions.MaxDepth = options.MaxDepth; + newOptions.IgnoreReadOnlyFields = options.IgnoreReadOnlyFields; + newOptions.IgnoreReadOnlyProperties = options.IgnoreReadOnlyProperties; + newOptions.IncludeFields = options.IncludeFields; + newOptions.NumberHandling = options.NumberHandling; + newOptions.ReadCommentHandling = options.ReadCommentHandling; + newOptions.UnknownTypeHandling = options.UnknownTypeHandling; + newOptions.AllowTrailingCommas = options.AllowTrailingCommas; // Handle type resolver extraction without setting it yet if (options.TypeInfoResolver != null) @@ -211,49 +211,52 @@ private void BuildJsonSerializerOptions(JsonSerializerOptions options = null) } // Set output case and other properties - SetOutputCase(); - AddConverters(); - _jsonOptions.Encoder = JavaScriptEncoder.UnsafeRelaxedJsonEscaping; - _jsonOptions.PropertyNameCaseInsensitive = true; + SetOutputCase(newOptions); + AddConverters(newOptions); + newOptions.Encoder = JavaScriptEncoder.UnsafeRelaxedJsonEscaping; + newOptions.PropertyNameCaseInsensitive = true; // Set TypeInfoResolver last, as this makes options read-only if (!RuntimeFeatureWrapper.IsDynamicCodeSupported) { - _jsonOptions.TypeInfoResolver = GetCompositeResolver(); + newOptions.TypeInfoResolver = GetCompositeResolver(); } + + // Publish fully-configured options in a single atomic assignment + _jsonOptions = newOptions; } } - internal void SetOutputCase() + internal void SetOutputCase(JsonSerializerOptions target) { switch (_currentOutputCase) { case LoggerOutputCase.CamelCase: - _jsonOptions.PropertyNamingPolicy = JsonNamingPolicy.CamelCase; - _jsonOptions.DictionaryKeyPolicy = JsonNamingPolicy.CamelCase; + target.PropertyNamingPolicy = JsonNamingPolicy.CamelCase; + target.DictionaryKeyPolicy = JsonNamingPolicy.CamelCase; break; case LoggerOutputCase.PascalCase: - _jsonOptions.PropertyNamingPolicy = PascalCaseNamingPolicy.Instance; - _jsonOptions.DictionaryKeyPolicy = PascalCaseNamingPolicy.Instance; + target.PropertyNamingPolicy = PascalCaseNamingPolicy.Instance; + target.DictionaryKeyPolicy = PascalCaseNamingPolicy.Instance; break; default: // Snake case // If is default (Not Set) and JsonOptions provided with DictionaryKeyPolicy or PropertyNamingPolicy, use it - _jsonOptions.DictionaryKeyPolicy ??= JsonNamingPolicy.SnakeCaseLower; - _jsonOptions.PropertyNamingPolicy ??= JsonNamingPolicy.SnakeCaseLower; + target.DictionaryKeyPolicy ??= JsonNamingPolicy.SnakeCaseLower; + target.PropertyNamingPolicy ??= JsonNamingPolicy.SnakeCaseLower; break; } } - private void AddConverters() + private static void AddConverters(JsonSerializerOptions target) { - _jsonOptions.Converters.Add(new ByteArrayConverter()); - _jsonOptions.Converters.Add(new ExceptionConverter()); - _jsonOptions.Converters.Add(new MemoryStreamConverter()); - _jsonOptions.Converters.Add(new ConstantClassConverter()); - _jsonOptions.Converters.Add(new DateOnlyConverter()); - _jsonOptions.Converters.Add(new TimeOnlyConverter()); - - _jsonOptions.Converters.Add(new LogLevelJsonConverter()); + target.Converters.Add(new ByteArrayConverter()); + target.Converters.Add(new ExceptionConverter()); + target.Converters.Add(new MemoryStreamConverter()); + target.Converters.Add(new ConstantClassConverter()); + target.Converters.Add(new DateOnlyConverter()); + target.Converters.Add(new TimeOnlyConverter()); + + target.Converters.Add(new LogLevelJsonConverter()); } internal void SetOptions(JsonSerializerOptions options) diff --git a/libraries/tests/AWS.Lambda.Powertools.Common.Tests/ConsoleWrapperTests.cs b/libraries/tests/AWS.Lambda.Powertools.Common.Tests/ConsoleWrapperTests.cs index 25cea21d4..a81ad5f2b 100644 --- a/libraries/tests/AWS.Lambda.Powertools.Common.Tests/ConsoleWrapperTests.cs +++ b/libraries/tests/AWS.Lambda.Powertools.Common.Tests/ConsoleWrapperTests.cs @@ -332,4 +332,112 @@ public void OverrideLambdaLogger_WhenOpenStandardOutputThrows_ThenSetsOverrideTo // Then - Should not throw (catch block handles it on lines 120-123) Assert.Null(exception); } + + [Fact] + public void OverrideLambdaLogger_GivenMultipleCalls_ShouldOpenStdoutOnlyOnce_NoFdLeak() + { + // Regression test for https://github.com/aws-powertools/powertools-lambda-dotnet/issues/1143 + // Before the fix, every call to OverrideLambdaLogger created a new + // StreamWriter(Console.OpenStandardOutput()), leaking one FD per log write. + // Under sustained load this exhausted the Lambda 1024 FD limit. + + // Given + ConsoleWrapper.ResetForTest(); + int openCount = 0; + Func countingOpener = () => + { + openCount++; + return new MemoryStream(); // stand-in for stdout + }; + + // When — simulate 500 log writes triggering OverrideLambdaLogger + for (int i = 0; i < 500; i++) + { + ConsoleWrapper.OverrideLambdaLogger(countingOpener); + } + + // Then — stream should have been opened exactly once, not 500 times + Assert.Equal(1, openCount); + } + + [Fact] + public void EnsureStderrOutput_GivenMultipleErrorCalls_ShouldOpenStderrOnlyOnce_NoFdLeak() + { + // Regression test: same FD leak pattern as stdout but for stderr path. + // EnsureStderrOutput should only call Console.OpenStandardError() once. + + // Given + ConsoleWrapper.ResetForTest(); + Environment.SetEnvironmentVariable("AWS_LAMBDA_FUNCTION_NAME", "test-function"); + int openCount = 0; + Func countingOpener = () => + { + openCount++; + return new MemoryStream(); // stand-in for stderr + }; + + // When — simulate 500 error writes triggering EnsureStderrOutput + for (int i = 0; i < 500; i++) + { + ConsoleWrapper.EnsureStderrOutput(countingOpener); + } + + // Then — stream should have been opened exactly once, not 500 times + Assert.Equal(1, openCount); + } + + [Fact] + public void WriteLine_GivenLambdaEnvironment_MultipleWrites_ShouldNotLeakFileDescriptors() + { + // Regression test for https://github.com/aws-powertools/powertools-lambda-dotnet/issues/1143 + // End-to-end: exercises the full WriteLine → EnsureConsoleOutput → + // ShouldOverrideConsole → OverrideLambdaLogger path in Lambda environment. + // Verifies that repeated calls through the public API only open stdout once. + + // Given + ConsoleWrapper.ResetForTest(); + Environment.SetEnvironmentVariable("AWS_LAMBDA_FUNCTION_NAME", "test-function"); + int openCount = 0; + Func countingOpener = () => + { + openCount++; + return new MemoryStream(); + }; + + // Seed the stdout writer via the internal API with our counting opener + // so subsequent public WriteLine calls reuse it instead of opening real stdout + ConsoleWrapper.OverrideLambdaLogger(countingOpener); + Assert.Equal(1, openCount); + + // When — multiple writes through the public API + var wrapper = new ConsoleWrapper(); + for (int i = 0; i < 100; i++) + { + wrapper.WriteLine($"message {i}"); + } + + // Then — the counting opener should still have been called only once; + // all 100 public writes reused the cached writer + Assert.Equal(1, openCount); + } + + [Fact] + public void HasLambdaReInterceptedConsole_AfterOverride_ShouldNotFalsePositiveOnSyncTextWriter() + { + // Regression test for https://github.com/aws-powertools/powertools-lambda-dotnet/issues/1143 + // The old code checked: typeName == "System.IO.TextWriter+SyncTextWriter" + // But Console.SetOut() ALWAYS wraps in SyncTextWriter, so this was a + // permanent false positive that caused OverrideLambdaLogger to fire on every call. + + // Given — override has been applied (simulating first log write in Lambda) + ConsoleWrapper.ResetForTest(); + ConsoleWrapper.OverrideLambdaLogger(() => new MemoryStream()); + + // When — check if Lambda "re-intercepted" (it didn't, we just set it ourselves) + // Console.Out is now SyncTextWriter wrapping our StreamWriter + var result = ConsoleWrapper.HasLambdaReInterceptedConsole(); + + // Then — should be false: our writer is still in place, Lambda didn't touch it + Assert.False(result); + } } \ No newline at end of file