Skip to content

chore: Logging improved message formatting #869

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 1 commit into from
May 6, 2025
Merged

chore: Logging improved message formatting #869

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
439 changes: 0 additions & 439 deletions libraries/src/AWS.Lambda.Powertools.Logging/Logger.ExtraKeysLogs.cs
View file
Open in desktop

This file was deleted.

472 changes: 1 addition & 471 deletions libraries/src/AWS.Lambda.Powertools.Logging/PowertoolsLoggerExtensions.cs
View file
Open in desktop

Large diffs are not rendered by default.

3 changes: 2 additions & 1 deletion libraries/tests/AWS.Lambda.Powertools.Logging.Tests/Formatter/LogFormatterTest.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -25,6 +25,7 @@
using AWS.Lambda.Powertools.Logging.Internal;
using AWS.Lambda.Powertools.Logging.Serializers;
using AWS.Lambda.Powertools.Logging.Tests.Handlers;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Options;
using NSubstitute;
using NSubstitute.ExceptionExtensions;
Expand Down Expand Up @@ -193,7 +194,7 @@ public void Log_WhenCustomFormatter_LogsCustomFormat()
};

// Act
logger.LogInformation(scopeExtraKeys, message);
logger.LogInformation(message, scopeExtraKeys);

// Assert
logFormatter.Received(1).FormatLogEntry(Arg.Is<LogEntry>
Expand Down
67 changes: 59 additions & 8 deletions libraries/tests/AWS.Lambda.Powertools.Logging.Tests/Formatter/LogFormattingTests.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -502,10 +502,9 @@ public void Should_Log_Multiple_Formats_No_Duplicates()
TimeStamp = "FakeTime"
};

Logger.LogInformation<User>(user, "{Name} and is {Age} years old", new object[]{user.Name, user.Age});
Assert.Contains("\"first_name\":\"John\"", output.ToString());
Assert.Contains("\"last_name\":\"Doe\"", output.ToString());
Assert.Contains("\"age\":42", output.ToString());
Logger.LogInformation("{Name} is {Age} years old", user.Name, user.Age);

Assert.Contains("\"message\":\"John Doe is 42 years old\"", output.ToString());
Assert.Contains("\"name\":\"AWS.Lambda.Powertools.Logging.Logger\"", output.ToString()); // does not override name

output.Clear();
Expand Down Expand Up @@ -564,16 +563,13 @@ public void Should_Log_Multiple_Formats()
Age = 42
};

Logger.LogInformation<User>(user, "{Name} is {Age} years old", new object[]{user.FirstName, user.Age});
Logger.LogInformation("{Name} is {Age} years old", user.FirstName, user.Age);

var logOutput = output.ToString();
Assert.Contains("\"level\":\"Information\"", logOutput);
Assert.Contains("\"message\":\"John is 42 years old\"", logOutput);
Assert.Contains("\"service\":\"log-level-test-service\"", logOutput);
Assert.Contains("\"name\":\"AWS.Lambda.Powertools.Logging.Logger\"", logOutput);
Assert.Contains("\"first_name\":\"John\"", logOutput);
Assert.Contains("\"last_name\":\"Doe\"", logOutput);
Assert.Contains("\"age\":42", logOutput);

output.Clear();

Expand Down Expand Up @@ -630,8 +626,63 @@ public void Should_Log_Multiple_Formats()
Assert.Contains("\"level\":\"Information\"", logOutput);
Assert.DoesNotContain("\"level\":\"fakeLevel\"", logOutput);

output.Clear();

Logger.LogInformation("{Name} is {Age} years old and {@user}", user.FirstName, user.Age, user);

logOutput = output.ToString();

