From 87757af611fd2c2fe5b375d6c850abcb66ae79ba Mon Sep 17 00:00:00 2001 From: "copilot-swe-agent[bot]" <198982749+Copilot@users.noreply.github.com> Date: Fri, 14 Aug 2026 03:07:15 +0000 Subject: [PATCH 1/3] Initial plan From b0300649e85fd6e5e3524880999d8f4709e5cb43 Mon Sep 17 00:00:00 2001 From: "copilot-swe-agent[bot]" <198982749+Copilot@users.noreply.github.com> Date: Fri, 14 Aug 2026 03:13:50 +0000 Subject: [PATCH 2/3] feat: Add structured scope support to Lambda JSON logging When AWS_LAMBDA_LOG_FORMAT=JSON and IncludeScopes=true, scope state objects implementing IEnumerable> have their key/value entries appended to the message template (as {key} placeholders) and the parameters array, so they are emitted as named JSON properties by the Lambda JSON formatter. Non-structured scopes are silently ignored. Existing behavior (scopes disabled, text-format logging, no scopes) is unchanged. Closes aws/aws-lambda-dotnet#2122 Co-authored-by: Lanayx <3329606+Lanayx@users.noreply.github.com> --- .../LambdaILogger.cs | 31 +++ .../README.md | 22 +++ .../LoggingTests.cs | 185 ++++++++++++++++++ 3 files changed, 238 insertions(+) diff --git a/Libraries/src/Amazon.Lambda.Logging.AspNetCore/LambdaILogger.cs b/Libraries/src/Amazon.Lambda.Logging.AspNetCore/LambdaILogger.cs index 2898a8472..ee5e5dcc1 100644 --- a/Libraries/src/Amazon.Lambda.Logging.AspNetCore/LambdaILogger.cs +++ b/Libraries/src/Amazon.Lambda.Logging.AspNetCore/LambdaILogger.cs @@ -75,6 +75,37 @@ public void Log(LogLevel logLevel, EventId eventId, TState state, Except messageTemplate = formatter.Invoke(state, exception); } + // Append structured scope key/value pairs to the template and parameters so they + // are emitted as named JSON properties by the Lambda JSON formatter. + if (_options.IncludeScopes && ScopeProvider != null) + { + var scopeEntries = new List>(); + ScopeProvider.ForEachScope((scope, list) => + { + if (scope is IEnumerable> scopeKvps) + { + foreach (var kvp in scopeKvps) + { + if (kvp.Key != null && kvp.Key != "{OriginalFormat}") + { + list.Add(kvp); + } + } + } + }, scopeEntries); + + if (scopeEntries.Count > 0) + { + var sb = new System.Text.StringBuilder(messageTemplate); + foreach (var entry in scopeEntries) + { + sb.Append($" {{{entry.Key}}}"); + parameters.Add(entry.Value); + } + messageTemplate = sb.ToString(); + } + } + Amazon.Lambda.Core.LambdaLogger.Log(lambdaLogLevel, exception, messageTemplate, parameters.ToArray()); } else diff --git a/Libraries/src/Amazon.Lambda.Logging.AspNetCore/README.md b/Libraries/src/Amazon.Lambda.Logging.AspNetCore/README.md index 6435cd39b..90a45845b 100644 --- a/Libraries/src/Amazon.Lambda.Logging.AspNetCore/README.md +++ b/Libraries/src/Amazon.Lambda.Logging.AspNetCore/README.md @@ -94,3 +94,25 @@ using(defaultLogger.BeginScope(awsRequestId)) } } ``` + +## Structured scopes in Lambda JSON mode + +When the `AWS_LAMBDA_LOG_FORMAT` environment variable is set to `JSON` and `IncludeScopes` is `true`, scope state objects that implement `IEnumerable>` (such as `Dictionary`) will have their key/value entries included as structured parameters in the emitted JSON log entry. + +```csharp +var loggerOptions = new LambdaLoggerOptions { IncludeScopes = true }; + +var scopeProperties = new Dictionary +{ + { "RequestId", "abc-123" }, + { "UserId", 42 } +}; + +using (logger.BeginScope(scopeProperties)) +{ + logger.LogInformation("Order {OrderId} placed", orderId); + // Emits JSON with RequestId, UserId, and OrderId as structured properties. +} +``` + +Nested structured scopes are supported. The scope properties are prepended to the parameter list (outermost scope first), followed by the message-template parameters. Non-structured scopes (e.g. plain strings) are silently ignored in JSON mode. diff --git a/Libraries/test/Amazon.Lambda.Logging.AspNetCore.Tests/LoggingTests.cs b/Libraries/test/Amazon.Lambda.Logging.AspNetCore.Tests/LoggingTests.cs index e9997cdf3..1c04b5152 100644 --- a/Libraries/test/Amazon.Lambda.Logging.AspNetCore.Tests/LoggingTests.cs +++ b/Libraries/test/Amazon.Lambda.Logging.AspNetCore.Tests/LoggingTests.cs @@ -614,6 +614,191 @@ public void JsonLoggingWithNoOriginalFormat() } } + [Fact] + public void JsonLogging_SingleStructuredScope_IncludedInParameters() + { + Environment.SetEnvironmentVariable("AWS_LAMBDA_LOG_FORMAT", "JSON"); + try + { + using (var writer = new StringWriter()) + { + ConnectLoggingActionToLogger(message => writer.Write(message)); + + var loggerOptions = new LambdaLoggerOptions { IncludeScopes = true }; + var loggerFactory = new TestLoggerFactory().AddLambdaLogger(loggerOptions); + var logger = loggerFactory.CreateLogger("JsonScopeTest"); + + var scopeProps = new Dictionary { { "RequestId", "abc-123" } }; + using (logger.BeginScope(scopeProps)) + { + logger.LogInformation("User {Name} logged in", "Alice"); + } + + var text = writer.ToString(); + // scope param + 1 message param = 2 + Assert.Contains("parameter count: 2", text); + } + } + finally + { + Environment.SetEnvironmentVariable("AWS_LAMBDA_LOG_FORMAT", null); + } + } + + [Fact] + public void JsonLogging_NestedStructuredScopes_AllIncludedInParameters() + { + Environment.SetEnvironmentVariable("AWS_LAMBDA_LOG_FORMAT", "JSON"); + try + { + using (var writer = new StringWriter()) + { + ConnectLoggingActionToLogger(message => writer.Write(message)); + + var loggerOptions = new LambdaLoggerOptions { IncludeScopes = true }; + var loggerFactory = new TestLoggerFactory().AddLambdaLogger(loggerOptions); + var logger = loggerFactory.CreateLogger("JsonScopeTest"); + + var outerScope = new Dictionary { { "TraceId", "trace-1" } }; + var innerScope = new Dictionary { { "UserId", "user-99" } }; + using (logger.BeginScope(outerScope)) + { + using (logger.BeginScope(innerScope)) + { + logger.LogInformation("Processed {Item}", "order"); + } + } + + var text = writer.ToString(); + // outer (1) + inner (1) + message param (1) = 3 + Assert.Contains("parameter count: 3", text); + } + } + finally + { + Environment.SetEnvironmentVariable("AWS_LAMBDA_LOG_FORMAT", null); + } + } + + [Fact] + public void JsonLogging_ScopesDisabled_ScopePropertiesNotIncluded() + { + Environment.SetEnvironmentVariable("AWS_LAMBDA_LOG_FORMAT", "JSON"); + try + { + using (var writer = new StringWriter()) + { + ConnectLoggingActionToLogger(message => writer.Write(message)); + + var loggerOptions = new LambdaLoggerOptions { IncludeScopes = false }; + var loggerFactory = new TestLoggerFactory().AddLambdaLogger(loggerOptions); + var logger = loggerFactory.CreateLogger("JsonScopeTest"); + + var scopeProps = new Dictionary { { "RequestId", "abc-123" } }; + using (logger.BeginScope(scopeProps)) + { + logger.LogInformation("User {Name} logged in", "Alice"); + } + + var text = writer.ToString(); + // only 1 message param, scope excluded + Assert.Contains("parameter count: 1", text); + } + } + finally + { + Environment.SetEnvironmentVariable("AWS_LAMBDA_LOG_FORMAT", null); + } + } + + [Fact] + public void JsonLogging_NoScopes_MessageTemplatePropertiesPreserved() + { + Environment.SetEnvironmentVariable("AWS_LAMBDA_LOG_FORMAT", "JSON"); + try + { + using (var writer = new StringWriter()) + { + ConnectLoggingActionToLogger(message => writer.Write(message)); + + var loggerOptions = new LambdaLoggerOptions { IncludeScopes = true }; + var loggerFactory = new TestLoggerFactory().AddLambdaLogger(loggerOptions); + var logger = loggerFactory.CreateLogger("JsonScopeTest"); + + logger.LogInformation("Order {OrderId} placed for {Customer}", 42, "Bob"); + + var text = writer.ToString(); + Assert.Contains("parameter count: 2", text); + Assert.Contains("Order {OrderId} placed for {Customer}", text); + } + } + finally + { + Environment.SetEnvironmentVariable("AWS_LAMBDA_LOG_FORMAT", null); + } + } + + [Fact] + public void JsonLogging_ScopeWithNullValue_DoesNotCrash() + { + Environment.SetEnvironmentVariable("AWS_LAMBDA_LOG_FORMAT", "JSON"); + try + { + using (var writer = new StringWriter()) + { + ConnectLoggingActionToLogger(message => writer.Write(message)); + + var loggerOptions = new LambdaLoggerOptions { IncludeScopes = true }; + var loggerFactory = new TestLoggerFactory().AddLambdaLogger(loggerOptions); + var logger = loggerFactory.CreateLogger("JsonScopeTest"); + + var scopeProps = new Dictionary { { "NullProp", null } }; + using (logger.BeginScope(scopeProps)) + { + logger.LogInformation("Null scope value test"); + } + + var text = writer.ToString(); + // 1 scope param (null) + 0 message params = 1 + Assert.Contains("parameter count: 1", text); + } + } + finally + { + Environment.SetEnvironmentVariable("AWS_LAMBDA_LOG_FORMAT", null); + } + } + + [Fact] + public void JsonLogging_NonStructuredScope_DoesNotCrash() + { + Environment.SetEnvironmentVariable("AWS_LAMBDA_LOG_FORMAT", "JSON"); + try + { + using (var writer = new StringWriter()) + { + ConnectLoggingActionToLogger(message => writer.Write(message)); + + var loggerOptions = new LambdaLoggerOptions { IncludeScopes = true }; + var loggerFactory = new TestLoggerFactory().AddLambdaLogger(loggerOptions); + var logger = loggerFactory.CreateLogger("JsonScopeTest"); + + using (logger.BeginScope("plain string scope")) + { + logger.LogInformation("Message {Param}", "value"); + } + + var text = writer.ToString(); + // non-structured scope ignored; only 1 message param + Assert.Contains("parameter count: 1", text); + } + } + finally + { + Environment.SetEnvironmentVariable("AWS_LAMBDA_LOG_FORMAT", null); + } + } + private static string GetAppSettingsPath(string fileName) { return Path.Combine(APPSETTINGS_DIR, fileName); From 373f034a40cbc1b069265f1441a9a44da19c65a1 Mon Sep 17 00:00:00 2001 From: "copilot-swe-agent[bot]" <198982749+Copilot@users.noreply.github.com> Date: Tue, 8 Sep 2026 17:20:06 +0000 Subject: [PATCH 3/3] Fix scope key sanitization, collisions, and add e2e JSON tests + autover change file Co-authored-by: Lanayx <3329606+Lanayx@users.noreply.github.com> --- .../2d110000-94ab-425d-b995-defdb0c81121.json | 11 + .../LambdaILogger.cs | 174 +++++++++- ...zon.Lambda.Logging.AspNetCore.Tests.csproj | 4 + .../LoggingTests.cs | 325 ++++++++++++++++++ 4 files changed, 501 insertions(+), 13 deletions(-) create mode 100644 .autover/changes/2d110000-94ab-425d-b995-defdb0c81121.json diff --git a/.autover/changes/2d110000-94ab-425d-b995-defdb0c81121.json b/.autover/changes/2d110000-94ab-425d-b995-defdb0c81121.json new file mode 100644 index 000000000..b6ceee01a --- /dev/null +++ b/.autover/changes/2d110000-94ab-425d-b995-defdb0c81121.json @@ -0,0 +1,11 @@ +{ + "Projects": [ + { + "Name": "Amazon.Lambda.Logging.AspNetCore", + "Type": "Minor", + "ChangelogMessages": [ + "Added structured scope support to Lambda JSON logging with safe handling of invalid, colliding, and duplicate scope keys" + ] + } + ] +} \ No newline at end of file diff --git a/Libraries/src/Amazon.Lambda.Logging.AspNetCore/LambdaILogger.cs b/Libraries/src/Amazon.Lambda.Logging.AspNetCore/LambdaILogger.cs index ee5e5dcc1..4131f3906 100644 --- a/Libraries/src/Amazon.Lambda.Logging.AspNetCore/LambdaILogger.cs +++ b/Libraries/src/Amazon.Lambda.Logging.AspNetCore/LambdaILogger.cs @@ -2,11 +2,29 @@ using System.Collections.Generic; namespace Microsoft.Extensions.Logging -{ - internal class LambdaILogger : ILogger - { - // Private fields - private readonly string _categoryName; +{ + internal class LambdaILogger : ILogger + { + /// + /// The set of JSON property names written unconditionally by the Lambda RuntimeSupport JSON log formatter + /// (Amazon.Lambda.RuntimeSupport.Helpers.Logging.JsonLogMessageFormatter). Scope values are never allowed to + /// use these names so that a scope entry can never overwrite/corrupt these reserved metadata fields. + /// + private static readonly HashSet ReservedMessagePropertyNames = new HashSet(StringComparer.Ordinal) + { + "timestamp", + "level", + "requestId", + "tenantId", + "traceId", + "message", + "errorType", + "errorMessage", + "stackTrace", + }; + + // Private fields + private readonly string _categoryName; private readonly LambdaLoggerOptions _options; @@ -79,28 +97,49 @@ public void Log(LogLevel logLevel, EventId eventId, TState state, Except // are emitted as named JSON properties by the Lambda JSON formatter. if (_options.IncludeScopes && ScopeProvider != null) { - var scopeEntries = new List>(); + // Names already claimed by the message template itself (explicit message properties) always win. + // Scope entries that collide with these names, or with each other, must never be allowed to + // silently corrupt the message or reserved JSON metadata fields written by the RuntimeSupport + // JSON formatter (e.g. "timestamp", "level", "message", ...). + var messagePropertyNames = ExtractTemplatePropertyNames(messageTemplate); + + // Preserves the order scope property names were first encountered, while allowing a later + // (i.e. more inner/nested) scope to overwrite the value of an earlier (outer) scope that used + // the same key. IExternalScopeProvider.ForEachScope invokes the callback from the outermost + // scope to the innermost scope, so later invocations here represent inner scopes. + var orderedScopeKeys = new List(); + var scopeValuesByKey = new Dictionary(StringComparer.Ordinal); + ScopeProvider.ForEachScope((scope, list) => { if (scope is IEnumerable> scopeKvps) { foreach (var kvp in scopeKvps) { - if (kvp.Key != null && kvp.Key != "{OriginalFormat}") + if (!IsSupportedScopeKey(kvp.Key) || messagePropertyNames.Contains(kvp.Key)) { - list.Add(kvp); + continue; } + + if (!scopeValuesByKey.ContainsKey(kvp.Key)) + { + list.Add(kvp.Key); + } + + // Overwrite with the latest value seen for this key so that, within a single + // scope's enumerable and across nested scopes, the innermost/last value wins. + scopeValuesByKey[kvp.Key] = kvp.Value; } } - }, scopeEntries); + }, orderedScopeKeys); - if (scopeEntries.Count > 0) + if (orderedScopeKeys.Count > 0) { var sb = new System.Text.StringBuilder(messageTemplate); - foreach (var entry in scopeEntries) + foreach (var key in orderedScopeKeys) { - sb.Append($" {{{entry.Key}}}"); - parameters.Add(entry.Value); + sb.Append($" {{{key}}}"); + parameters.Add(scopeValuesByKey[key]); } messageTemplate = sb.ToString(); } @@ -145,6 +184,115 @@ public void Log(LogLevel logLevel, EventId eventId, TState state, Except } } + /// + /// Determines whether a scope key can be safely appended as a "{key}" message-template placeholder + /// and understood correctly by the Lambda RuntimeSupport JSON log formatter's message template parser. + /// + /// + /// The RuntimeSupport parser (Amazon.Lambda.RuntimeSupport.Helpers.Logging.AbstractLogMessageFormatter / + /// MessageProperty) treats '{' and '}' as structural delimiters, an optional leading '@' as a directive + /// that switches the value to JSON serialization, and the first ':' as the start of a .NET format string + /// applied to the value. None of these characters can appear in the key without changing how the + /// template is parsed or silently truncating/renaming the resulting JSON property. Keys containing + /// whitespace are also rejected since they do not represent a well-formed identifier for a JSON + /// property name. Unsupported keys are skipped entirely rather than sanitized/renamed to avoid + /// introducing new collisions or misleading data. + /// + /// The scope dictionary key to validate. + /// True if the key is safe to use as a message-template property name. + private static bool IsSupportedScopeKey(string key) + { + if (string.IsNullOrEmpty(key) || key == "{OriginalFormat}") + { + return false; + } + + if (ReservedMessagePropertyNames.Contains(key)) + { + return false; + } + + foreach (var c in key) + { + if (c == '{' || c == '}' || c == ':' || c == '@' || char.IsWhiteSpace(c)) + { + return false; + } + } + + return true; + } + + /// + /// Parses a message template to determine the set of message-property names it explicitly defines + /// (e.g. "User {Name} logged in" defines the property name "Name"). Used to ensure scope values never + /// override an explicit message property with the same name. + /// + /// The message template to inspect. + /// The set of property names already used by the message template. + private static HashSet ExtractTemplatePropertyNames(string messageTemplate) + { + var names = new HashSet(StringComparer.Ordinal); + + if (string.IsNullOrEmpty(messageTemplate)) + { + return names; + } + + var inParameter = false; + var possibleParameterOpen = false; + int paramStartIdx = -1; + + for (int i = 0, l = messageTemplate.Length; i < l; i++) + { + var c = messageTemplate[i]; + if (c == '{') + { + if (!inParameter && !possibleParameterOpen) + { + possibleParameterOpen = true; + } + else if (possibleParameterOpen) + { + // escaped "{{" + possibleParameterOpen = false; + } + } + else if (c == '}') + { + if (inParameter || possibleParameterOpen) + { + if (paramStartIdx != -1) + { + var token = messageTemplate.Substring(paramStartIdx, i - paramStartIdx); + if (token.Length > 0 && token[0] == '@') + { + token = token.Substring(1); + } + var colonIdx = token.IndexOf(':'); + if (colonIdx >= 0) + { + token = token.Substring(0, colonIdx); + } + names.Add(token.Trim()); + } + + inParameter = false; + possibleParameterOpen = false; + paramStartIdx = -1; + } + } + else if (possibleParameterOpen) + { + paramStartIdx = i; + possibleParameterOpen = false; + inParameter = true; + } + } + + return names; + } + private static Amazon.Lambda.Core.LogLevel ConvertLogLevel(LogLevel logLevel) { switch (logLevel) diff --git a/Libraries/test/Amazon.Lambda.Logging.AspNetCore.Tests/Amazon.Lambda.Logging.AspNetCore.Tests.csproj b/Libraries/test/Amazon.Lambda.Logging.AspNetCore.Tests/Amazon.Lambda.Logging.AspNetCore.Tests.csproj index cf907724c..d6baae589 100644 --- a/Libraries/test/Amazon.Lambda.Logging.AspNetCore.Tests/Amazon.Lambda.Logging.AspNetCore.Tests.csproj +++ b/Libraries/test/Amazon.Lambda.Logging.AspNetCore.Tests/Amazon.Lambda.Logging.AspNetCore.Tests.csproj @@ -31,6 +31,10 @@ + + diff --git a/Libraries/test/Amazon.Lambda.Logging.AspNetCore.Tests/LoggingTests.cs b/Libraries/test/Amazon.Lambda.Logging.AspNetCore.Tests/LoggingTests.cs index 1c04b5152..4d3262225 100644 --- a/Libraries/test/Amazon.Lambda.Logging.AspNetCore.Tests/LoggingTests.cs +++ b/Libraries/test/Amazon.Lambda.Logging.AspNetCore.Tests/LoggingTests.cs @@ -1,4 +1,6 @@ using Amazon.Lambda.Logging.AspNetCore.Tests; +using Amazon.Lambda.RuntimeSupport.Helpers; +using Amazon.Lambda.RuntimeSupport.Helpers.Logging; using Microsoft.Extensions.Configuration; using Microsoft.Extensions.Logging; using System; @@ -7,6 +9,7 @@ using System.Linq; using System.Reflection; using System.Text; +using System.Text.Json; using Xunit; namespace Amazon.Lambda.Tests @@ -799,6 +802,328 @@ public void JsonLogging_NonStructuredScope_DoesNotCrash() } } + /// + /// Hooks the actual Lambda RuntimeSupport JSON log formatter (Amazon.Lambda.RuntimeSupport.Helpers.Logging.JsonLogMessageFormatter) + /// up to Amazon.Lambda.Core.LambdaLogger, the same way RuntimeSupport does at runtime, so tests can assert on real, parsed JSON + /// output rather than a fake sink. Returns the list that will be populated with the raw JSON produced for each log call. + /// + private static List ConnectJsonFormatterToLogger() + { + var jsonMessages = new List(); + var formatter = new JsonLogMessageFormatter(); + + void Capture(string level, Exception exception, string message, object[] args) + { + var state = new MessageState + { + TimeStamp = DateTime.UtcNow, + Level = Enum.TryParse(level, true, out var parsedLevel) + ? parsedLevel + : (LogLevelLoggerWriter.LogLevel?)null, + MessageTemplate = message, + MessageArguments = args ?? Array.Empty(), + Exception = exception, + }; + + jsonMessages.Add(formatter.FormatMessage(state)); + } + + Action loggingWithExceptionLevelAction = + (level, exception, message, args) => Capture(level, exception, message, args); + + var lambdaLoggerType = typeof(Amazon.Lambda.Core.LambdaLogger); + var loggingWithExceptionLevelActionField = lambdaLoggerType + .GetTypeInfo() + .GetField("_loggingWithLevelAndExceptionAction", BindingFlags.NonPublic | BindingFlags.Static); + Assert.NotNull(loggingWithExceptionLevelActionField); + + loggingWithExceptionLevelActionField.SetValue(null, loggingWithExceptionLevelAction); + + return jsonMessages; + } + + /// + /// Runs with AWS_LAMBDA_LOG_FORMAT=JSON and the real RuntimeSupport JSON formatter + /// connected to Amazon.Lambda.Core.LambdaLogger, restoring both the environment variable and the original + /// static logging delegate afterwards so this test does not leak state into other tests. + /// + private static void RunWithJsonFormatterCapture(Action> testBody) + { + var lambdaLoggerType = typeof(Amazon.Lambda.Core.LambdaLogger); + var loggingWithExceptionLevelActionField = lambdaLoggerType + .GetTypeInfo() + .GetField("_loggingWithLevelAndExceptionAction", BindingFlags.NonPublic | BindingFlags.Static); + Assert.NotNull(loggingWithExceptionLevelActionField); + var originalAction = loggingWithExceptionLevelActionField.GetValue(null); + + Environment.SetEnvironmentVariable("AWS_LAMBDA_LOG_FORMAT", "JSON"); + try + { + var jsonMessages = ConnectJsonFormatterToLogger(); + testBody(jsonMessages); + } + finally + { + Environment.SetEnvironmentVariable("AWS_LAMBDA_LOG_FORMAT", null); + loggingWithExceptionLevelActionField.SetValue(null, originalAction); + } + } + + [Fact] + public void EndToEndJson_MessageProperties_WrittenWithCorrectNamesAndValues() + { + RunWithJsonFormatterCapture(jsonMessages => + { + var loggerFactory = new TestLoggerFactory().AddLambdaLogger(new LambdaLoggerOptions()); + var logger = loggerFactory.CreateLogger("EndToEndJson"); + + logger.LogInformation("User {Name} bought {Count} items for {Price}", "Alice", 3, 19.99); + + var json = JsonDocument.Parse(Assert.Single(jsonMessages)).RootElement; + Assert.Equal("Alice", json.GetProperty("Name").GetString()); + Assert.Equal(3, json.GetProperty("Count").GetInt32()); + Assert.Equal(19.99, json.GetProperty("Price").GetDouble()); + Assert.Equal("Information", json.GetProperty("level").GetString()); + }); + } + + [Fact] + public void EndToEndJson_ScopeProperties_AddedAsJsonPropertiesWithCorrectTypes() + { + RunWithJsonFormatterCapture(jsonMessages => + { + var loggerFactory = new TestLoggerFactory().AddLambdaLogger(new LambdaLoggerOptions { IncludeScopes = true }); + var logger = loggerFactory.CreateLogger("EndToEndJson"); + + var scopeProps = new Dictionary + { + { "RequestId", "abc-123" }, + { "RetryCount", 2 }, + }; + using (logger.BeginScope(scopeProps)) + { + logger.LogInformation("User {Name} logged in", "Bob"); + } + + var json = JsonDocument.Parse(Assert.Single(jsonMessages)).RootElement; + Assert.Equal("Bob", json.GetProperty("Name").GetString()); + Assert.Equal("abc-123", json.GetProperty("RequestId").GetString()); + Assert.Equal(2, json.GetProperty("RetryCount").GetInt32()); + }); + } + + [Fact] + public void EndToEndJson_NestedScopesDuplicateKey_InnerValueWins() + { + RunWithJsonFormatterCapture(jsonMessages => + { + var loggerFactory = new TestLoggerFactory().AddLambdaLogger(new LambdaLoggerOptions { IncludeScopes = true }); + var logger = loggerFactory.CreateLogger("EndToEndJson"); + + var outerScope = new Dictionary { { "UserId", "outer-user" } }; + var innerScope = new Dictionary { { "UserId", "inner-user" } }; + using (logger.BeginScope(outerScope)) + using (logger.BeginScope(innerScope)) + { + logger.LogInformation("Processing"); + } + + var json = JsonDocument.Parse(Assert.Single(jsonMessages)).RootElement; + Assert.Equal("inner-user", json.GetProperty("UserId").GetString()); + // Ensure the property was written exactly once by round-tripping through JsonDocument (which would + // otherwise expose duplicate properties on enumeration). + Assert.Equal(1, json.EnumerateObject().Count(p => p.Name == "UserId")); + }); + } + + [Fact] + public void EndToEndJson_DuplicateKeysWithinSingleScope_LastValueWins() + { + RunWithJsonFormatterCapture(jsonMessages => + { + var loggerFactory = new TestLoggerFactory().AddLambdaLogger(new LambdaLoggerOptions { IncludeScopes = true }); + var logger = loggerFactory.CreateLogger("EndToEndJson"); + + var scopeWithDuplicates = new List> + { + new KeyValuePair("Key", "first"), + new KeyValuePair("Key", "second"), + }; + using (logger.BeginScope(scopeWithDuplicates)) + { + logger.LogInformation("Message"); + } + + var json = JsonDocument.Parse(Assert.Single(jsonMessages)).RootElement; + Assert.Equal("second", json.GetProperty("Key").GetString()); + Assert.Equal(1, json.EnumerateObject().Count(p => p.Name == "Key")); + }); + } + + [Fact] + public void EndToEndJson_ScopeKeyCollidesWithMessageProperty_MessagePropertyPreserved() + { + RunWithJsonFormatterCapture(jsonMessages => + { + var loggerFactory = new TestLoggerFactory().AddLambdaLogger(new LambdaLoggerOptions { IncludeScopes = true }); + var logger = loggerFactory.CreateLogger("EndToEndJson"); + + var scopeProps = new Dictionary { { "Name", "FromScope" } }; + using (logger.BeginScope(scopeProps)) + { + logger.LogInformation("User {Name} logged in", "FromMessage"); + } + + var json = JsonDocument.Parse(Assert.Single(jsonMessages)).RootElement; + Assert.Equal("FromMessage", json.GetProperty("Name").GetString()); + Assert.Equal(1, json.EnumerateObject().Count(p => p.Name == "Name")); + }); + } + + [Theory] + [InlineData("Invalid:Key")] + [InlineData("Invalid{Key")] + [InlineData("Invalid}Key")] + [InlineData("Invalid Key")] + public void EndToEndJson_InvalidScopeKey_SkippedAndSubsequentValidKeyStillBinds(string invalidKey) + { + RunWithJsonFormatterCapture(jsonMessages => + { + var loggerFactory = new TestLoggerFactory().AddLambdaLogger(new LambdaLoggerOptions { IncludeScopes = true }); + var logger = loggerFactory.CreateLogger("EndToEndJson"); + + var scopeProps = new List> + { + new KeyValuePair(invalidKey, "should-not-appear"), + new KeyValuePair("ValidKey", "valid-value"), + }; + using (logger.BeginScope(scopeProps)) + { + logger.LogInformation("Message"); + } + + var jsonString = Assert.Single(jsonMessages); + var json = JsonDocument.Parse(jsonString).RootElement; + Assert.Equal("valid-value", json.GetProperty("ValidKey").GetString()); + Assert.DoesNotContain("should-not-appear", jsonString); + }); + } + + [Theory] + [InlineData("timestamp")] + [InlineData("level")] + [InlineData("message")] + public void EndToEndJson_ScopeKeyCollidesWithReservedField_ReservedFieldNotOverwritten(string reservedKey) + { + RunWithJsonFormatterCapture(jsonMessages => + { + var loggerFactory = new TestLoggerFactory().AddLambdaLogger(new LambdaLoggerOptions { IncludeScopes = true }); + var logger = loggerFactory.CreateLogger("EndToEndJson"); + + var scopeProps = new Dictionary { { reservedKey, "hijacked-value" } }; + using (logger.BeginScope(scopeProps)) + { + logger.LogInformation("Message"); + } + + var jsonString = Assert.Single(jsonMessages); + var json = JsonDocument.Parse(jsonString).RootElement; + // The reserved value (a real timestamp/level/message string) must never be replaced by the + // scope's "hijacked-value", and the reserved field must appear exactly once. + Assert.DoesNotContain("hijacked-value", jsonString); + Assert.NotEqual("hijacked-value", json.GetProperty(reservedKey).GetString()); + Assert.Equal(1, json.EnumerateObject().Count(p => p.Name == reservedKey)); + }); + } + + [Fact] + public void EndToEndJson_ScopeKeyCollidesWithConditionalReservedField_NotAddedAsMessageProperty() + { + RunWithJsonFormatterCapture(jsonMessages => + { + var loggerFactory = new TestLoggerFactory().AddLambdaLogger(new LambdaLoggerOptions { IncludeScopes = true }); + var logger = loggerFactory.CreateLogger("EndToEndJson"); + + // "requestId", "tenantId" and "traceId" are only written by the formatter when the corresponding + // MessageState value is populated. Since MessageState.AwsRequestId is null in this test, the + // "requestId" JSON property is not emitted at all - it must not be added as a message property either. + var scopeProps = new Dictionary { { "requestId", "hijacked-value" } }; + using (logger.BeginScope(scopeProps)) + { + logger.LogInformation("Message"); + } + + var jsonString = Assert.Single(jsonMessages); + var json = JsonDocument.Parse(jsonString).RootElement; + Assert.DoesNotContain("hijacked-value", jsonString); + Assert.False(json.TryGetProperty("requestId", out _)); + }); + } + + [Fact] + public void EndToEndJson_ScopesDisabled_ScopePropertiesAbsentFromJson() + { + RunWithJsonFormatterCapture(jsonMessages => + { + var loggerFactory = new TestLoggerFactory().AddLambdaLogger(new LambdaLoggerOptions { IncludeScopes = false }); + var logger = loggerFactory.CreateLogger("EndToEndJson"); + + var scopeProps = new Dictionary { { "RequestId", "abc-123" } }; + using (logger.BeginScope(scopeProps)) + { + logger.LogInformation("User {Name} logged in", "Carol"); + } + + var jsonString = Assert.Single(jsonMessages); + var json = JsonDocument.Parse(jsonString).RootElement; + Assert.Equal("Carol", json.GetProperty("Name").GetString()); + Assert.False(json.TryGetProperty("RequestId", out _)); + }); + } + + [Fact] + public void EndToEndJson_ScopeWithNullValue_WritesJsonNull() + { + RunWithJsonFormatterCapture(jsonMessages => + { + var loggerFactory = new TestLoggerFactory().AddLambdaLogger(new LambdaLoggerOptions { IncludeScopes = true }); + var logger = loggerFactory.CreateLogger("EndToEndJson"); + + var scopeProps = new Dictionary { { "NullProp", null } }; + using (logger.BeginScope(scopeProps)) + { + logger.LogInformation("Message"); + } + + var jsonString = Assert.Single(jsonMessages); + var json = JsonDocument.Parse(jsonString).RootElement; + // The RuntimeSupport JSON formatter omits null-valued message properties entirely rather than + // writing a JSON null (see JsonLogMessageFormatter.WriteMessageAttributes). + Assert.False(json.TryGetProperty("NullProp", out _)); + }); + } + + [Fact] + public void EndToEndJson_NoScopeProvider_NonJsonBehaviorUnaffected() + { + using (var writer = new StringWriter()) + { + ConnectLoggingActionToLogger(message => writer.Write(message)); + + var loggerOptions = new LambdaLoggerOptions { IncludeScopes = true }; + var loggerFactory = new TestLoggerFactory().AddLambdaLogger(loggerOptions); + var logger = loggerFactory.CreateLogger("Default"); + + using (logger.BeginScope("First {0}", "scope123")) + { + logger.LogInformation("Hello"); + } + + var text = writer.ToString(); + Assert.Contains("[Information] First scope123 => Default: Hello ", text); + } + } + private static string GetAppSettingsPath(string fileName) { return Path.Combine(APPSETTINGS_DIR, fileName);