diff --git a/.autover/changes/5e73fa84-6603-4a1e-b957-2e1e926c5aa9.json b/.autover/changes/5e73fa84-6603-4a1e-b957-2e1e926c5aa9.json new file mode 100644 index 000000000..c3de3eacc --- /dev/null +++ b/.autover/changes/5e73fa84-6603-4a1e-b957-2e1e926c5aa9.json @@ -0,0 +1,32 @@ +{ + "Projects": [ + { + "Name": "Amazon.Lambda.AspNetCoreServer", + "Type": "Minor", + "ChangelogMessages": [ + "Update Amazon.Lambda.Logging.AspNetCore dependency" + ] + }, + { + "Name": "Amazon.Lambda.AspNetCoreServer.Hosting", + "Type": "Minor", + "ChangelogMessages": [ + "Update Amazon.Lambda.Logging.AspNetCore dependency" + ] + }, + { + "Name": "Amazon.Lambda.Core", + "Type": "Minor", + "ChangelogMessages": [ + "Added log level with exception version of the static logging functions on Amazon.Lambda.Core.LambdaLogger" + ] + }, + { + "Name": "Amazon.Lambda.Logging.AspNetCore", + "Type": "Minor", + "ChangelogMessages": [ + "Convert logging parameters into JSON properties when Lambda log format is configured as JSON" + ] + } + ] +} \ No newline at end of file diff --git a/Libraries/src/Amazon.Lambda.Core/LambdaLogger.cs b/Libraries/src/Amazon.Lambda.Core/LambdaLogger.cs index 8cb4d128e..8e74a380b 100644 --- a/Libraries/src/Amazon.Lambda.Core/LambdaLogger.cs +++ b/Libraries/src/Amazon.Lambda.Core/LambdaLogger.cs @@ -75,10 +75,6 @@ private static void LogWithLevelAndExceptionToConsole(string level, Exception ex Console.WriteLine(exception); } - private const string ParameterizedPreviewMessage = - "This method has been mark as preview till the Lambda .NET Managed runtime has been updated with the backing implementation of this method. " + - "It is possible to use this method while in preview if the Lambda function is deployed as an executable and uses the latest version of Amazon.Lambda.RuntimeSupport."; - /// /// Logs a message to AWS CloudWatch Logs. /// @@ -114,7 +110,6 @@ public static void Log(string level, string message, params object[] args) /// Exception to include with the logging. /// Message to log. The message may have format arguments. /// Arguments to format the message with. - [RequiresPreviewFeatures(ParameterizedPreviewMessage)] public static void Log(string level, Exception exception, string message, params object[] args) { _loggingWithLevelAndExceptionAction(level, exception, message, args); @@ -130,7 +125,6 @@ public static void Log(string level, Exception exception, string message, params /// Exception to include with the logging. /// Message to log. The message may have format arguments. /// Arguments to format the message with. - [RequiresPreviewFeatures(ParameterizedPreviewMessage)] public static void Log(LogLevel level, Exception exception, string message, params object[] args) => Log(level.ToString(), exception, message, args); #endif } diff --git a/Libraries/src/Amazon.Lambda.Logging.AspNetCore/LambdaILogger.cs b/Libraries/src/Amazon.Lambda.Logging.AspNetCore/LambdaILogger.cs index 1097f9103..0482c91d7 100644 --- a/Libraries/src/Amazon.Lambda.Logging.AspNetCore/LambdaILogger.cs +++ b/Libraries/src/Amazon.Lambda.Logging.AspNetCore/LambdaILogger.cs @@ -52,39 +52,61 @@ public void Log(LogLevel logLevel, EventId eventId, TState state, Except return; } - var components = new List(4); - if (_options.IncludeLogLevel) - { - components.Add($"[{logLevel}]"); - } - - GetScopeInformation(components); + var lambdaLogLevel = ConvertLogLevel(logLevel); - if (_options.IncludeCategory) + if (IsLambdaJsonFormatEnabled && state is IEnumerable> structure) { - components.Add($"{_categoryName}:"); + string messageTemplate = null; + var parameters = new List(); + foreach (var property in structure) + { + if (property is { Key: "{OriginalFormat}", Value: string value }) + { + messageTemplate = value; + } + else + { + parameters.Add(property.Value); + } + } + + Amazon.Lambda.Core.LambdaLogger.Log(lambdaLogLevel, exception, messageTemplate, parameters.ToArray()); } - if (_options.IncludeEventId) + else { - components.Add($"[{eventId}]:"); - } + var components = new List(4); + if (_options.IncludeLogLevel) + { + components.Add($"[{logLevel}]"); + } - var text = formatter.Invoke(state, exception); - components.Add(text); + GetScopeInformation(components); - if (_options.IncludeException) - { - components.Add($"{exception}"); - } - if (_options.IncludeNewline) - { - components.Add(Environment.NewLine); - } + if (_options.IncludeCategory) + { + components.Add($"{_categoryName}:"); + } + if (_options.IncludeEventId) + { + components.Add($"[{eventId}]:"); + } - var finalText = string.Join(" ", components); + var text = formatter.Invoke(state, exception); + components.Add(text); - var lambdaLogLevel = ConvertLogLevel(logLevel); - Amazon.Lambda.Core.LambdaLogger.Log(lambdaLogLevel, finalText); + if (_options.IncludeException) + { + components.Add($"{exception}"); + } + if (_options.IncludeNewline) + { + components.Add(Environment.NewLine); + } + + var finalText = string.Join(" ", components); + + Amazon.Lambda.Core.LambdaLogger.Log(lambdaLogLevel, finalText); + } } private static Amazon.Lambda.Core.LogLevel ConvertLogLevel(LogLevel logLevel) @@ -126,9 +148,17 @@ private void GetScopeInformation(List logMessageComponents) logMessageComponents.Add("=>"); } } - } - - // Private classes + } + + private bool IsLambdaJsonFormatEnabled + { + get + { + return string.Equals(Environment.GetEnvironmentVariable("AWS_LAMBDA_LOG_FORMAT"), "JSON", StringComparison.InvariantCultureIgnoreCase); + } + } + + // Private classes private class NoOpDisposable : IDisposable { public void Dispose() diff --git a/Libraries/test/Amazon.Lambda.Logging.AspNetCore.Tests/LoggingTests.cs b/Libraries/test/Amazon.Lambda.Logging.AspNetCore.Tests/LoggingTests.cs index 5a8bbecde..b854982ef 100644 --- a/Libraries/test/Amazon.Lambda.Logging.AspNetCore.Tests/LoggingTests.cs +++ b/Libraries/test/Amazon.Lambda.Logging.AspNetCore.Tests/LoggingTests.cs @@ -118,14 +118,14 @@ public void TestWilcardConfiguration() Assert.False(loggerOptions.IncludeLogLevel); Assert.False(loggerOptions.IncludeNewline); - var loggerfactory = new TestLoggerFactory() + var loggerFactory = new TestLoggerFactory() .AddLambdaLogger(loggerOptions); int count = 0; // Should match: // "Foo.*": "Information" - var foobarLogger = loggerfactory.CreateLogger("Foo.Bar"); + var foobarLogger = loggerFactory.CreateLogger("Foo.Bar"); foobarLogger.LogTrace(SHOULD_NOT_APPEAR); foobarLogger.LogDebug(SHOULD_NOT_APPEAR); foobarLogger.LogInformation(SHOULD_APPEAR + (count++)); @@ -135,7 +135,7 @@ public void TestWilcardConfiguration() // Should match: // "Foo.Bar.Baz": "Critical" - var foobarbazLogger = loggerfactory.CreateLogger("Foo.Bar.Baz"); + var foobarbazLogger = loggerFactory.CreateLogger("Foo.Bar.Baz"); foobarbazLogger.LogTrace(SHOULD_NOT_APPEAR); foobarbazLogger.LogDebug(SHOULD_NOT_APPEAR); foobarbazLogger.LogInformation(SHOULD_NOT_APPEAR); @@ -145,7 +145,7 @@ public void TestWilcardConfiguration() // Should match: // "Foo.Bar.*": "Warning" - var foobarbuzzLogger = loggerfactory.CreateLogger("Foo.Bar.Buzz"); + var foobarbuzzLogger = loggerFactory.CreateLogger("Foo.Bar.Buzz"); foobarbuzzLogger.LogTrace(SHOULD_NOT_APPEAR); foobarbuzzLogger.LogDebug(SHOULD_NOT_APPEAR); foobarbuzzLogger.LogInformation(SHOULD_NOT_APPEAR); @@ -156,7 +156,7 @@ public void TestWilcardConfiguration() // Should match: // "*": "Error" - var somethingLogger = loggerfactory.CreateLogger("something"); + var somethingLogger = loggerFactory.CreateLogger("something"); somethingLogger.LogTrace(SHOULD_NOT_APPEAR); somethingLogger.LogDebug(SHOULD_NOT_APPEAR); somethingLogger.LogInformation(SHOULD_NOT_APPEAR); @@ -285,19 +285,19 @@ public void TestLoggingExceptionsAndEvents() .Build(); var loggerOptions = new LambdaLoggerOptions(configuration); - var loggerfactory = new TestLoggerFactory() + var loggerFactory = new TestLoggerFactory() .AddLambdaLogger(loggerOptions); int countMessage = 0; int countEvent = 0; int countException = 0; - var defaultLogger = loggerfactory.CreateLogger("Default"); + var defaultLogger = loggerFactory.CreateLogger("Default"); defaultLogger.LogTrace(SHOULD_NOT_APPEAR_EVENT, SHOULD_NOT_APPEAR_EXCEPTION, SHOULD_NOT_APPEAR); defaultLogger.LogDebug(SHOULD_NOT_APPEAR_EVENT, SHOULD_APPEAR + (countMessage++)); defaultLogger.LogCritical(SHOULD_NOT_APPEAR_EVENT, SHOULD_APPEAR + (countMessage++)); - defaultLogger = loggerfactory.CreateLogger(null); + defaultLogger = loggerFactory.CreateLogger(null); defaultLogger.LogTrace(SHOULD_NOT_APPEAR_EVENT, SHOULD_NOT_APPEAR); defaultLogger.LogDebug(SHOULD_NOT_APPEAR_EVENT, SHOULD_APPEAR + (countMessage++)); defaultLogger.LogCritical(SHOULD_NOT_APPEAR_EVENT, SHOULD_APPEAR + (countMessage++)); @@ -309,12 +309,12 @@ public void TestLoggingExceptionsAndEvents() loggerOptions.IncludeException = true; loggerOptions.IncludeEventId = true; - var msLogger = loggerfactory.CreateLogger("Microsoft"); + var msLogger = loggerFactory.CreateLogger("Microsoft"); msLogger.LogTrace(SHOULD_NOT_APPEAR_EVENT, SHOULD_NOT_APPEAR_EXCEPTION, SHOULD_NOT_APPEAR); msLogger.LogInformation(GET_SHOULD_APPEAR_EVENT(countEvent++), GET_SHOULD_APPEAR_EXCEPTION(countException++), SHOULD_APPEAR + (countMessage++)); msLogger.LogCritical(GET_SHOULD_APPEAR_EVENT(countEvent++), GET_SHOULD_APPEAR_EXCEPTION(countException++), SHOULD_APPEAR + (countMessage++)); - var sdkLogger = loggerfactory.CreateLogger("AWSSDK"); + var sdkLogger = loggerFactory.CreateLogger("AWSSDK"); sdkLogger.LogTrace(SHOULD_NOT_APPEAR_EVENT, SHOULD_NOT_APPEAR_EXCEPTION, SHOULD_NOT_APPEAR); sdkLogger.LogInformation(GET_SHOULD_APPEAR_EVENT(countEvent++), GET_SHOULD_APPEAR_EXCEPTION(countException++), SHOULD_APPEAR + (countMessage++)); sdkLogger.LogCritical(GET_SHOULD_APPEAR_EVENT(countEvent++), GET_SHOULD_APPEAR_EXCEPTION(countException++), SHOULD_APPEAR + (countMessage++)); @@ -356,10 +356,10 @@ public void TestLoggingScopesEvents() ConnectLoggingActionToLogger(message => writer.Write(message)); var loggerOptions = new LambdaLoggerOptions{ IncludeScopes = true }; - var loggerfactory = new TestLoggerFactory() + var loggerFactory = new TestLoggerFactory() .AddLambdaLogger(loggerOptions); - var defaultLogger = loggerfactory.CreateLogger("Default"); + var defaultLogger = loggerFactory.CreateLogger("Default"); // Act using(defaultLogger.BeginScope("First {0}", "scope123")) @@ -391,10 +391,10 @@ public void TestLoggingScopesEvents_When_ScopesDisabled() ConnectLoggingActionToLogger(message => writer.Write(message)); var loggerOptions = new LambdaLoggerOptions { IncludeScopes = false }; - var loggerfactory = new TestLoggerFactory() + var loggerFactory = new TestLoggerFactory() .AddLambdaLogger(loggerOptions); - var defaultLogger = loggerfactory.CreateLogger("Default"); + var defaultLogger = loggerFactory.CreateLogger("Default"); // Act using (defaultLogger.BeginScope("First {0}", "scope123")) @@ -477,25 +477,25 @@ public void TestDefaultLogLevel() .Build(); var loggerOptions = new LambdaLoggerOptions(configuration); - var loggerfactory = new TestLoggerFactory() + var loggerFactory = new TestLoggerFactory() .AddLambdaLogger(loggerOptions); // act // creating named logger, `Default` category is set to "Debug" // (Default category has special treatment - it's not actually stored, named logger just falls to default) - var defaultLogger = loggerfactory.CreateLogger("Default"); + var defaultLogger = loggerFactory.CreateLogger("Default"); defaultLogger.LogTrace(SHOULD_NOT_APPEAR); defaultLogger.LogDebug(SHOULD_APPEAR); defaultLogger.LogInformation(SHOULD_APPEAR); // `Dummy` category is not specified, we should use `Default` category instead - var dummyLogger = loggerfactory.CreateLogger("Dummy"); + var dummyLogger = loggerFactory.CreateLogger("Dummy"); dummyLogger.LogTrace(SHOULD_NOT_APPEAR); dummyLogger.LogDebug(SHOULD_APPEAR); dummyLogger.LogInformation(SHOULD_APPEAR); // `Microsoft` category is specified, log accordingly - var msLogger = loggerfactory.CreateLogger("Microsoft"); + var msLogger = loggerFactory.CreateLogger("Microsoft"); msLogger.LogTrace(SHOULD_NOT_APPEAR); msLogger.LogDebug(SHOULD_NOT_APPEAR); msLogger.LogInformation(SHOULD_APPEAR); @@ -519,18 +519,18 @@ public void TestDefaultLogLevelIfNotConfigured() .Build(); var loggerOptions = new LambdaLoggerOptions(configuration); - var loggerfactory = new TestLoggerFactory() + var loggerFactory = new TestLoggerFactory() .AddLambdaLogger(loggerOptions); // act // `Dummy` category is not specified, we should stick with default: min level = INFO - var dummyLogger = loggerfactory.CreateLogger("Dummy"); + var dummyLogger = loggerFactory.CreateLogger("Dummy"); dummyLogger.LogTrace(SHOULD_NOT_APPEAR); dummyLogger.LogDebug(SHOULD_NOT_APPEAR); dummyLogger.LogInformation(SHOULD_APPEAR); // `Microsoft` category is specified, log accordingly - var msLogger = loggerfactory.CreateLogger("Microsoft"); + var msLogger = loggerFactory.CreateLogger("Microsoft"); msLogger.LogTrace(SHOULD_NOT_APPEAR); msLogger.LogDebug(SHOULD_NOT_APPEAR); msLogger.LogInformation(SHOULD_NOT_APPEAR); @@ -541,7 +541,47 @@ public void TestDefaultLogLevelIfNotConfigured() } } - private static string GetAppSettingsPath(string fileName) + /// + /// For this test we just need to make sure the _loggingWithLevelAndExceptionAction is called with parameters and exception. + /// We can't confirm the JSON formatting is done because RuntimeSupport is not involved. That is okay because we have + /// other tests that confirm RuntimeSupport formats the log as JSON. We jsut need to confirm the right callback is called + /// with the parameters from the log message. + /// + [Fact] + public void TestJSONParameterLogging() + { + Environment.SetEnvironmentVariable("AWS_LAMBDA_LOG_FORMAT", "JSON"); + try + { + using (var writer = new StringWriter()) + { + ConnectLoggingActionToLogger(message => writer.Write(message)); + + var configuration = new ConfigurationBuilder() + .AddJsonFile(GetAppSettingsPath("appsettings.json")) + .Build(); + + var loggerOptions = new LambdaLoggerOptions(configuration); + var loggerFactory = new TestLoggerFactory() + .AddLambdaLogger(loggerOptions); + + var logger = loggerFactory.CreateLogger("JSONLogging"); + + logger.LogError(new Exception("Too Cheap"), "User {name} fail to by {product} for {price}", "Gilmour", "Guitar", 55.55); + + var text = writer.ToString(); + Assert.Contains("parameter count: 3", text); + Assert.Contains("Too Cheap", text); + } + } + finally + { + Environment.SetEnvironmentVariable("AWS_LAMBDA_LOG_FORMAT", null); + } + + } + + private static string GetAppSettingsPath(string fileName) { return Path.Combine(APPSETTINGS_DIR, fileName); } @@ -567,6 +607,18 @@ private static void ConnectLoggingActionToLogger(Action loggingAction) Assert.NotNull(loggingActionField); loggingWithLevelActionField.SetValue(null, loggingWithLevelAction); + + Action loggingWithExceptionLevelAction = (level, exception, message, parameters) => { + var formattedMessage = $"{level}: {message}: parameter count: {parameters?.Length}\n{exception.Message}"; + loggingAction(formattedMessage); + }; + + var loggingWithExceptionLevelActionField = lambdaLoggerType + .GetTypeInfo() + .GetField("_loggingWithLevelAndExceptionAction", BindingFlags.NonPublic | BindingFlags.Static); + Assert.NotNull(loggingActionField); + + loggingWithExceptionLevelActionField.SetValue(null, loggingWithExceptionLevelAction); } private static int CountOccurences(string text, string substring)