Assert.Contains("\"message\":\"John is 42 years old and Doe, John (42)\"", logOutput);
// Verify serialized user object with all properties
Assert.Contains("\"user\":{", logOutput);
Assert.Contains("\"first_name\":\"John\"", logOutput);
Assert.Contains("\"last_name\":\"Doe\"", logOutput);
Assert.Contains("\"age\":42", logOutput);
Assert.Contains("\"name\":\"John Doe\"", logOutput);
Assert.Contains("\"time_stamp\":null", logOutput);
Assert.Contains("}", logOutput);

_output.WriteLine(logOutput);
}

[Fact]
public void TestMessageTemplateFormatting()
{
var output = new TestLoggerOutput();
var logger = LoggerFactory.Create(builder =>
{
builder.AddPowertoolsLogger(config =>
{
config.Service = "template-format-service";
config.MinimumLogLevel = LogLevel.Debug;
config.LoggerOutputCase = LoggerOutputCase.SnakeCase;
config.LogOutput = output;
});
}).CreatePowertoolsLogger();

// Simple template with one parameter
logger.LogInformation("This is a test with {param}", "Hello");

var logOutput = output.ToString();
_output.WriteLine(logOutput);

// Verify full formatted message appears correctly
Assert.Contains("\"message\":\"This is a test with Hello\"", logOutput);
// Verify parameter is also included separately
Assert.Contains("\"param\":\"Hello\"", logOutput);

output.Clear();

// Multiple parameters
logger.LogInformation("Test with {first} and {second}", "One", "Two");

logOutput = output.ToString();
_output.WriteLine(logOutput);

// Verify message with multiple parameters
Assert.Contains("\"message\":\"Test with One and Two\"", logOutput);
Assert.Contains("\"first\":\"One\"", logOutput);
Assert.Contains("\"second\":\"Two\"", logOutput);
}

public class ParentClass
Expand Down
10 changes: 2 additions & 8 deletions libraries/tests/AWS.Lambda.Powertools.Logging.Tests/Handlers/ExceptionFunctionHandler.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -34,14 +34,14 @@ public string HandlerLoggerForExceptions(string input, ILambdaContext context)
Logger.LogDebug("Hello {input}", input);
Logger.LogTrace("Hello {input}", input);

Logger.LogInformation("Testing with parameter Log Information Method {company}", new[] { "AWS" });
Logger.LogInformation("Testing with parameter Log Information Method {company}", "AWS" );

var customKeys = new Dictionary<string, string>
{
{"test1", "value1"},
{"test2", "value2"}
};
Logger.LogInformation(customKeys, "Retrieved data for city {cityName} with count {company}", "AWS");
Logger.LogInformation("Retrieved data for city {cityName} with count {company}", "AWS", customKeys);

Logger.AppendKey("aws",1);
Logger.AppendKey("aws",3);
Expand All @@ -52,10 +52,4 @@ public string HandlerLoggerForExceptions(string input, ILambdaContext context)

return "OK";
}

