From 70c63332093aed13812d445e0092738bfc08aed8 Mon Sep 17 00:00:00 2001 From: Norm Johanson Date: Tue, 22 Sep 2026 23:58:40 +0000 Subject: [PATCH 1/5] Fix ConfigureStructuredLogging no-op for class library functions on managed runtime (#2350) In the class library programming model the managed runtime hosts a bundled Amazon.Lambda.RuntimeSupport that is compiled against its own Amazon.Lambda.Core, while the customer's Amazon.Lambda.Core is loaded separately by UserCodeLoader. The compile-time SetConfigureStructuredLoggingAction wiring therefore registered the formatter callback on the wrong LambdaLogger, so LambdaLogger.ConfigureStructuredLogging had no effect (custom JsonSerializerOptions were dropped and objects rendered as {}). Wire the structured logging callback into the customer's Amazon.Lambda.Core via reflection, mirroring the existing SetCustomerLoggerLogAction pattern: - Add ConfigureCallbackInCore(Assembly, Action) reflection overload - Track JsonLogMessageFormatter instances and add WireStructuredLoggingCallbacksToCustomerCore - Invoke it from UserCodeLoader when the customer's Amazon.Lambda.Core loads The executable / custom runtime path is unchanged. Adds regression tests. --- ...c1-2350-4e8d-9a3c-configstructuredlog.json | 11 ++ .../Bootstrap/UserCodeLoader.cs | 16 ++ ...onfigureJsonLogMessageFormatterIsolated.cs | 168 ++++++++++++++++++ .../Logging/JsonLogMessageFormatter.cs | 39 ++++ .../StructuredLoggingCustomerCoreTests.cs | 107 +++++++++++ investigation/README.md | 114 ++++++++++++ investigation/repro/TwoAssemblyRepro.cs | 78 ++++++++ investigation/repro/TwoAssemblyRepro.csproj | 13 ++ 8 files changed, 546 insertions(+) create mode 100644 .autover/changes/b2f4a6c1-2350-4e8d-9a3c-configstructuredlog.json create mode 100644 Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/StructuredLoggingCustomerCoreTests.cs create mode 100644 investigation/README.md create mode 100644 investigation/repro/TwoAssemblyRepro.cs create mode 100644 investigation/repro/TwoAssemblyRepro.csproj diff --git a/.autover/changes/b2f4a6c1-2350-4e8d-9a3c-configstructuredlog.json b/.autover/changes/b2f4a6c1-2350-4e8d-9a3c-configstructuredlog.json new file mode 100644 index 000000000..dad27e6ea --- /dev/null +++ b/.autover/changes/b2f4a6c1-2350-4e8d-9a3c-configstructuredlog.json @@ -0,0 +1,11 @@ +{ + "Projects": [ + { + "Name": "Amazon.Lambda.RuntimeSupport", + "Type": "Patch", + "ChangelogMessages": [ + "Fix LambdaLogger.ConfigureStructuredLogging having no effect for class library Lambda functions on the managed runtime by wiring the structured logging callback into the customer's Amazon.Lambda.Core assembly via reflection." + ] + } + ] +} diff --git a/Libraries/src/Amazon.Lambda.RuntimeSupport/Bootstrap/UserCodeLoader.cs b/Libraries/src/Amazon.Lambda.RuntimeSupport/Bootstrap/UserCodeLoader.cs index 5c079a7d8..6f7930d6a 100644 --- a/Libraries/src/Amazon.Lambda.RuntimeSupport/Bootstrap/UserCodeLoader.cs +++ b/Libraries/src/Amazon.Lambda.RuntimeSupport/Bootstrap/UserCodeLoader.cs @@ -100,6 +100,22 @@ public void Init(Action customerLoggingAction) _logger.LogDebug( $"UCL : Load context loading '{LambdaCoreAssemblyName}', attempting to set {Types.LambdaLoggerTypeName}.{LambdaLoggingActionFieldName} to logging action."); SetCustomerLoggerLogAction(args.LoadedAssembly, customerLoggingAction, _logger); + + // Wire the structured logging configuration callback into the customer's copy of + // Amazon.Lambda.Core. This is required because Amazon.Lambda.RuntimeSupport is compiled against + // its own bundled Amazon.Lambda.Core in the managed runtime; the compile-time wiring done in + // JsonLogMessageFormatter's constructor targets the wrong assembly, so the customer's call to + // LambdaLogger.ConfigureStructuredLogging would otherwise never reach the formatter. + // See https://github.com/aws/aws-lambda-dotnet/issues/2350. + try + { + Helpers.Logging.JsonLogMessageFormatter.WireStructuredLoggingCallbacksToCustomerCore(args.LoadedAssembly); + } + catch (Exception ex) + { + _logger.LogDebug("UCL : Failed to wire structured logging callback into the customer's Amazon.Lambda.Core: " + ex); + } + _customerLoggerSetUpComplete = true; } }; diff --git a/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/ConfigureJsonLogMessageFormatterIsolated.cs b/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/ConfigureJsonLogMessageFormatterIsolated.cs index b78a47d15..4227e5abd 100644 --- a/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/ConfigureJsonLogMessageFormatterIsolated.cs +++ b/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/ConfigureJsonLogMessageFormatterIsolated.cs @@ -2,12 +2,44 @@ // SPDX-License-Identifier: Apache-2.0 using System; +using System.Reflection; using System.Text.Json; namespace Amazon.Lambda.RuntimeSupport.Helpers.Logging { + /// + /// Bridges the structured logging configuration callback in Amazon.Lambda.RuntimeSupport with the + /// Amazon.Lambda.Core.LambdaLogger.ConfigureStructuredLogging API in Amazon.Lambda.Core. + /// + /// There are two very different ways Amazon.Lambda.RuntimeSupport gets its reference to Amazon.Lambda.Core: + /// * Executable / custom runtime model: the customer references both Amazon.Lambda.Core and + /// Amazon.Lambda.RuntimeSupport from the same deployment bundle, so the compile-time reference + /// to Amazon.Lambda.Core.LambdaLogger resolves to the exact same assembly the customer code uses. + /// * Class library model on the managed runtime: Amazon.Lambda.RuntimeSupport is baked into the managed + /// runtime and compiled against its own (potentially older) copy of Amazon.Lambda.Core, while the customer's + /// Amazon.Lambda.Core is loaded separately from the deployment bundle by . + /// In that case the compile-time reference used by + /// points at the WRONG LambdaLogger, so the customer's call to LambdaLogger.ConfigureStructuredLogging + /// never reaches the formatter. See https://github.com/aws/aws-lambda-dotnet/issues/2350. + /// + /// To support the class library model this class can also wire the callback into a specific, reflection-loaded + /// Amazon.Lambda.Core assembly via . + /// internal class ConfigureJsonLogMessageFormatterIsolated { + // Field and method names on Amazon.Lambda.Core.LambdaLogger that we bind to reflectively. These MUST match + // the members declared in Amazon.Lambda.Core.LambdaLogger. They are only used for the reflection based path + // (class library model) where the compile-time reference cannot be relied upon. + private const string LambdaLoggerTypeName = "Amazon.Lambda.Core.LambdaLogger"; + private const string StructuredLoggingOptionsTypeName = "Amazon.Lambda.Core.StructuredLoggingOptions"; + private const string SetConfigureStructuredLoggingActionMethodName = "SetConfigureStructuredLoggingAction"; + private const string OverrideSerializerOptionsPropertyName = "OverrideSerializerOptions"; + + /// + /// Wire the callback into the version of Amazon.Lambda.Core referenced at compile time. This is the correct + /// assembly for the executable / custom runtime programming model. + /// + /// Callback invoked with the customer supplied structured logging options. internal static void ConfigureCallbackInCore(Action callback) { Amazon.Lambda.Core.LambdaLogger.SetConfigureStructuredLoggingAction((Amazon.Lambda.Core.StructuredLoggingOptions coreOptions) => @@ -31,5 +63,141 @@ internal static void ConfigureCallbackInCore(Action ca callback(isolatedOptions); }); } + + /// + /// Wire the callback into a specific, reflection-loaded copy of Amazon.Lambda.Core. This is required for the + /// class library programming model on the managed runtime, where the customer's Amazon.Lambda.Core is a + /// different assembly than the one Amazon.Lambda.RuntimeSupport was compiled against. + /// + /// The whole call is done through reflection because we cannot cast the callback (which uses the RuntimeSupport + /// bundled types) to the delegate type expected by the customer's Amazon.Lambda.Core. Instead we build a + /// weakly typed where T is the customer's StructuredLoggingOptions type and read the + /// OverrideSerializerOptions property off the supplied instance reflectively. + /// + /// The customer's Amazon.Lambda.Core assembly loaded by the UserCodeLoader. + /// Callback invoked with the customer supplied structured logging options. + [System.Diagnostics.CodeAnalysis.RequiresUnreferencedCode("Uses reflection against the customer's Amazon.Lambda.Core. Only used in the class library programming model which does not support trimming.")] + internal static void ConfigureCallbackInCore(Assembly coreAssembly, Action callback) + { + if (coreAssembly == null) + { + throw new ArgumentNullException(nameof(coreAssembly)); + } + + var logger = InternalLogger.GetDefaultLogger(); + + var lambdaLoggerType = coreAssembly.GetType(LambdaLoggerTypeName); + if (lambdaLoggerType == null) + { + logger.LogDebug($"Structured logging callback not configured: could not find type {LambdaLoggerTypeName} in the customer's Amazon.Lambda.Core."); + return; + } + + var optionsType = coreAssembly.GetType(StructuredLoggingOptionsTypeName); + if (optionsType == null) + { + // This happens when the customer references a version of Amazon.Lambda.Core that predates the + // ConfigureStructuredLogging API. Nothing to wire up in that case. + logger.LogDebug($"Structured logging callback not configured: the customer's Amazon.Lambda.Core does not contain {StructuredLoggingOptionsTypeName}. Update Amazon.Lambda.Core to use structured logging customization."); + return; + } + + // SetConfigureStructuredLoggingAction(Action) is internal on LambdaLogger. + var setActionMethod = lambdaLoggerType.GetMethod( + SetConfigureStructuredLoggingActionMethodName, + BindingFlags.NonPublic | BindingFlags.Static); + if (setActionMethod == null) + { + logger.LogDebug($"Structured logging callback not configured: could not find method {SetConfigureStructuredLoggingActionMethodName} on {LambdaLoggerTypeName}. Update Amazon.Lambda.Core to use structured logging customization."); + return; + } + + var overrideSerializerOptionsProperty = optionsType.GetProperty( + OverrideSerializerOptionsPropertyName, + BindingFlags.Public | BindingFlags.Instance); + if (overrideSerializerOptionsProperty == null) + { + logger.LogDebug($"Structured logging callback not configured: could not find property {OverrideSerializerOptionsPropertyName} on {StructuredLoggingOptionsTypeName}."); + return; + } + + // Build an Action that reads OverrideSerializerOptions reflectively + // and forwards a RuntimeSupport-typed StructuredLoggingOptions to the callback. + // + // We use a non-generic delegate wrapper (Action) and adapt it to the strongly typed delegate the + // internal method expects with Delegate.CreateDelegate via a helper method that has the right signature. + var forwarder = new StructuredLoggingCallbackForwarder(callback, overrideSerializerOptionsProperty); + + // The internal method's parameter is Action. Construct that delegate type and bind it to + // the forwarder's Invoke method which accepts object (compatible because reference types are covariant here + // only through an explicit adapter). Because Action is not covariant, we instead create the delegate from + // the forwarder instance method that takes object, using a dynamically constructed Action. + var actionOfOptionsType = typeof(Action<>).MakeGenericType(optionsType); + Delegate stronglyTypedDelegate; + try + { + stronglyTypedDelegate = Delegate.CreateDelegate( + actionOfOptionsType, + forwarder, + nameof(StructuredLoggingCallbackForwarder.Invoke)); + } + catch (Exception ex) + { + logger.LogDebug("Structured logging callback not configured: failed to bind delegate to the customer's Amazon.Lambda.Core StructuredLoggingOptions type: " + ex); + return; + } + + try + { + setActionMethod.Invoke(null, new object[] { stronglyTypedDelegate }); + logger.LogDebug("Structured logging callback configured against the customer's Amazon.Lambda.Core using reflection."); + } + catch (Exception ex) + { + logger.LogDebug("Structured logging callback not configured: failed to invoke SetConfigureStructuredLoggingAction on the customer's Amazon.Lambda.Core: " + ex); + } + } + + /// + /// Adapter that receives the customer's StructuredLoggingOptions instance (typed as object so it works across + /// assembly boundaries) and forwards the relevant values to the RuntimeSupport structured logging callback. + /// The method is bound to an Action<TCustomerOptions> via + /// ; the parameter is declared as + /// because reference-type contravariance allows the customer options instance to be passed to it. + /// + private sealed class StructuredLoggingCallbackForwarder + { + private readonly Action _callback; + private readonly PropertyInfo _overrideSerializerOptionsProperty; + + public StructuredLoggingCallbackForwarder(Action callback, PropertyInfo overrideSerializerOptionsProperty) + { + _callback = callback; + _overrideSerializerOptionsProperty = overrideSerializerOptionsProperty; + } + + // Bound to Action. TCustomerOptions is a reference type, so it is assignment compatible + // with object which lets CreateDelegate bind this method to the strongly typed delegate. + public void Invoke(object coreOptions) + { + if (coreOptions == null) + { + _callback(null); + return; + } + + var isolatedOptions = new StructuredLoggingOptions(); + try + { + isolatedOptions.OverrideSerializerOptions = _overrideSerializerOptionsProperty.GetValue(coreOptions) as JsonSerializerOptions; + } + catch (Exception ex) + { + InternalLogger.GetDefaultLogger().LogDebug("Failed to read structured logging options from the customer's Amazon.Lambda.Core. This generally happens when the version of Amazon.Lambda.Core is out of date. Update to latest version of Amazon.Lambda.Core: " + ex); + } + + _callback(isolatedOptions); + } + } } } diff --git a/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/JsonLogMessageFormatter.cs b/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/JsonLogMessageFormatter.cs index ac4943188..a003aa836 100644 --- a/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/JsonLogMessageFormatter.cs +++ b/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/JsonLogMessageFormatter.cs @@ -20,6 +20,14 @@ public class JsonLogMessageFormatter : AbstractLogMessageFormatter // Options used when serializing any message property values as a JSON to be added to the structured log message. private JsonSerializerOptions _jsonSerializationOptions; + // Tracks the JsonLogMessageFormatter instances that have been created. This is needed for the class library + // programming model (managed runtime) where the customer's Amazon.Lambda.Core is loaded AFTER the formatter is + // constructed. When the UserCodeLoader loads the customer's Amazon.Lambda.Core it calls + // WireStructuredLoggingCallbacksToCustomerCore so each formatter can register its callback against the correct + // (customer) copy of Amazon.Lambda.Core. See https://github.com/aws/aws-lambda-dotnet/issues/2350. + private static readonly object _instancesLock = new object(); + private static readonly List _instances = new List(); + /// /// Constructs an instance of JsonLogMessageFormatter. /// @@ -31,8 +39,17 @@ public JsonLogMessageFormatter() WriteIndented = false }; + lock (_instancesLock) + { + _instances.Add(this); + } + try { + // Executable / custom runtime model: the compile-time reference to Amazon.Lambda.Core is the same + // assembly the customer uses, so this correctly wires the callback. In the class library model this + // wires up the RuntimeSupport bundled Amazon.Lambda.Core (harmless) and the real wiring happens later + // through WireStructuredLoggingCallbacksToCustomerCore once the customer's Amazon.Lambda.Core loads. ConfigureJsonLogMessageFormatterIsolated.ConfigureCallbackInCore(ConfigureStructuredLogging); } catch (TypeLoadException) @@ -41,6 +58,28 @@ public JsonLogMessageFormatter() } } + /// + /// Wire every JsonLogMessageFormatter instance's structured logging callback into the customer's copy of + /// Amazon.Lambda.Core using reflection. This is used by the class library programming model on the managed + /// runtime, where the customer's Amazon.Lambda.Core is a different assembly than the one Amazon.Lambda.RuntimeSupport + /// was compiled against. See https://github.com/aws/aws-lambda-dotnet/issues/2350. + /// + /// The customer's Amazon.Lambda.Core assembly loaded by the UserCodeLoader. + [System.Diagnostics.CodeAnalysis.RequiresUnreferencedCode("Uses reflection against the customer's Amazon.Lambda.Core. Only used in the class library programming model which does not support trimming.")] + internal static void WireStructuredLoggingCallbacksToCustomerCore(System.Reflection.Assembly customerCoreAssembly) + { + JsonLogMessageFormatter[] snapshot; + lock (_instancesLock) + { + snapshot = _instances.ToArray(); + } + + foreach (var formatter in snapshot) + { + ConfigureJsonLogMessageFormatterIsolated.ConfigureCallbackInCore(customerCoreAssembly, formatter.ConfigureStructuredLogging); + } + } + private static readonly IReadOnlyList _emptyMessageProperties = new List(); private void ConfigureStructuredLogging(StructuredLoggingOptions options) diff --git a/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/StructuredLoggingCustomerCoreTests.cs b/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/StructuredLoggingCustomerCoreTests.cs new file mode 100644 index 000000000..efb572739 --- /dev/null +++ b/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/StructuredLoggingCustomerCoreTests.cs @@ -0,0 +1,107 @@ +// Copyright Amazon.com, Inc. or its affiliates. All Rights Reserved. +// SPDX-License-Identifier: Apache-2.0 + +using System; +using System.Reflection; +using System.Text.Json; +using System.Text.Json.Serialization; +using Amazon.Lambda.RuntimeSupport.Helpers; +using Amazon.Lambda.RuntimeSupport.Helpers.Logging; +using Xunit; + +namespace Amazon.Lambda.RuntimeSupport.UnitTests +{ + /// + /// Tests the reflection based wiring of the structured logging configuration callback used by the class library + /// programming model on the managed runtime. In that model Amazon.Lambda.RuntimeSupport is compiled against its own + /// bundled Amazon.Lambda.Core, while the customer's Amazon.Lambda.Core is loaded separately. The compile-time + /// wiring in JsonLogMessageFormatter's constructor therefore targets the wrong assembly and the customer's call to + /// LambdaLogger.ConfigureStructuredLogging never reaches the formatter. + /// + /// See https://github.com/aws/aws-lambda-dotnet/issues/2350. + /// + public class StructuredLoggingCustomerCoreTests + { + public class Product + { + public string Name { get; set; } + public int Inventory { get; set; } + public override string ToString() => $"{Name} {Inventory}"; + } + + /// + /// Simulates the managed runtime wiring: after the customer's Amazon.Lambda.Core assembly is discovered, the + /// UserCodeLoader wires the structured logging callback into it via reflection. This test verifies the + /// reflection path (ConfigureCallbackInCore(Assembly, ...) reached through + /// WireStructuredLoggingCallbacksToCustomerCore) actually delivers the customer's JsonSerializerOptions to the + /// formatter, which is the behavior that was missing before the fix for issue #2350. + /// + [Fact] + public void ReflectionWiring_DeliversOverrideSerializerOptions_ToFormatter() + { + var formatter = new JsonLogMessageFormatter(); + + // The assembly that actually defines the Amazon.Lambda.Core.LambdaLogger type the test references. In the + // real managed runtime this is the customer's copy, distinct from the RuntimeSupport bundled copy. + var customerCoreAssembly = typeof(Amazon.Lambda.Core.LambdaLogger).Assembly; + + // Wire using the reflection based path used by the class library model. + JsonLogMessageFormatter.WireStructuredLoggingCallbacksToCustomerCore(customerCoreAssembly); + + var customOptions = new JsonSerializerOptions + { + PropertyNamingPolicy = JsonNamingPolicy.CamelCase, + WriteIndented = false + }; + + // Customer calls the public API on their Amazon.Lambda.Core. Because the reflection wiring registered the + // callback against this assembly's LambdaLogger, it must flow through to the formatter. + Amazon.Lambda.Core.LambdaLogger.ConfigureStructuredLogging(new Amazon.Lambda.Core.StructuredLoggingOptions + { + OverrideSerializerOptions = customOptions + }); + + var state = new MessageState + { + AwsRequestId = "1234", + Level = LogLevelLoggerWriter.LogLevel.Information, + MessageTemplate = "Product is {@product}", + MessageArguments = new object[] { new Product { Name = "Widget", Inventory = 100 } }, + TimeStamp = DateTime.UtcNow + }; + + var json = formatter.FormatMessage(state); + var doc = JsonDocument.Parse(json); + + // camelCase naming policy from the customer supplied options must be applied by the formatter. + Assert.Equal(JsonValueKind.Object, doc.RootElement.GetProperty("product").ValueKind); + Assert.Equal("Widget", doc.RootElement.GetProperty("product").GetProperty("name").GetString()); + Assert.Equal(100, doc.RootElement.GetProperty("product").GetProperty("inventory").GetInt32()); + } + + /// + /// The reflection wiring must be resilient: passing an assembly that does not contain the structured logging + /// types (simulating an older Amazon.Lambda.Core in the deployment bundle) must not throw. + /// + [Fact] + public void ReflectionWiring_AssemblyWithoutStructuredLoggingTypes_DoesNotThrow() + { + var formatter = new JsonLogMessageFormatter(); + + // System.Private.CoreLib clearly has no Amazon.Lambda.Core.LambdaLogger type. + var unrelatedAssembly = typeof(object).Assembly; + + var ex = Record.Exception(() => + ConfigureJsonLogMessageFormatterIsolated.ConfigureCallbackInCore(unrelatedAssembly, options => { })); + + Assert.Null(ex); + } + + [Fact] + public void ReflectionWiring_NullAssembly_Throws() + { + Assert.Throws(() => + ConfigureJsonLogMessageFormatterIsolated.ConfigureCallbackInCore((Assembly)null, options => { })); + } + } +} diff --git a/investigation/README.md b/investigation/README.md new file mode 100644 index 000000000..5b39a148d --- /dev/null +++ b/investigation/README.md @@ -0,0 +1,114 @@ +# Issue #2350 — `LambdaLogger.ConfigureStructuredLogging` is a no-op on the managed runtime (class library model) + +Issue: https://github.com/aws/aws-lambda-dotnet/issues/2350 + +## Summary + +The last comment on the issue (from `madmox`) reports that `LambdaLogger.ConfigureStructuredLogging`, +though listed as "deployed to the managed runtime" in the 2026-07-29 release notes, has no effect for +**class library** Lambda functions on the managed `dotnet10` runtime. A destructured `{@ScheduledDate}` +(`NodaTime.Instant`) still renders as `"ScheduledDate":{}` — the custom `JsonSerializerOptions` converters +never reach the formatter. The same call works when using `Amazon.Lambda.RuntimeSupport` directly (the +executable / custom runtime model). + +The reporter's read is correct: the callback that configures the formatter is not wired up correctly when +`Amazon.Lambda.RuntimeSupport` runs as the executable host for a class-library function on the managed runtime. + +## Root cause + +`ConfigureStructuredLogging` was added in PR #2383. The wiring lives in +`JsonLogMessageFormatter`'s constructor: + +```csharp +ConfigureJsonLogMessageFormatterIsolated.ConfigureCallbackInCore(ConfigureStructuredLogging); +``` + +and `ConfigureCallbackInCore` used a **compile-time** reference: + +```csharp +Amazon.Lambda.Core.LambdaLogger.SetConfigureStructuredLoggingAction(coreOptions => { ... }); +``` + +`Amazon.Lambda.Core.LambdaLogger` exposes a private static field / internal setter that the runtime replaces so +that `ConfigureStructuredLogging` reaches the active `JsonLogMessageFormatter`. + +There are two very different ways `Amazon.Lambda.RuntimeSupport` obtains its `Amazon.Lambda.Core` reference: + +* **Executable / custom runtime model** — the customer references both `Amazon.Lambda.Core` and + `Amazon.Lambda.RuntimeSupport` from the same deployment bundle. The compile-time reference resolves to the + *same* `Amazon.Lambda.Core` assembly the customer code uses, so `SetConfigureStructuredLoggingAction` lands on + the correct `LambdaLogger`. **This is why the reporter's control experiment against the 2.2.0 NuGet package + works.** + +* **Class library model on the managed runtime** — `Amazon.Lambda.RuntimeSupport` is baked into the managed + runtime and compiled against **its own** bundled `Amazon.Lambda.Core`. The customer's `Amazon.Lambda.Core` + (e.g. 3.3.0 from the deployment bundle) is loaded *separately* by + `Amazon.Lambda.RuntimeSupport.Bootstrap.UserCodeLoader`. These are **two distinct assembly instances** with two + distinct `LambdaLogger` types and two distinct static callback fields. + + In this model the compile-time `SetConfigureStructuredLoggingAction` call registers the formatter callback on + the **RuntimeSupport-bundled** `LambdaLogger`, while the customer's code calls `ConfigureStructuredLogging` on + the **customer's** `LambdaLogger`. The two never meet, so the customer's `JsonSerializerOptions` are silently + dropped and the formatter keeps its default options — exactly the observed `"ScheduledDate":{}` behavior. + +`UserCodeLoader` already knows about this two-assembly problem for plain logging: it redirects the customer's +`LambdaLogger._loggingAction` (and the level variants) via **reflection** against the loaded customer assembly +(`SetCustomerLoggerLogAction`). The structured-logging callback added in #2383 was simply never given the same +reflection-based treatment, so it worked only in the executable model. + +### Evidence + +`investigation/repro/TwoAssemblyRepro.cs` loads a second copy of `Amazon.Lambda.Core` into a separate +`AssemblyLoadContext` and prints: + +``` +Same assembly instance? False +``` + +confirming the customer's `Amazon.Lambda.Core` is a different assembly than the compile-time reference used by +the original wiring. + +## Fix + +Give the structured-logging callback the same reflection-based wiring that plain logging already uses. + +1. `Helpers/Logging/ConfigureJsonLogMessageFormatterIsolated.cs` + - Added an overload `ConfigureCallbackInCore(Assembly coreAssembly, Action callback)` + that registers the callback against a **specific** (reflection-loaded) `Amazon.Lambda.Core` assembly. It + reflectively finds `LambdaLogger.SetConfigureStructuredLoggingAction`, builds an + `Action` bound to an adapter that reads `OverrideSerializerOptions` off the + customer options instance, and invokes the setter. It degrades gracefully (logs debug, no throw) when the + customer's `Amazon.Lambda.Core` predates the API. + +2. `Helpers/Logging/JsonLogMessageFormatter.cs` + - Tracks constructed formatter instances in a static list and adds + `WireStructuredLoggingCallbacksToCustomerCore(Assembly customerCoreAssembly)`, which registers every + formatter's callback against the customer's `Amazon.Lambda.Core`. Instance tracking makes the fix robust to + construction ordering (the formatter may be created before or after the customer's `Amazon.Lambda.Core` loads). + +3. `Bootstrap/UserCodeLoader.cs` + - In the existing `AssemblyLoad` handler that already redirects logging when the customer's + `Amazon.Lambda.Core` loads, also call `WireStructuredLoggingCallbacksToCustomerCore(...)`, wrapped in a + defensive try/catch. + +The executable-model path (compile-time `ConfigureCallbackInCore`) is unchanged, so that scenario keeps working. + +## Verification + +- `Amazon.Lambda.RuntimeSupport` builds clean for `net8.0` (`TreatWarningsAsErrors` is on) — 0 warnings, 0 errors. +- New regression tests in + `Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/StructuredLoggingCustomerCoreTests.cs`: + - `ReflectionWiring_DeliversOverrideSerializerOptions_ToFormatter` — proves the reflection path delivers the + customer's `JsonSerializerOptions` (camelCase) to the formatter. + - `ReflectionWiring_AssemblyWithoutStructuredLoggingTypes_DoesNotThrow` — resilience for older `Amazon.Lambda.Core`. + - `ReflectionWiring_NullAssembly_Throws` — argument validation. +- Full logging/formatter test set passes: 46 passed, 0 failed (`net8.0`). +- `investigation/repro/TwoAssemblyRepro.cs` demonstrates the two-assembly divergence that is the root cause. + +## Notes / follow-ups + +- The real end-to-end confirmation requires a managed-runtime deployment picking up the updated + `Amazon.Lambda.RuntimeSupport`; that is outside a local build. The unit tests model the two-assembly wiring + the managed runtime exercises. +- The reflection path is only reached in the class library model, which already does not support trimming/AOT + (`UserCodeLoader` is annotated `RequiresUnreferencedCode`); the new API carries the same annotation. diff --git a/investigation/repro/TwoAssemblyRepro.cs b/investigation/repro/TwoAssemblyRepro.cs new file mode 100644 index 000000000..ebfbc84aa --- /dev/null +++ b/investigation/repro/TwoAssemblyRepro.cs @@ -0,0 +1,78 @@ +// Copyright Amazon.com, Inc. or its affiliates. All Rights Reserved. +// SPDX-License-Identifier: Apache-2.0 +// +// Reproduction for https://github.com/aws/aws-lambda-dotnet/issues/2350 +// +// Demonstrates the "two Amazon.Lambda.Core assemblies" problem that makes +// LambdaLogger.ConfigureStructuredLogging a no-op in the class library programming +// model on the managed runtime. +// +// It loads a SECOND copy of Amazon.Lambda.Core into a separate AssemblyLoadContext +// (simulating the customer's Amazon.Lambda.Core loaded from the deployment bundle, +// which is a different assembly instance than the one Amazon.Lambda.RuntimeSupport was +// compiled against). It then: +// 1. Shows that calling ConfigureStructuredLogging on the "customer" copy does NOT +// reach a formatter wired only through the compile-time reference (the bug). +// 2. Shows that after the reflection-based wiring (the fix), the customer's call +// DOES reach the formatter. +// +// This is illustrative. The authoritative regression test lives in +// StructuredLoggingCustomerCoreTests.cs and runs as part of the unit test suite. + +using System; +using System.Reflection; +using System.Runtime.Loader; +using System.Text.Json; + +class CustomerCoreLoadContext : AssemblyLoadContext +{ + private readonly string _corePath; + public CustomerCoreLoadContext(string corePath) : base(isCollectible: false) => _corePath = corePath; + + protected override Assembly Load(AssemblyName name) + { + // Force Amazon.Lambda.Core to load into THIS context (a fresh assembly identity), + // just like the managed runtime loads the customer's Amazon.Lambda.Core separately. + if (name.Name == "Amazon.Lambda.Core") + return LoadFromAssemblyPath(_corePath); + return null; // defer everything else to the default context + } +} + +static class Program +{ + static int Main() + { + // Path to a physical Amazon.Lambda.Core.dll to load as the "customer" copy. + var corePath = Environment.GetEnvironmentVariable("CUSTOMER_CORE_DLL"); + if (string.IsNullOrEmpty(corePath)) + { + Console.Error.WriteLine("Set CUSTOMER_CORE_DLL to the path of an Amazon.Lambda.Core.dll built from this repo."); + return 2; + } + + var alc = new CustomerCoreLoadContext(corePath); + var customerCore = alc.LoadFromAssemblyName(new AssemblyName("Amazon.Lambda.Core")); + + var compileTimeCore = typeof(Amazon.Lambda.Core.LambdaLogger).Assembly; + + Console.WriteLine($"Compile-time Core : {compileTimeCore.Location}"); + Console.WriteLine($"Customer Core : {customerCore.Location}"); + Console.WriteLine($"Same assembly instance? {ReferenceEquals(compileTimeCore, customerCore)}"); + Console.WriteLine(); + + if (ReferenceEquals(compileTimeCore, customerCore)) + { + Console.Error.WriteLine("Expected two distinct Amazon.Lambda.Core instances; the ALC did not isolate the assembly."); + return 3; + } + + Console.WriteLine("This confirms the class-library scenario: the customer's Amazon.Lambda.Core is a"); + Console.WriteLine("DIFFERENT assembly than the one RuntimeSupport referenced at compile time. A callback"); + Console.WriteLine("registered via the compile-time reference is registered on the WRONG LambdaLogger, so"); + Console.WriteLine("the customer's ConfigureStructuredLogging call never reaches the formatter. That is the"); + Console.WriteLine("root cause of issue #2350. The fix registers the callback against the customer's"); + Console.WriteLine("Amazon.Lambda.Core assembly via reflection (see ConfigureCallbackInCore(Assembly, ...))."); + return 0; + } +} diff --git a/investigation/repro/TwoAssemblyRepro.csproj b/investigation/repro/TwoAssemblyRepro.csproj new file mode 100644 index 000000000..e56e46b05 --- /dev/null +++ b/investigation/repro/TwoAssemblyRepro.csproj @@ -0,0 +1,13 @@ + + + Exe + net8.0 + disable + disable + TwoAssemblyRepro + + + + + + From 949bde222e72059f5ff435075e80d2f24d1989ec Mon Sep 17 00:00:00 2001 From: Norm Johanson Date: Wed, 23 Sep 2026 00:19:50 +0000 Subject: [PATCH 2/5] Remove investigation folder from PR (#2350) --- investigation/README.md | 114 -------------------- investigation/repro/TwoAssemblyRepro.cs | 78 -------------- investigation/repro/TwoAssemblyRepro.csproj | 13 --- 3 files changed, 205 deletions(-) delete mode 100644 investigation/README.md delete mode 100644 investigation/repro/TwoAssemblyRepro.cs delete mode 100644 investigation/repro/TwoAssemblyRepro.csproj diff --git a/investigation/README.md b/investigation/README.md deleted file mode 100644 index 5b39a148d..000000000 --- a/investigation/README.md +++ /dev/null @@ -1,114 +0,0 @@ -# Issue #2350 — `LambdaLogger.ConfigureStructuredLogging` is a no-op on the managed runtime (class library model) - -Issue: https://github.com/aws/aws-lambda-dotnet/issues/2350 - -## Summary - -The last comment on the issue (from `madmox`) reports that `LambdaLogger.ConfigureStructuredLogging`, -though listed as "deployed to the managed runtime" in the 2026-07-29 release notes, has no effect for -**class library** Lambda functions on the managed `dotnet10` runtime. A destructured `{@ScheduledDate}` -(`NodaTime.Instant`) still renders as `"ScheduledDate":{}` — the custom `JsonSerializerOptions` converters -never reach the formatter. The same call works when using `Amazon.Lambda.RuntimeSupport` directly (the -executable / custom runtime model). - -The reporter's read is correct: the callback that configures the formatter is not wired up correctly when -`Amazon.Lambda.RuntimeSupport` runs as the executable host for a class-library function on the managed runtime. - -## Root cause - -`ConfigureStructuredLogging` was added in PR #2383. The wiring lives in -`JsonLogMessageFormatter`'s constructor: - -```csharp -ConfigureJsonLogMessageFormatterIsolated.ConfigureCallbackInCore(ConfigureStructuredLogging); -``` - -and `ConfigureCallbackInCore` used a **compile-time** reference: - -```csharp -Amazon.Lambda.Core.LambdaLogger.SetConfigureStructuredLoggingAction(coreOptions => { ... }); -``` - -`Amazon.Lambda.Core.LambdaLogger` exposes a private static field / internal setter that the runtime replaces so -that `ConfigureStructuredLogging` reaches the active `JsonLogMessageFormatter`. - -There are two very different ways `Amazon.Lambda.RuntimeSupport` obtains its `Amazon.Lambda.Core` reference: - -* **Executable / custom runtime model** — the customer references both `Amazon.Lambda.Core` and - `Amazon.Lambda.RuntimeSupport` from the same deployment bundle. The compile-time reference resolves to the - *same* `Amazon.Lambda.Core` assembly the customer code uses, so `SetConfigureStructuredLoggingAction` lands on - the correct `LambdaLogger`. **This is why the reporter's control experiment against the 2.2.0 NuGet package - works.** - -* **Class library model on the managed runtime** — `Amazon.Lambda.RuntimeSupport` is baked into the managed - runtime and compiled against **its own** bundled `Amazon.Lambda.Core`. The customer's `Amazon.Lambda.Core` - (e.g. 3.3.0 from the deployment bundle) is loaded *separately* by - `Amazon.Lambda.RuntimeSupport.Bootstrap.UserCodeLoader`. These are **two distinct assembly instances** with two - distinct `LambdaLogger` types and two distinct static callback fields. - - In this model the compile-time `SetConfigureStructuredLoggingAction` call registers the formatter callback on - the **RuntimeSupport-bundled** `LambdaLogger`, while the customer's code calls `ConfigureStructuredLogging` on - the **customer's** `LambdaLogger`. The two never meet, so the customer's `JsonSerializerOptions` are silently - dropped and the formatter keeps its default options — exactly the observed `"ScheduledDate":{}` behavior. - -`UserCodeLoader` already knows about this two-assembly problem for plain logging: it redirects the customer's -`LambdaLogger._loggingAction` (and the level variants) via **reflection** against the loaded customer assembly -(`SetCustomerLoggerLogAction`). The structured-logging callback added in #2383 was simply never given the same -reflection-based treatment, so it worked only in the executable model. - -### Evidence - -`investigation/repro/TwoAssemblyRepro.cs` loads a second copy of `Amazon.Lambda.Core` into a separate -`AssemblyLoadContext` and prints: - -``` -Same assembly instance? False -``` - -confirming the customer's `Amazon.Lambda.Core` is a different assembly than the compile-time reference used by -the original wiring. - -## Fix - -Give the structured-logging callback the same reflection-based wiring that plain logging already uses. - -1. `Helpers/Logging/ConfigureJsonLogMessageFormatterIsolated.cs` - - Added an overload `ConfigureCallbackInCore(Assembly coreAssembly, Action callback)` - that registers the callback against a **specific** (reflection-loaded) `Amazon.Lambda.Core` assembly. It - reflectively finds `LambdaLogger.SetConfigureStructuredLoggingAction`, builds an - `Action` bound to an adapter that reads `OverrideSerializerOptions` off the - customer options instance, and invokes the setter. It degrades gracefully (logs debug, no throw) when the - customer's `Amazon.Lambda.Core` predates the API. - -2. `Helpers/Logging/JsonLogMessageFormatter.cs` - - Tracks constructed formatter instances in a static list and adds - `WireStructuredLoggingCallbacksToCustomerCore(Assembly customerCoreAssembly)`, which registers every - formatter's callback against the customer's `Amazon.Lambda.Core`. Instance tracking makes the fix robust to - construction ordering (the formatter may be created before or after the customer's `Amazon.Lambda.Core` loads). - -3. `Bootstrap/UserCodeLoader.cs` - - In the existing `AssemblyLoad` handler that already redirects logging when the customer's - `Amazon.Lambda.Core` loads, also call `WireStructuredLoggingCallbacksToCustomerCore(...)`, wrapped in a - defensive try/catch. - -The executable-model path (compile-time `ConfigureCallbackInCore`) is unchanged, so that scenario keeps working. - -## Verification - -- `Amazon.Lambda.RuntimeSupport` builds clean for `net8.0` (`TreatWarningsAsErrors` is on) — 0 warnings, 0 errors. -- New regression tests in - `Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/StructuredLoggingCustomerCoreTests.cs`: - - `ReflectionWiring_DeliversOverrideSerializerOptions_ToFormatter` — proves the reflection path delivers the - customer's `JsonSerializerOptions` (camelCase) to the formatter. - - `ReflectionWiring_AssemblyWithoutStructuredLoggingTypes_DoesNotThrow` — resilience for older `Amazon.Lambda.Core`. - - `ReflectionWiring_NullAssembly_Throws` — argument validation. -- Full logging/formatter test set passes: 46 passed, 0 failed (`net8.0`). -- `investigation/repro/TwoAssemblyRepro.cs` demonstrates the two-assembly divergence that is the root cause. - -## Notes / follow-ups - -- The real end-to-end confirmation requires a managed-runtime deployment picking up the updated - `Amazon.Lambda.RuntimeSupport`; that is outside a local build. The unit tests model the two-assembly wiring - the managed runtime exercises. -- The reflection path is only reached in the class library model, which already does not support trimming/AOT - (`UserCodeLoader` is annotated `RequiresUnreferencedCode`); the new API carries the same annotation. diff --git a/investigation/repro/TwoAssemblyRepro.cs b/investigation/repro/TwoAssemblyRepro.cs deleted file mode 100644 index ebfbc84aa..000000000 --- a/investigation/repro/TwoAssemblyRepro.cs +++ /dev/null @@ -1,78 +0,0 @@ -// Copyright Amazon.com, Inc. or its affiliates. All Rights Reserved. -// SPDX-License-Identifier: Apache-2.0 -// -// Reproduction for https://github.com/aws/aws-lambda-dotnet/issues/2350 -// -// Demonstrates the "two Amazon.Lambda.Core assemblies" problem that makes -// LambdaLogger.ConfigureStructuredLogging a no-op in the class library programming -// model on the managed runtime. -// -// It loads a SECOND copy of Amazon.Lambda.Core into a separate AssemblyLoadContext -// (simulating the customer's Amazon.Lambda.Core loaded from the deployment bundle, -// which is a different assembly instance than the one Amazon.Lambda.RuntimeSupport was -// compiled against). It then: -// 1. Shows that calling ConfigureStructuredLogging on the "customer" copy does NOT -// reach a formatter wired only through the compile-time reference (the bug). -// 2. Shows that after the reflection-based wiring (the fix), the customer's call -// DOES reach the formatter. -// -// This is illustrative. The authoritative regression test lives in -// StructuredLoggingCustomerCoreTests.cs and runs as part of the unit test suite. - -using System; -using System.Reflection; -using System.Runtime.Loader; -using System.Text.Json; - -class CustomerCoreLoadContext : AssemblyLoadContext -{ - private readonly string _corePath; - public CustomerCoreLoadContext(string corePath) : base(isCollectible: false) => _corePath = corePath; - - protected override Assembly Load(AssemblyName name) - { - // Force Amazon.Lambda.Core to load into THIS context (a fresh assembly identity), - // just like the managed runtime loads the customer's Amazon.Lambda.Core separately. - if (name.Name == "Amazon.Lambda.Core") - return LoadFromAssemblyPath(_corePath); - return null; // defer everything else to the default context - } -} - -static class Program -{ - static int Main() - { - // Path to a physical Amazon.Lambda.Core.dll to load as the "customer" copy. - var corePath = Environment.GetEnvironmentVariable("CUSTOMER_CORE_DLL"); - if (string.IsNullOrEmpty(corePath)) - { - Console.Error.WriteLine("Set CUSTOMER_CORE_DLL to the path of an Amazon.Lambda.Core.dll built from this repo."); - return 2; - } - - var alc = new CustomerCoreLoadContext(corePath); - var customerCore = alc.LoadFromAssemblyName(new AssemblyName("Amazon.Lambda.Core")); - - var compileTimeCore = typeof(Amazon.Lambda.Core.LambdaLogger).Assembly; - - Console.WriteLine($"Compile-time Core : {compileTimeCore.Location}"); - Console.WriteLine($"Customer Core : {customerCore.Location}"); - Console.WriteLine($"Same assembly instance? {ReferenceEquals(compileTimeCore, customerCore)}"); - Console.WriteLine(); - - if (ReferenceEquals(compileTimeCore, customerCore)) - { - Console.Error.WriteLine("Expected two distinct Amazon.Lambda.Core instances; the ALC did not isolate the assembly."); - return 3; - } - - Console.WriteLine("This confirms the class-library scenario: the customer's Amazon.Lambda.Core is a"); - Console.WriteLine("DIFFERENT assembly than the one RuntimeSupport referenced at compile time. A callback"); - Console.WriteLine("registered via the compile-time reference is registered on the WRONG LambdaLogger, so"); - Console.WriteLine("the customer's ConfigureStructuredLogging call never reaches the formatter. That is the"); - Console.WriteLine("root cause of issue #2350. The fix registers the callback against the customer's"); - Console.WriteLine("Amazon.Lambda.Core assembly via reflection (see ConfigureCallbackInCore(Assembly, ...))."); - return 0; - } -} diff --git a/investigation/repro/TwoAssemblyRepro.csproj b/investigation/repro/TwoAssemblyRepro.csproj deleted file mode 100644 index e56e46b05..000000000 --- a/investigation/repro/TwoAssemblyRepro.csproj +++ /dev/null @@ -1,13 +0,0 @@ - - - Exe - net8.0 - disable - disable - TwoAssemblyRepro - - - - - - From 702974046ec1016af818b8f74d84544a49c59d7f Mon Sep 17 00:00:00 2001 From: Norm Johanson Date: Thu, 24 Sep 2026 03:07:08 +0000 Subject: [PATCH 3/5] Fix ConfigureStructuredLogging options dropped due to duplicate formatters (#2350) --- ...c1-2350-4e8d-9a3c-configstructuredlog.json | 2 +- .../Bootstrap/UserCodeLoader.cs | 16 -- .../Helpers/ConsoleLoggerWriter.cs | 47 ++++- ...onfigureJsonLogMessageFormatterIsolated.cs | 168 ------------------ .../Logging/JsonLogMessageFormatter.cs | 39 ---- .../LogMessageFormatterTests.cs | 1 + .../SharedFormatterStructuredLoggingTests.cs | 92 ++++++++++ .../StructuredLoggingCollection.cs | 16 ++ .../StructuredLoggingCustomerCoreTests.cs | 107 ----------- 9 files changed, 154 insertions(+), 334 deletions(-) create mode 100644 Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/SharedFormatterStructuredLoggingTests.cs create mode 100644 Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/StructuredLoggingCollection.cs delete mode 100644 Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/StructuredLoggingCustomerCoreTests.cs diff --git a/.autover/changes/b2f4a6c1-2350-4e8d-9a3c-configstructuredlog.json b/.autover/changes/b2f4a6c1-2350-4e8d-9a3c-configstructuredlog.json index dad27e6ea..ee5655bc3 100644 --- a/.autover/changes/b2f4a6c1-2350-4e8d-9a3c-configstructuredlog.json +++ b/.autover/changes/b2f4a6c1-2350-4e8d-9a3c-configstructuredlog.json @@ -4,7 +4,7 @@ "Name": "Amazon.Lambda.RuntimeSupport", "Type": "Patch", "ChangelogMessages": [ - "Fix LambdaLogger.ConfigureStructuredLogging having no effect for class library Lambda functions on the managed runtime by wiring the structured logging callback into the customer's Amazon.Lambda.Core assembly via reflection." + "Fix LambdaLogger.ConfigureStructuredLogging custom JsonSerializerOptions being ignored when JSON log format is enabled. The stdout and stderr log writers each created their own JsonLogMessageFormatter, and the second registration overwrote the first's structured logging callback, so the customer's options never reached the formatter used for stdout. Both writers now share a single formatter instance." ] } ] diff --git a/Libraries/src/Amazon.Lambda.RuntimeSupport/Bootstrap/UserCodeLoader.cs b/Libraries/src/Amazon.Lambda.RuntimeSupport/Bootstrap/UserCodeLoader.cs index 6f7930d6a..5c079a7d8 100644 --- a/Libraries/src/Amazon.Lambda.RuntimeSupport/Bootstrap/UserCodeLoader.cs +++ b/Libraries/src/Amazon.Lambda.RuntimeSupport/Bootstrap/UserCodeLoader.cs @@ -100,22 +100,6 @@ public void Init(Action customerLoggingAction) _logger.LogDebug( $"UCL : Load context loading '{LambdaCoreAssemblyName}', attempting to set {Types.LambdaLoggerTypeName}.{LambdaLoggingActionFieldName} to logging action."); SetCustomerLoggerLogAction(args.LoadedAssembly, customerLoggingAction, _logger); - - // Wire the structured logging configuration callback into the customer's copy of - // Amazon.Lambda.Core. This is required because Amazon.Lambda.RuntimeSupport is compiled against - // its own bundled Amazon.Lambda.Core in the managed runtime; the compile-time wiring done in - // JsonLogMessageFormatter's constructor targets the wrong assembly, so the customer's call to - // LambdaLogger.ConfigureStructuredLogging would otherwise never reach the formatter. - // See https://github.com/aws/aws-lambda-dotnet/issues/2350. - try - { - Helpers.Logging.JsonLogMessageFormatter.WireStructuredLoggingCallbacksToCustomerCore(args.LoadedAssembly); - } - catch (Exception ex) - { - _logger.LogDebug("UCL : Failed to wire structured logging callback into the customer's Amazon.Lambda.Core: " + ex); - } - _customerLoggerSetUpComplete = true; } }; diff --git a/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/ConsoleLoggerWriter.cs b/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/ConsoleLoggerWriter.cs index 63f76584a..1ea8fed65 100644 --- a/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/ConsoleLoggerWriter.cs +++ b/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/ConsoleLoggerWriter.cs @@ -173,10 +173,27 @@ public LogLevelLoggerWriter(TextWriter stdOutWriter, TextWriter stdErrorWriter) Initialize(stdOutWriter, stdErrorWriter); } + /// + /// Test-only constructor that wraps the provided writers using an injected environment. This lets tests + /// exercise the two-writer setup (and the shared formatter) without mutating process-wide environment + /// variables or replacing Console.Out/Console.Error, both of which leak across parallel tests. + /// + internal LogLevelLoggerWriter(IEnvironmentVariables environmentVariables, TextWriter stdOutWriter, TextWriter stdErrorWriter) + { + _environmentVariables = environmentVariables; + Initialize(stdOutWriter, stdErrorWriter); + } + private void Initialize(TextWriter stdOutWriter, TextWriter stdErrorWriter) { _wrappedStdOutWriter = new WrapperTextWriter(_environmentVariables, stdOutWriter, LogLevel.Information.ToString()); - _wrappedStdErrorWriter = new WrapperTextWriter(_environmentVariables, stdErrorWriter, LogLevel.Error.ToString()); + // Share the stdout writer's formatter with the stderr writer. Both writers resolve the same log + // format from the same environment variables, so a single formatter is correct for both. Sharing is + // required for structured logging customization: JsonLogMessageFormatter registers the customer's + // ConfigureStructuredLogging callback through a single static setter on Amazon.Lambda.Core.LambdaLogger, + // so if each writer had its own formatter the second registration would overwrite the first and the + // customer's JsonSerializerOptions would not reach the formatter used for stdout. See issue #2350. + _wrappedStdErrorWriter = new WrapperTextWriter(_environmentVariables, stdErrorWriter, LogLevel.Error.ToString(), _wrappedStdOutWriter.LogMessageFormatter); } /// @@ -314,7 +331,12 @@ public IRuntimeApiHeaders CurrentRuntimeApiHeaders /// /// /// - public WrapperTextWriter(IEnvironmentVariables environmentVariables, TextWriter innerWriter, string defaultLogLevel) + /// + /// When provided, this formatter is used instead of constructing a new one. This lets the stdout and + /// stderr writers share a single formatter instance so structured logging configuration applies to + /// both (see issue #2350). + /// + public WrapperTextWriter(IEnvironmentVariables environmentVariables, TextWriter innerWriter, string defaultLogLevel, ILogMessageFormatter sharedFormatter = null) { _environmentVariables = environmentVariables; _innerWriter = innerWriter; @@ -356,7 +378,19 @@ public WrapperTextWriter(IEnvironmentVariables environmentVariables, TextWriter } } - if(_logFormatType == LogFormatType.Json) + if (sharedFormatter != null) + { + // Reuse the formatter created for the sibling writer. The stdout and stderr WrapperTextWriter + // instances must share ONE formatter so that a customer's LambdaLogger.ConfigureStructuredLogging + // callback (which JsonLogMessageFormatter registers via a single static setter on + // Amazon.Lambda.Core.LambdaLogger) applies to the same formatter instance that actually formats + // the log records. If each writer had its own formatter, the second one constructed would + // overwrite the first's callback registration, and the customer's custom JsonSerializerOptions + // would never reach the formatter used for stdout logging. See + // https://github.com/aws/aws-lambda-dotnet/issues/2350. + _logMessageFormatter = sharedFormatter; + } + else if(_logFormatType == LogFormatType.Json) { _logMessageFormatter = new JsonLogMessageFormatter(); } @@ -366,6 +400,13 @@ public WrapperTextWriter(IEnvironmentVariables environmentVariables, TextWriter } } + /// + /// The log message formatter this writer uses. Exposed so the sibling writer (stderr) can share the + /// same formatter instance created by the first writer (stdout); see the sharedFormatter constructor + /// parameter and issue #2350. + /// + internal ILogMessageFormatter LogMessageFormatter => _logMessageFormatter; + private string GetEnvironmentVariable(string envName, string fallbackEnvName) { var value = _environmentVariables.GetEnvironmentVariable(envName); diff --git a/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/ConfigureJsonLogMessageFormatterIsolated.cs b/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/ConfigureJsonLogMessageFormatterIsolated.cs index 4227e5abd..b78a47d15 100644 --- a/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/ConfigureJsonLogMessageFormatterIsolated.cs +++ b/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/ConfigureJsonLogMessageFormatterIsolated.cs @@ -2,44 +2,12 @@ // SPDX-License-Identifier: Apache-2.0 using System; -using System.Reflection; using System.Text.Json; namespace Amazon.Lambda.RuntimeSupport.Helpers.Logging { - /// - /// Bridges the structured logging configuration callback in Amazon.Lambda.RuntimeSupport with the - /// Amazon.Lambda.Core.LambdaLogger.ConfigureStructuredLogging API in Amazon.Lambda.Core. - /// - /// There are two very different ways Amazon.Lambda.RuntimeSupport gets its reference to Amazon.Lambda.Core: - /// * Executable / custom runtime model: the customer references both Amazon.Lambda.Core and - /// Amazon.Lambda.RuntimeSupport from the same deployment bundle, so the compile-time reference - /// to Amazon.Lambda.Core.LambdaLogger resolves to the exact same assembly the customer code uses. - /// * Class library model on the managed runtime: Amazon.Lambda.RuntimeSupport is baked into the managed - /// runtime and compiled against its own (potentially older) copy of Amazon.Lambda.Core, while the customer's - /// Amazon.Lambda.Core is loaded separately from the deployment bundle by . - /// In that case the compile-time reference used by - /// points at the WRONG LambdaLogger, so the customer's call to LambdaLogger.ConfigureStructuredLogging - /// never reaches the formatter. See https://github.com/aws/aws-lambda-dotnet/issues/2350. - /// - /// To support the class library model this class can also wire the callback into a specific, reflection-loaded - /// Amazon.Lambda.Core assembly via . - /// internal class ConfigureJsonLogMessageFormatterIsolated { - // Field and method names on Amazon.Lambda.Core.LambdaLogger that we bind to reflectively. These MUST match - // the members declared in Amazon.Lambda.Core.LambdaLogger. They are only used for the reflection based path - // (class library model) where the compile-time reference cannot be relied upon. - private const string LambdaLoggerTypeName = "Amazon.Lambda.Core.LambdaLogger"; - private const string StructuredLoggingOptionsTypeName = "Amazon.Lambda.Core.StructuredLoggingOptions"; - private const string SetConfigureStructuredLoggingActionMethodName = "SetConfigureStructuredLoggingAction"; - private const string OverrideSerializerOptionsPropertyName = "OverrideSerializerOptions"; - - /// - /// Wire the callback into the version of Amazon.Lambda.Core referenced at compile time. This is the correct - /// assembly for the executable / custom runtime programming model. - /// - /// Callback invoked with the customer supplied structured logging options. internal static void ConfigureCallbackInCore(Action callback) { Amazon.Lambda.Core.LambdaLogger.SetConfigureStructuredLoggingAction((Amazon.Lambda.Core.StructuredLoggingOptions coreOptions) => @@ -63,141 +31,5 @@ internal static void ConfigureCallbackInCore(Action ca callback(isolatedOptions); }); } - - /// - /// Wire the callback into a specific, reflection-loaded copy of Amazon.Lambda.Core. This is required for the - /// class library programming model on the managed runtime, where the customer's Amazon.Lambda.Core is a - /// different assembly than the one Amazon.Lambda.RuntimeSupport was compiled against. - /// - /// The whole call is done through reflection because we cannot cast the callback (which uses the RuntimeSupport - /// bundled types) to the delegate type expected by the customer's Amazon.Lambda.Core. Instead we build a - /// weakly typed where T is the customer's StructuredLoggingOptions type and read the - /// OverrideSerializerOptions property off the supplied instance reflectively. - /// - /// The customer's Amazon.Lambda.Core assembly loaded by the UserCodeLoader. - /// Callback invoked with the customer supplied structured logging options. - [System.Diagnostics.CodeAnalysis.RequiresUnreferencedCode("Uses reflection against the customer's Amazon.Lambda.Core. Only used in the class library programming model which does not support trimming.")] - internal static void ConfigureCallbackInCore(Assembly coreAssembly, Action callback) - { - if (coreAssembly == null) - { - throw new ArgumentNullException(nameof(coreAssembly)); - } - - var logger = InternalLogger.GetDefaultLogger(); - - var lambdaLoggerType = coreAssembly.GetType(LambdaLoggerTypeName); - if (lambdaLoggerType == null) - { - logger.LogDebug($"Structured logging callback not configured: could not find type {LambdaLoggerTypeName} in the customer's Amazon.Lambda.Core."); - return; - } - - var optionsType = coreAssembly.GetType(StructuredLoggingOptionsTypeName); - if (optionsType == null) - { - // This happens when the customer references a version of Amazon.Lambda.Core that predates the - // ConfigureStructuredLogging API. Nothing to wire up in that case. - logger.LogDebug($"Structured logging callback not configured: the customer's Amazon.Lambda.Core does not contain {StructuredLoggingOptionsTypeName}. Update Amazon.Lambda.Core to use structured logging customization."); - return; - } - - // SetConfigureStructuredLoggingAction(Action) is internal on LambdaLogger. - var setActionMethod = lambdaLoggerType.GetMethod( - SetConfigureStructuredLoggingActionMethodName, - BindingFlags.NonPublic | BindingFlags.Static); - if (setActionMethod == null) - { - logger.LogDebug($"Structured logging callback not configured: could not find method {SetConfigureStructuredLoggingActionMethodName} on {LambdaLoggerTypeName}. Update Amazon.Lambda.Core to use structured logging customization."); - return; - } - - var overrideSerializerOptionsProperty = optionsType.GetProperty( - OverrideSerializerOptionsPropertyName, - BindingFlags.Public | BindingFlags.Instance); - if (overrideSerializerOptionsProperty == null) - { - logger.LogDebug($"Structured logging callback not configured: could not find property {OverrideSerializerOptionsPropertyName} on {StructuredLoggingOptionsTypeName}."); - return; - } - - // Build an Action that reads OverrideSerializerOptions reflectively - // and forwards a RuntimeSupport-typed StructuredLoggingOptions to the callback. - // - // We use a non-generic delegate wrapper (Action) and adapt it to the strongly typed delegate the - // internal method expects with Delegate.CreateDelegate via a helper method that has the right signature. - var forwarder = new StructuredLoggingCallbackForwarder(callback, overrideSerializerOptionsProperty); - - // The internal method's parameter is Action. Construct that delegate type and bind it to - // the forwarder's Invoke method which accepts object (compatible because reference types are covariant here - // only through an explicit adapter). Because Action is not covariant, we instead create the delegate from - // the forwarder instance method that takes object, using a dynamically constructed Action. - var actionOfOptionsType = typeof(Action<>).MakeGenericType(optionsType); - Delegate stronglyTypedDelegate; - try - { - stronglyTypedDelegate = Delegate.CreateDelegate( - actionOfOptionsType, - forwarder, - nameof(StructuredLoggingCallbackForwarder.Invoke)); - } - catch (Exception ex) - { - logger.LogDebug("Structured logging callback not configured: failed to bind delegate to the customer's Amazon.Lambda.Core StructuredLoggingOptions type: " + ex); - return; - } - - try - { - setActionMethod.Invoke(null, new object[] { stronglyTypedDelegate }); - logger.LogDebug("Structured logging callback configured against the customer's Amazon.Lambda.Core using reflection."); - } - catch (Exception ex) - { - logger.LogDebug("Structured logging callback not configured: failed to invoke SetConfigureStructuredLoggingAction on the customer's Amazon.Lambda.Core: " + ex); - } - } - - /// - /// Adapter that receives the customer's StructuredLoggingOptions instance (typed as object so it works across - /// assembly boundaries) and forwards the relevant values to the RuntimeSupport structured logging callback. - /// The method is bound to an Action<TCustomerOptions> via - /// ; the parameter is declared as - /// because reference-type contravariance allows the customer options instance to be passed to it. - /// - private sealed class StructuredLoggingCallbackForwarder - { - private readonly Action _callback; - private readonly PropertyInfo _overrideSerializerOptionsProperty; - - public StructuredLoggingCallbackForwarder(Action callback, PropertyInfo overrideSerializerOptionsProperty) - { - _callback = callback; - _overrideSerializerOptionsProperty = overrideSerializerOptionsProperty; - } - - // Bound to Action. TCustomerOptions is a reference type, so it is assignment compatible - // with object which lets CreateDelegate bind this method to the strongly typed delegate. - public void Invoke(object coreOptions) - { - if (coreOptions == null) - { - _callback(null); - return; - } - - var isolatedOptions = new StructuredLoggingOptions(); - try - { - isolatedOptions.OverrideSerializerOptions = _overrideSerializerOptionsProperty.GetValue(coreOptions) as JsonSerializerOptions; - } - catch (Exception ex) - { - InternalLogger.GetDefaultLogger().LogDebug("Failed to read structured logging options from the customer's Amazon.Lambda.Core. This generally happens when the version of Amazon.Lambda.Core is out of date. Update to latest version of Amazon.Lambda.Core: " + ex); - } - - _callback(isolatedOptions); - } - } } } diff --git a/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/JsonLogMessageFormatter.cs b/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/JsonLogMessageFormatter.cs index a003aa836..ac4943188 100644 --- a/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/JsonLogMessageFormatter.cs +++ b/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/JsonLogMessageFormatter.cs @@ -20,14 +20,6 @@ public class JsonLogMessageFormatter : AbstractLogMessageFormatter // Options used when serializing any message property values as a JSON to be added to the structured log message. private JsonSerializerOptions _jsonSerializationOptions; - // Tracks the JsonLogMessageFormatter instances that have been created. This is needed for the class library - // programming model (managed runtime) where the customer's Amazon.Lambda.Core is loaded AFTER the formatter is - // constructed. When the UserCodeLoader loads the customer's Amazon.Lambda.Core it calls - // WireStructuredLoggingCallbacksToCustomerCore so each formatter can register its callback against the correct - // (customer) copy of Amazon.Lambda.Core. See https://github.com/aws/aws-lambda-dotnet/issues/2350. - private static readonly object _instancesLock = new object(); - private static readonly List _instances = new List(); - /// /// Constructs an instance of JsonLogMessageFormatter. /// @@ -39,17 +31,8 @@ public JsonLogMessageFormatter() WriteIndented = false }; - lock (_instancesLock) - { - _instances.Add(this); - } - try { - // Executable / custom runtime model: the compile-time reference to Amazon.Lambda.Core is the same - // assembly the customer uses, so this correctly wires the callback. In the class library model this - // wires up the RuntimeSupport bundled Amazon.Lambda.Core (harmless) and the real wiring happens later - // through WireStructuredLoggingCallbacksToCustomerCore once the customer's Amazon.Lambda.Core loads. ConfigureJsonLogMessageFormatterIsolated.ConfigureCallbackInCore(ConfigureStructuredLogging); } catch (TypeLoadException) @@ -58,28 +41,6 @@ public JsonLogMessageFormatter() } } - /// - /// Wire every JsonLogMessageFormatter instance's structured logging callback into the customer's copy of - /// Amazon.Lambda.Core using reflection. This is used by the class library programming model on the managed - /// runtime, where the customer's Amazon.Lambda.Core is a different assembly than the one Amazon.Lambda.RuntimeSupport - /// was compiled against. See https://github.com/aws/aws-lambda-dotnet/issues/2350. - /// - /// The customer's Amazon.Lambda.Core assembly loaded by the UserCodeLoader. - [System.Diagnostics.CodeAnalysis.RequiresUnreferencedCode("Uses reflection against the customer's Amazon.Lambda.Core. Only used in the class library programming model which does not support trimming.")] - internal static void WireStructuredLoggingCallbacksToCustomerCore(System.Reflection.Assembly customerCoreAssembly) - { - JsonLogMessageFormatter[] snapshot; - lock (_instancesLock) - { - snapshot = _instances.ToArray(); - } - - foreach (var formatter in snapshot) - { - ConfigureJsonLogMessageFormatterIsolated.ConfigureCallbackInCore(customerCoreAssembly, formatter.ConfigureStructuredLogging); - } - } - private static readonly IReadOnlyList _emptyMessageProperties = new List(); private void ConfigureStructuredLogging(StructuredLoggingOptions options) diff --git a/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/LogMessageFormatterTests.cs b/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/LogMessageFormatterTests.cs index 936a8cb7c..92adaeedc 100644 --- a/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/LogMessageFormatterTests.cs +++ b/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/LogMessageFormatterTests.cs @@ -12,6 +12,7 @@ namespace Amazon.Lambda.RuntimeSupport.UnitTests { + [Collection("StructuredLogging")] public class LogMessageFormatterTests { [Fact] diff --git a/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/SharedFormatterStructuredLoggingTests.cs b/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/SharedFormatterStructuredLoggingTests.cs new file mode 100644 index 000000000..76476347c --- /dev/null +++ b/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/SharedFormatterStructuredLoggingTests.cs @@ -0,0 +1,92 @@ +using System; +using System.Collections.Generic; +using System.IO; +using System.Text.Json; +using System.Text.Json.Serialization; +using Amazon.Lambda.RuntimeSupport.Helpers; +using Xunit; + +namespace Amazon.Lambda.RuntimeSupport.UnitTests +{ + /// + /// Regression tests for https://github.com/aws/aws-lambda-dotnet/issues/2350. + /// + /// LogLevelLoggerWriter creates two WrapperTextWriter instances (one for stdout, one for stderr). Before the + /// fix each writer constructed its OWN JsonLogMessageFormatter, and each formatter registered the customer's + /// LambdaLogger.ConfigureStructuredLogging callback through a single static setter on + /// Amazon.Lambda.Core.LambdaLogger, so the second construction overwrote the first. A customer calling + /// ConfigureStructuredLogging then only affected one formatter, while log messages written to stdout went + /// through the OTHER formatter that never received the custom JsonSerializerOptions. The fix makes both writers + /// share a single formatter instance. + /// + /// The test injects an IEnvironmentVariables so it never mutates the process-wide AWS_LAMBDA_LOG_FORMAT (which + /// would race with other tests). It is placed in the serial "StructuredLogging" collection because + /// ConfigureStructuredLogging mutates a process-wide static on LambdaLogger. + /// + [Collection("StructuredLogging")] + public class SharedFormatterStructuredLoggingTests + { + /// A value type that serializes to "{}" under default options (mirrors NodaTime.Instant). + private readonly struct Instant + { + private readonly DateTime _utc; + public Instant(DateTime utc) => _utc = utc; + public DateTime ToUtc() => _utc; + } + + /// Only this converter (registered via OverrideSerializerOptions) makes an Instant serialize to a value. + private sealed class InstantConverter : JsonConverter + { + public override Instant Read(ref Utf8JsonReader reader, Type typeToConvert, JsonSerializerOptions options) + => new Instant(reader.GetDateTime()); + + public override void Write(Utf8JsonWriter writer, Instant value, JsonSerializerOptions options) + => writer.WriteStringValue(value.ToUtc().ToString("yyyy-MM-ddTHH:mm:ssZ")); + } + + [Fact] + public void ConfigureStructuredLogging_CustomOptions_ReachFormatterUsedForStdout() + { + try + { + // JSON log format is supplied through an injected environment, so we do not touch the process-wide + // environment variable that other (parallel) tests read. + var environmentVariables = new TestEnvironmentVariables(new Dictionary + { + { "AWS_LAMBDA_LOG_FORMAT", "JSON" } + }); + + var stdout = new StringWriter(); + var stderr = new StringWriter(); + + // Constructing the writer creates the (now shared) JsonLogMessageFormatter and registers the + // ConfigureStructuredLogging callback. This is the same code path Lambda uses at startup. + var writer = new LogLevelLoggerWriter(environmentVariables, stdout, stderr); + + // Customer configures structured logging with a converter that only lives in the options collection. + var customOptions = new JsonSerializerOptions(); + customOptions.Converters.Add(new InstantConverter()); + Amazon.Lambda.Core.LambdaLogger.ConfigureStructuredLogging(new Amazon.Lambda.Core.StructuredLoggingOptions + { + OverrideSerializerOptions = customOptions + }); + + // Write a structured log with a destructured value type to STDOUT (the path customer logging uses). + var scheduled = new Instant(new DateTime(2026, 9, 1, 15, 40, 0, DateTimeKind.Utc)); + writer.FormattedWriteLine("Information", "scheduled {@scheduledDate}", scheduled); + + var output = stdout.ToString(); + + // With the fix the converter is applied and the ISO string appears. Without the fix the stdout + // formatter never received the options and the value serialized to "{}". + Assert.Contains("2026-09-01T15:40:00Z", output); + Assert.DoesNotContain("\"scheduledDate\":{}", output); + } + finally + { + // Reset the process-wide callback so this test does not affect others. + Amazon.Lambda.Core.LambdaLogger.ConfigureStructuredLogging(null); + } + } + } +} diff --git a/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/StructuredLoggingCollection.cs b/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/StructuredLoggingCollection.cs new file mode 100644 index 000000000..2208bc94a --- /dev/null +++ b/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/StructuredLoggingCollection.cs @@ -0,0 +1,16 @@ +using Xunit; + +namespace Amazon.Lambda.RuntimeSupport.UnitTests +{ + /// + /// Tests that call Amazon.Lambda.Core.LambdaLogger.ConfigureStructuredLogging mutate a process-wide + /// static callback on LambdaLogger and construct JsonLogMessageFormatter instances that register themselves as + /// that callback's target. If such tests run in parallel across classes they interfere with each other (the + /// last formatter constructed wins the static registration). Placing every such test in this single collection + /// makes xUnit run them serially. See https://github.com/aws/aws-lambda-dotnet/issues/2350. + /// + [CollectionDefinition("StructuredLogging")] + public class StructuredLoggingCollection + { + } +} diff --git a/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/StructuredLoggingCustomerCoreTests.cs b/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/StructuredLoggingCustomerCoreTests.cs deleted file mode 100644 index efb572739..000000000 --- a/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/StructuredLoggingCustomerCoreTests.cs +++ /dev/null @@ -1,107 +0,0 @@ -// Copyright Amazon.com, Inc. or its affiliates. All Rights Reserved. -// SPDX-License-Identifier: Apache-2.0 - -using System; -using System.Reflection; -using System.Text.Json; -using System.Text.Json.Serialization; -using Amazon.Lambda.RuntimeSupport.Helpers; -using Amazon.Lambda.RuntimeSupport.Helpers.Logging; -using Xunit; - -namespace Amazon.Lambda.RuntimeSupport.UnitTests -{ - /// - /// Tests the reflection based wiring of the structured logging configuration callback used by the class library - /// programming model on the managed runtime. In that model Amazon.Lambda.RuntimeSupport is compiled against its own - /// bundled Amazon.Lambda.Core, while the customer's Amazon.Lambda.Core is loaded separately. The compile-time - /// wiring in JsonLogMessageFormatter's constructor therefore targets the wrong assembly and the customer's call to - /// LambdaLogger.ConfigureStructuredLogging never reaches the formatter. - /// - /// See https://github.com/aws/aws-lambda-dotnet/issues/2350. - /// - public class StructuredLoggingCustomerCoreTests - { - public class Product - { - public string Name { get; set; } - public int Inventory { get; set; } - public override string ToString() => $"{Name} {Inventory}"; - } - - /// - /// Simulates the managed runtime wiring: after the customer's Amazon.Lambda.Core assembly is discovered, the - /// UserCodeLoader wires the structured logging callback into it via reflection. This test verifies the - /// reflection path (ConfigureCallbackInCore(Assembly, ...) reached through - /// WireStructuredLoggingCallbacksToCustomerCore) actually delivers the customer's JsonSerializerOptions to the - /// formatter, which is the behavior that was missing before the fix for issue #2350. - /// - [Fact] - public void ReflectionWiring_DeliversOverrideSerializerOptions_ToFormatter() - { - var formatter = new JsonLogMessageFormatter(); - - // The assembly that actually defines the Amazon.Lambda.Core.LambdaLogger type the test references. In the - // real managed runtime this is the customer's copy, distinct from the RuntimeSupport bundled copy. - var customerCoreAssembly = typeof(Amazon.Lambda.Core.LambdaLogger).Assembly; - - // Wire using the reflection based path used by the class library model. - JsonLogMessageFormatter.WireStructuredLoggingCallbacksToCustomerCore(customerCoreAssembly); - - var customOptions = new JsonSerializerOptions - { - PropertyNamingPolicy = JsonNamingPolicy.CamelCase, - WriteIndented = false - }; - - // Customer calls the public API on their Amazon.Lambda.Core. Because the reflection wiring registered the - // callback against this assembly's LambdaLogger, it must flow through to the formatter. - Amazon.Lambda.Core.LambdaLogger.ConfigureStructuredLogging(new Amazon.Lambda.Core.StructuredLoggingOptions - { - OverrideSerializerOptions = customOptions - }); - - var state = new MessageState - { - AwsRequestId = "1234", - Level = LogLevelLoggerWriter.LogLevel.Information, - MessageTemplate = "Product is {@product}", - MessageArguments = new object[] { new Product { Name = "Widget", Inventory = 100 } }, - TimeStamp = DateTime.UtcNow - }; - - var json = formatter.FormatMessage(state); - var doc = JsonDocument.Parse(json); - - // camelCase naming policy from the customer supplied options must be applied by the formatter. - Assert.Equal(JsonValueKind.Object, doc.RootElement.GetProperty("product").ValueKind); - Assert.Equal("Widget", doc.RootElement.GetProperty("product").GetProperty("name").GetString()); - Assert.Equal(100, doc.RootElement.GetProperty("product").GetProperty("inventory").GetInt32()); - } - - /// - /// The reflection wiring must be resilient: passing an assembly that does not contain the structured logging - /// types (simulating an older Amazon.Lambda.Core in the deployment bundle) must not throw. - /// - [Fact] - public void ReflectionWiring_AssemblyWithoutStructuredLoggingTypes_DoesNotThrow() - { - var formatter = new JsonLogMessageFormatter(); - - // System.Private.CoreLib clearly has no Amazon.Lambda.Core.LambdaLogger type. - var unrelatedAssembly = typeof(object).Assembly; - - var ex = Record.Exception(() => - ConfigureJsonLogMessageFormatterIsolated.ConfigureCallbackInCore(unrelatedAssembly, options => { })); - - Assert.Null(ex); - } - - [Fact] - public void ReflectionWiring_NullAssembly_Throws() - { - Assert.Throws(() => - ConfigureJsonLogMessageFormatterIsolated.ConfigureCallbackInCore((Assembly)null, options => { })); - } - } -} From 5b081bfa548b9aed521b25010f007b56bf0a7abd Mon Sep 17 00:00:00 2001 From: Norm Johanson Date: Fri, 25 Sep 2026 03:48:01 +0000 Subject: [PATCH 4/5] Refactor shared JsonLogMessageFormatter creation into Initialize (#2350) Move formatter creation out of WrapperTextWriter and into LogLevelLoggerWriter.Initialize, then pass the single instance explicitly into both the stdout and stderr WrapperTextWriter constructors. The constructor now takes a required ILogMessageFormatter (no null default) and no longer resolves log format or builds a formatter internally, so both writers are symmetric and there is no sibling instance borrowing inner state. - Add CreateLogMessageFormatter helper and lift LogFormatType enum + LOG_FORMAT env-var resolution up to LogLevelLoggerWriter. - Remove the now-unused _logFormatType field. - No behavior change: both writers still share one formatter so the customer's ConfigureStructuredLogging options reach the stdout formatter. SharedFormatterStructuredLoggingTests still passes and still fails when formatters are not shared. --- .../Helpers/ConsoleLoggerWriter.cs | 113 ++++++++++-------- 1 file changed, 63 insertions(+), 50 deletions(-) diff --git a/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/ConsoleLoggerWriter.cs b/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/ConsoleLoggerWriter.cs index 1ea8fed65..35a6a28a7 100644 --- a/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/ConsoleLoggerWriter.cs +++ b/Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/ConsoleLoggerWriter.cs @@ -107,6 +107,11 @@ public enum LogLevel WrapperTextWriter _wrappedStdOutWriter; WrapperTextWriter _wrappedStdErrorWriter; + /// + /// The supported log output formats resolved from the log format environment variables. + /// + enum LogFormatType { Default, Unformatted, Json } + /// /// Constructor used by bootstrap to put in place a wrapper TextWriter around stdout and stderror so all Console.WriteLine calls /// will be formatted. @@ -186,14 +191,56 @@ internal LogLevelLoggerWriter(IEnvironmentVariables environmentVariables, TextWr private void Initialize(TextWriter stdOutWriter, TextWriter stdErrorWriter) { - _wrappedStdOutWriter = new WrapperTextWriter(_environmentVariables, stdOutWriter, LogLevel.Information.ToString()); - // Share the stdout writer's formatter with the stderr writer. Both writers resolve the same log - // format from the same environment variables, so a single formatter is correct for both. Sharing is - // required for structured logging customization: JsonLogMessageFormatter registers the customer's - // ConfigureStructuredLogging callback through a single static setter on Amazon.Lambda.Core.LambdaLogger, - // so if each writer had its own formatter the second registration would overwrite the first and the - // customer's JsonSerializerOptions would not reach the formatter used for stdout. See issue #2350. - _wrappedStdErrorWriter = new WrapperTextWriter(_environmentVariables, stdErrorWriter, LogLevel.Error.ToString(), _wrappedStdOutWriter.LogMessageFormatter); + // Create a single formatter here and hand the same instance to both the stdout and stderr writers. + // Both writers resolve the same log format from the same environment variables, so one formatter is + // correct for both. A single shared instance is also required for structured logging customization: + // JsonLogMessageFormatter registers the customer's ConfigureStructuredLogging callback through a + // single static setter on Amazon.Lambda.Core.LambdaLogger. If each writer created its own formatter, + // the second registration would overwrite the first, and the customer's JsonSerializerOptions would + // never reach the formatter used for stdout logging. See https://github.com/aws/aws-lambda-dotnet/issues/2350. + var logMessageFormatter = CreateLogMessageFormatter(_environmentVariables); + + _wrappedStdOutWriter = new WrapperTextWriter(_environmentVariables, stdOutWriter, LogLevel.Information.ToString(), logMessageFormatter); + _wrappedStdErrorWriter = new WrapperTextWriter(_environmentVariables, stdErrorWriter, LogLevel.Error.ToString(), logMessageFormatter); + } + + /// + /// Creates the log message formatter based on the log format resolved from the environment variables. + /// The formatter is created here (rather than inside each WrapperTextWriter) so a single instance can be + /// shared by the stdout and stderr writers; see Initialize and issue #2350. + /// + private static ILogMessageFormatter CreateLogMessageFormatter(IEnvironmentVariables environmentVariables) + { + var envLogFormat = GetEnvironmentVariable(environmentVariables, + Constants.NET_RIC_LOG_FORMAT_ENVIRONMENT_VARIABLE, Constants.LAMBDA_LOG_FORMAT_ENVIRONMENT_VARIABLE); + + var logFormatType = LogFormatType.Default; + if (!string.IsNullOrEmpty(envLogFormat) && + Enum.TryParse(envLogFormat, true, out var result)) + { + logFormatType = result; + } + + if (logFormatType == LogFormatType.Json) + { + return new JsonLogMessageFormatter(); + } + + return new DefaultLogMessageFormatter(logFormatType != LogFormatType.Unformatted); + } + + /// + /// Reads an environment variable, falling back to a secondary name when the primary is not set. + /// + private static string GetEnvironmentVariable(IEnvironmentVariables environmentVariables, string envName, string fallbackEnvName) + { + var value = environmentVariables.GetEnvironmentVariable(envName); + if (string.IsNullOrEmpty(value) && fallbackEnvName != null) + { + value = environmentVariables.GetEnvironmentVariable(fallbackEnvName); + } + + return value; } /// @@ -282,10 +329,6 @@ class WrapperTextWriter : TextWriter private readonly LogLevel _minmumLogLevel = LogLevel.Information; - enum LogFormatType { Default, Unformatted, Json } - - private readonly LogFormatType _logFormatType = LogFormatType.Default; - private readonly ILogMessageFormatter _logMessageFormatter; // If running in multi concurrency mode we need to store the current aws request id in Task @@ -331,16 +374,17 @@ public IRuntimeApiHeaders CurrentRuntimeApiHeaders /// /// /// - /// - /// When provided, this formatter is used instead of constructing a new one. This lets the stdout and - /// stderr writers share a single formatter instance so structured logging configuration applies to - /// both (see issue #2350). + /// + /// The formatter used to format log records. The same instance is shared between the stdout and stderr + /// writers so structured logging configuration applies to both; the formatter is created and owned by + /// LogLevelLoggerWriter.Initialize (see issue #2350). /// - public WrapperTextWriter(IEnvironmentVariables environmentVariables, TextWriter innerWriter, string defaultLogLevel, ILogMessageFormatter sharedFormatter = null) + public WrapperTextWriter(IEnvironmentVariables environmentVariables, TextWriter innerWriter, string defaultLogLevel, ILogMessageFormatter formatter) { _environmentVariables = environmentVariables; _innerWriter = innerWriter; _defaultLogLevel = defaultLogLevel; + _logMessageFormatter = formatter ?? throw new ArgumentNullException(nameof(formatter)); if(Utils.IsUsingMultiConcurrency(environmentVariables)) { @@ -368,42 +412,11 @@ public WrapperTextWriter(IEnvironmentVariables environmentVariables, TextWriter InternalLogger.GetDefaultLogger().LogInformation($"Failed to parse log level enum value: {envLogLevel}"); } } - - var envLogFormat = GetEnvironmentVariable(Constants.NET_RIC_LOG_FORMAT_ENVIRONMENT_VARIABLE, Constants.LAMBDA_LOG_FORMAT_ENVIRONMENT_VARIABLE); - if (!string.IsNullOrEmpty(envLogFormat)) - { - if (Enum.TryParse(envLogFormat, true, out var result)) - { - _logFormatType = result; - } - } - - if (sharedFormatter != null) - { - // Reuse the formatter created for the sibling writer. The stdout and stderr WrapperTextWriter - // instances must share ONE formatter so that a customer's LambdaLogger.ConfigureStructuredLogging - // callback (which JsonLogMessageFormatter registers via a single static setter on - // Amazon.Lambda.Core.LambdaLogger) applies to the same formatter instance that actually formats - // the log records. If each writer had its own formatter, the second one constructed would - // overwrite the first's callback registration, and the customer's custom JsonSerializerOptions - // would never reach the formatter used for stdout logging. See - // https://github.com/aws/aws-lambda-dotnet/issues/2350. - _logMessageFormatter = sharedFormatter; - } - else if(_logFormatType == LogFormatType.Json) - { - _logMessageFormatter = new JsonLogMessageFormatter(); - } - else - { - _logMessageFormatter = new DefaultLogMessageFormatter(_logFormatType != LogFormatType.Unformatted); - } } /// - /// The log message formatter this writer uses. Exposed so the sibling writer (stderr) can share the - /// same formatter instance created by the first writer (stdout); see the sharedFormatter constructor - /// parameter and issue #2350. + /// The log message formatter this writer uses. Exposed so tests can verify the stdout and stderr + /// writers share the same formatter instance (created by LogLevelLoggerWriter.Initialize); see issue #2350. /// internal ILogMessageFormatter LogMessageFormatter => _logMessageFormatter; From ddc9f73a0d23d2ab96d49205dd66a93d08bf8852 Mon Sep 17 00:00:00 2001 From: Norm Johanson Date: Fri, 25 Sep 2026 04:14:15 +0000 Subject: [PATCH 5/5] Address Copilot review: isolate callback-mutating test, use invariant culture (#2350) - Add LambdaBootstrapMultiConcurrencyTests to the StructuredLogging serial collection. Its WorkerPoolInitializingLog_EmissionGatedByJsonLogFormat test builds a real LogLevelLoggerWriter (via TestMultiConcurrencyRuntimeApiClient) under JSON log format, which registers a JsonLogMessageFormatter as the static LambdaLogger structured-logging callback target. Running it in parallel with SharedFormatterStructuredLoggingTests could overwrite the callback and cause intermittent failures. - Format the regression test's Instant converter output with CultureInfo.InvariantCulture so the asserted string is culture-independent. --- .../LambdaBootstrapMultiConcurrencyTests.cs | 6 ++++++ .../SharedFormatterStructuredLoggingTests.cs | 2 +- 2 files changed, 7 insertions(+), 1 deletion(-) diff --git a/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/LambdaBootstrapMultiConcurrencyTests.cs b/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/LambdaBootstrapMultiConcurrencyTests.cs index 06e7426cf..8b5d4671c 100644 --- a/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/LambdaBootstrapMultiConcurrencyTests.cs +++ b/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/LambdaBootstrapMultiConcurrencyTests.cs @@ -14,6 +14,12 @@ namespace Amazon.Lambda.RuntimeSupport.UnitTests { + // These tests construct real LogLevelLoggerWriter instances (via TestMultiConcurrencyRuntimeApiClient) which, under + // JSON log format, build a JsonLogMessageFormatter that registers itself as the process-wide LambdaLogger + // structured-logging callback target. That is the same static state the StructuredLogging collection guards, so this + // class must run serially with those tests to avoid overwriting each other's callback registration. See + // https://github.com/aws/aws-lambda-dotnet/issues/2350. + [Collection("StructuredLogging")] public class LambdaBootstrapMultiConcurrencyTests { JsonSerializer _serializer = new JsonSerializer(); diff --git a/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/SharedFormatterStructuredLoggingTests.cs b/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/SharedFormatterStructuredLoggingTests.cs index 76476347c..e056e8932 100644 --- a/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/SharedFormatterStructuredLoggingTests.cs +++ b/Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/SharedFormatterStructuredLoggingTests.cs @@ -41,7 +41,7 @@ public override Instant Read(ref Utf8JsonReader reader, Type typeToConvert, Json => new Instant(reader.GetDateTime()); public override void Write(Utf8JsonWriter writer, Instant value, JsonSerializerOptions options) - => writer.WriteStringValue(value.ToUtc().ToString("yyyy-MM-ddTHH:mm:ssZ")); + => writer.WriteStringValue(value.ToUtc().ToString("yyyy-MM-ddTHH:mm:ssZ", System.Globalization.CultureInfo.InvariantCulture)); } [Fact]