[Logging(LogEvent = true)]
public string HandleOk(string input)
{
return input.ToUpper(CultureInfo.InvariantCulture);
}
}
48 changes: 24 additions & 24 deletions libraries/tests/AWS.Lambda.Powertools.Logging.Tests/PowertoolsLoggerTest.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -811,7 +811,7 @@ public void Log_WhenExtraKeysIsObjectDictionary_AppendExtraKeys(LogLevel logLeve
// Arrange
var loggerName = Guid.NewGuid().ToString();
var service = Guid.NewGuid().ToString();
var message = Guid.NewGuid().ToString();
var message = "{@keys}";

var configurations = Substitute.For<IPowertoolsConfigurations>();
configurations.Service.Returns(service);
Expand All @@ -836,29 +836,29 @@ public void Log_WhenExtraKeysIsObjectDictionary_AppendExtraKeys(LogLevel logLeve

if (logMethod)
{
logger.Log(logLevel, scopeKeys, message);
logger.Log(logLevel, message,scopeKeys);
}
else
{
switch (logLevel)
{
case LogLevel.Trace:
logger.LogTrace(scopeKeys, message);
logger.LogTrace(message,scopeKeys);
break;
case LogLevel.Debug:
logger.LogDebug(scopeKeys, message);
logger.LogDebug(message,scopeKeys);
break;
case LogLevel.Information:
logger.LogInformation(scopeKeys, message);
logger.LogInformation(message,scopeKeys);
break;
case LogLevel.Warning:
logger.LogWarning(scopeKeys, message);
logger.LogWarning(message,scopeKeys);
break;
case LogLevel.Error:
logger.LogError(scopeKeys, message);
logger.LogError(message,scopeKeys);
break;
case LogLevel.Critical:
logger.LogCritical(scopeKeys, message);
logger.LogCritical(message,scopeKeys);
break;
case LogLevel.None:
break;
Expand Down Expand Up @@ -895,7 +895,7 @@ public void Log_WhenExtraKeysIsStringDictionary_AppendExtraKeys(LogLevel logLeve
// Arrange
var loggerName = Guid.NewGuid().ToString();
var service = Guid.NewGuid().ToString();
var message = Guid.NewGuid().ToString();
var message = "{@keys}";

var configurations = Substitute.For<IPowertoolsConfigurations>();
configurations.Service.Returns(service);
Expand All @@ -921,29 +921,29 @@ public void Log_WhenExtraKeysIsStringDictionary_AppendExtraKeys(LogLevel logLeve

if (logMethod)
{
logger.Log(logLevel, scopeKeys, message);
logger.Log(logLevel, message,scopeKeys);
}
else
{
switch (logLevel)
{
case LogLevel.Trace:
logger.LogTrace(scopeKeys, message);
logger.LogTrace(message,scopeKeys);
break;
case LogLevel.Debug:
logger.LogDebug(scopeKeys, message);
logger.LogDebug(message,scopeKeys);
break;
case LogLevel.Information:
logger.LogInformation(scopeKeys, message);
logger.LogInformation(message,scopeKeys);
break;
case LogLevel.Warning:
logger.LogWarning(scopeKeys, message);
logger.LogWarning(message,scopeKeys);
break;
case LogLevel.Error:
logger.LogError(scopeKeys, message);
logger.LogError(message,scopeKeys);
break;
case LogLevel.Critical:
logger.LogCritical(scopeKeys, message);
logger.LogCritical(message,scopeKeys);
break;
case LogLevel.None:
break;
Expand Down Expand Up @@ -980,7 +980,7 @@ public void Log_WhenExtraKeysAsObject_AppendExtraKeys(LogLevel logLevel, bool lo
// Arrange
var loggerName = Guid.NewGuid().ToString();
var service = Guid.NewGuid().ToString();
var message = Guid.NewGuid().ToString();
var message = "{@keys}";

var configurations = Substitute.For<IPowertoolsConfigurations>();
configurations.Service.Returns(service);
Expand All @@ -1006,29 +1006,29 @@ public void Log_WhenExtraKeysAsObject_AppendExtraKeys(LogLevel logLevel, bool lo

if (logMethod)
{
logger.Log(logLevel, scopeKeys, message);
logger.Log(logLevel, message, scopeKeys);
}
else
{
switch (logLevel)
{
case LogLevel.Trace:
logger.LogTrace(scopeKeys, message);
logger.LogTrace(message,scopeKeys);
break;
case LogLevel.Debug:
logger.LogDebug(scopeKeys, message);
logger.LogDebug(message,scopeKeys);
break;
case LogLevel.Information:
logger.LogInformation(scopeKeys, message);
logger.LogInformation(message,scopeKeys);
break;
case LogLevel.Warning:
logger.LogWarning(scopeKeys, message);
logger.LogWarning(message,scopeKeys);
break;
case LogLevel.Error:
logger.LogError(scopeKeys, message);
logger.LogError(message,scopeKeys);
break;
case LogLevel.Critical:
logger.LogCritical(scopeKeys, message);
logger.LogCritical(message,scopeKeys);
break;
case LogLevel.None:
break;
Expand Down
Loading