Skip to content

Commit 4ea145b

Browse files
normjnormj
authored
Update Amazon.Lambda.Logging.AspNetCore to honor Lambda log config set to JSON (#2083)
This means the log message sent through the ILogger is converted into a parameterized log message allowing RuntimeSupport to create the JSON document
1 parent c7e126b commit 4ea145b

File tree

4 files changed

+164
-56
lines changed

4 files changed

+164
-56
lines changed

‎.autover/changes/5e73fa84-6603-4a1e-b957-2e1e926c5aa9.json‎

Lines changed: 32 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,32 @@
1+
{
2+
"Projects": [
3+
{
4+
"Name": "Amazon.Lambda.AspNetCoreServer",
5+
"Type": "Minor",
6+
"ChangelogMessages": [
7+
"Update Amazon.Lambda.Logging.AspNetCore dependency"
8+
]
9+
},
10+
{
11+
"Name": "Amazon.Lambda.AspNetCoreServer.Hosting",
12+
"Type": "Minor",
13+
"ChangelogMessages": [
14+
"Update Amazon.Lambda.Logging.AspNetCore dependency"
15+
]
16+
},
17+
{
18+
"Name": "Amazon.Lambda.Core",
19+
"Type": "Minor",
20+
"ChangelogMessages": [
21+
"Added log level with exception version of the static logging functions on Amazon.Lambda.Core.LambdaLogger"
22+
]
23+
},
24+
{
25+
"Name": "Amazon.Lambda.Logging.AspNetCore",
26+
"Type": "Minor",
27+
"ChangelogMessages": [
28+
"Convert logging parameters into JSON properties when Lambda log format is configured as JSON"
29+
]
30+
}
31+
]
32+
}

‎Libraries/src/Amazon.Lambda.Core/LambdaLogger.cs‎

Lines changed: 0 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -75,10 +75,6 @@ private static void LogWithLevelAndExceptionToConsole(string level, Exception ex
7575
Console.WriteLine(exception);
7676
}
7777

78-
private const string ParameterizedPreviewMessage =
79-
"This method has been mark as preview till the Lambda .NET Managed runtime has been updated with the backing implementation of this method. " +
80-
"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.";
81-
8278
/// <summary>
8379
/// Logs a message to AWS CloudWatch Logs.
8480
///
@@ -114,7 +110,6 @@ public static void Log(string level, string message, params object[] args)
114110
/// <param name="exception">Exception to include with the logging.</param>
115111
/// <param name="message">Message to log. The message may have format arguments.</param>
116112
/// <param name="args">Arguments to format the message with.</param>
117-
[RequiresPreviewFeatures(ParameterizedPreviewMessage)]
118113
public static void Log(string level, Exception exception, string message, params object[] args)
119114
{
120115
_loggingWithLevelAndExceptionAction(level, exception, message, args);
@@ -130,7 +125,6 @@ public static void Log(string level, Exception exception, string message, params
130125
/// <param name="exception">Exception to include with the logging.</param>
131126
/// <param name="message">Message to log. The message may have format arguments.</param>
132127
/// <param name="args">Arguments to format the message with.</param>
133-
[RequiresPreviewFeatures(ParameterizedPreviewMessage)]
134128
public static void Log(LogLevel level, Exception exception, string message, params object[] args) => Log(level.ToString(), exception, message, args);
135129
#endif
136130
}

‎Libraries/src/Amazon.Lambda.Logging.AspNetCore/LambdaILogger.cs‎

Lines changed: 58 additions & 28 deletions
Original file line numberDiff line numberDiff line change
@@ -52,39 +52,61 @@ public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Except
5252
return;
5353
}
5454

55-
var components = new List<string>(4);
56-
if (_options.IncludeLogLevel)
57-
{
58-
components.Add($"[{logLevel}]");
59-
}
60-
61-
GetScopeInformation(components);
55+
var lambdaLogLevel = ConvertLogLevel(logLevel);
6256

63-
if (_options.IncludeCategory)
57+
if (IsLambdaJsonFormatEnabled && state is IEnumerable<KeyValuePair<string, object>> structure)
6458
{
65-
components.Add($"{_categoryName}:");
59+
string messageTemplate = null;
60+
var parameters = new List<object>();
61+
foreach (var property in structure)
62+
{
63+
if (property is { Key: "{OriginalFormat}", Value: string value })
64+
{
65+
messageTemplate = value;
66+
}
67+
else
68+
{
69+
parameters.Add(property.Value);
70+
}
71+
}
72+
73+
Amazon.Lambda.Core.LambdaLogger.Log(lambdaLogLevel, exception, messageTemplate, parameters.ToArray());
6674
}
67-
if (_options.IncludeEventId)
75+
else
6876
{
69-
components.Add($"[{eventId}]:");
70-
}
77+
var components = new List<string>(4);
78+
if (_options.IncludeLogLevel)
79+
{
80+
components.Add($"[{logLevel}]");
81+
}
7182

72-
var text = formatter.Invoke(state, exception);
73-
components.Add(text);
83+
GetScopeInformation(components);
7484

75-
if (_options.IncludeException)
76-
{
77-
components.Add($"{exception}");
78-
}
79-
if (_options.IncludeNewline)
80-
{
81-
components.Add(Environment.NewLine);
82-
}
85+
if (_options.IncludeCategory)
86+
{
87+
components.Add($"{_categoryName}:");
88+
}
89+
if (_options.IncludeEventId)
90+
{
91+
components.Add($"[{eventId}]:");
92+
}
8393

84-
var finalText = string.Join(" ", components);
94+
var text = formatter.Invoke(state, exception);
95+
components.Add(text);
8596

86-
var lambdaLogLevel = ConvertLogLevel(logLevel);
87-
Amazon.Lambda.Core.LambdaLogger.Log(lambdaLogLevel, finalText);
97+
if (_options.IncludeException)
98+
{
99+
components.Add($"{exception}");
100+
}
101+
if (_options.IncludeNewline)
102+
{
103+
components.Add(Environment.NewLine);
104+
}
105+
106+
var finalText = string.Join(" ", components);
107+
108+
Amazon.Lambda.Core.LambdaLogger.Log(lambdaLogLevel, finalText);
109+
}
88110
}
89111

90112
private static Amazon.Lambda.Core.LogLevel ConvertLogLevel(LogLevel logLevel)
@@ -126,9 +148,17 @@ private void GetScopeInformation(List<string> logMessageComponents)
126148
logMessageComponents.Add("=>");
127149
}
128150
}
129-
}
130-
131-
// Private classes
151+
}
152+
153+
private bool IsLambdaJsonFormatEnabled
154+
{
155+
get
156+
{
157+
return string.Equals(Environment.GetEnvironmentVariable("AWS_LAMBDA_LOG_FORMAT"), "JSON", StringComparison.InvariantCultureIgnoreCase);
158+
}
159+
}
160+
161+
// Private classes
132162
private class NoOpDisposable : IDisposable
133163
{
134164
public void Dispose()

‎Libraries/test/Amazon.Lambda.Logging.AspNetCore.Tests/LoggingTests.cs‎

Lines changed: 74 additions & 22 deletions
Original file line numberDiff line numberDiff line change
@@ -118,14 +118,14 @@ public void TestWilcardConfiguration()
118118
Assert.False(loggerOptions.IncludeLogLevel);
119119
Assert.False(loggerOptions.IncludeNewline);
120120

121-
var loggerfactory = new TestLoggerFactory()
121+
var loggerFactory = new TestLoggerFactory()
122122
.AddLambdaLogger(loggerOptions);
123123

124124
int count = 0;
125125

126126
// Should match:
127127
// "Foo.*": "Information"
128-
var foobarLogger = loggerfactory.CreateLogger("Foo.Bar");
128+
var foobarLogger = loggerFactory.CreateLogger("Foo.Bar");
129129
foobarLogger.LogTrace(SHOULD_NOT_APPEAR);
130130
foobarLogger.LogDebug(SHOULD_NOT_APPEAR);
131131
foobarLogger.LogInformation(SHOULD_APPEAR + (count++));
@@ -135,7 +135,7 @@ public void TestWilcardConfiguration()
135135

136136
// Should match:
137137
// "Foo.Bar.Baz": "Critical"
138-
var foobarbazLogger = loggerfactory.CreateLogger("Foo.Bar.Baz");
138+
var foobarbazLogger = loggerFactory.CreateLogger("Foo.Bar.Baz");
139139
foobarbazLogger.LogTrace(SHOULD_NOT_APPEAR);
140140
foobarbazLogger.LogDebug(SHOULD_NOT_APPEAR);
141141
foobarbazLogger.LogInformation(SHOULD_NOT_APPEAR);
@@ -145,7 +145,7 @@ public void TestWilcardConfiguration()
145145

146146
// Should match:
147147
// "Foo.Bar.*": "Warning"
148-
var foobarbuzzLogger = loggerfactory.CreateLogger("Foo.Bar.Buzz");
148+
var foobarbuzzLogger = loggerFactory.CreateLogger("Foo.Bar.Buzz");
149149
foobarbuzzLogger.LogTrace(SHOULD_NOT_APPEAR);
150150
foobarbuzzLogger.LogDebug(SHOULD_NOT_APPEAR);
151151
foobarbuzzLogger.LogInformation(SHOULD_NOT_APPEAR);
@@ -156,7 +156,7 @@ public void TestWilcardConfiguration()
156156

157157
// Should match:
158158
// "*": "Error"
159-
var somethingLogger = loggerfactory.CreateLogger("something");
159+
var somethingLogger = loggerFactory.CreateLogger("something");
160160
somethingLogger.LogTrace(SHOULD_NOT_APPEAR);
161161
somethingLogger.LogDebug(SHOULD_NOT_APPEAR);
162162
somethingLogger.LogInformation(SHOULD_NOT_APPEAR);
@@ -285,19 +285,19 @@ public void TestLoggingExceptionsAndEvents()
285285
.Build();
286286

287287
var loggerOptions = new LambdaLoggerOptions(configuration);
288-
var loggerfactory = new TestLoggerFactory()
288+
var loggerFactory = new TestLoggerFactory()
289289
.AddLambdaLogger(loggerOptions);
290290

291291
int countMessage = 0;
292292
int countEvent = 0;
293293
int countException = 0;
294294

295-
var defaultLogger = loggerfactory.CreateLogger("Default");
295+
var defaultLogger = loggerFactory.CreateLogger("Default");
296296
defaultLogger.LogTrace(SHOULD_NOT_APPEAR_EVENT, SHOULD_NOT_APPEAR_EXCEPTION, SHOULD_NOT_APPEAR);
297297
defaultLogger.LogDebug(SHOULD_NOT_APPEAR_EVENT, SHOULD_APPEAR + (countMessage++));
298298
defaultLogger.LogCritical(SHOULD_NOT_APPEAR_EVENT, SHOULD_APPEAR + (countMessage++));
299299

300-
defaultLogger = loggerfactory.CreateLogger(null);
300+
defaultLogger = loggerFactory.CreateLogger(null);
301301
defaultLogger.LogTrace(SHOULD_NOT_APPEAR_EVENT, SHOULD_NOT_APPEAR);
302302
defaultLogger.LogDebug(SHOULD_NOT_APPEAR_EVENT, SHOULD_APPEAR + (countMessage++));
303303
defaultLogger.LogCritical(SHOULD_NOT_APPEAR_EVENT, SHOULD_APPEAR + (countMessage++));
@@ -309,12 +309,12 @@ public void TestLoggingExceptionsAndEvents()
309309
loggerOptions.IncludeException = true;
310310
loggerOptions.IncludeEventId = true;
311311

312-
var msLogger = loggerfactory.CreateLogger("Microsoft");
312+
var msLogger = loggerFactory.CreateLogger("Microsoft");
313313
msLogger.LogTrace(SHOULD_NOT_APPEAR_EVENT, SHOULD_NOT_APPEAR_EXCEPTION, SHOULD_NOT_APPEAR);
314314
msLogger.LogInformation(GET_SHOULD_APPEAR_EVENT(countEvent++), GET_SHOULD_APPEAR_EXCEPTION(countException++), SHOULD_APPEAR + (countMessage++));
315315
msLogger.LogCritical(GET_SHOULD_APPEAR_EVENT(countEvent++), GET_SHOULD_APPEAR_EXCEPTION(countException++), SHOULD_APPEAR + (countMessage++));
316316

317-
var sdkLogger = loggerfactory.CreateLogger("AWSSDK");
317+
var sdkLogger = loggerFactory.CreateLogger("AWSSDK");
318318
sdkLogger.LogTrace(SHOULD_NOT_APPEAR_EVENT, SHOULD_NOT_APPEAR_EXCEPTION, SHOULD_NOT_APPEAR);
319319
sdkLogger.LogInformation(GET_SHOULD_APPEAR_EVENT(countEvent++), GET_SHOULD_APPEAR_EXCEPTION(countException++), SHOULD_APPEAR + (countMessage++));
320320
sdkLogger.LogCritical(GET_SHOULD_APPEAR_EVENT(countEvent++), GET_SHOULD_APPEAR_EXCEPTION(countException++), SHOULD_APPEAR + (countMessage++));
@@ -356,10 +356,10 @@ public void TestLoggingScopesEvents()
356356
ConnectLoggingActionToLogger(message => writer.Write(message));
357357

358358
var loggerOptions = new LambdaLoggerOptions{ IncludeScopes = true };
359-
var loggerfactory = new TestLoggerFactory()
359+
var loggerFactory = new TestLoggerFactory()
360360
.AddLambdaLogger(loggerOptions);
361361

362-
var defaultLogger = loggerfactory.CreateLogger("Default");
362+
var defaultLogger = loggerFactory.CreateLogger("Default");
363363

364364
// Act
365365
using(defaultLogger.BeginScope("First {0}", "scope123"))
@@ -391,10 +391,10 @@ public void TestLoggingScopesEvents_When_ScopesDisabled()
391391
ConnectLoggingActionToLogger(message => writer.Write(message));
392392

393393
var loggerOptions = new LambdaLoggerOptions { IncludeScopes = false };
394-
var loggerfactory = new TestLoggerFactory()
394+
var loggerFactory = new TestLoggerFactory()
395395
.AddLambdaLogger(loggerOptions);
396396

397-
var defaultLogger = loggerfactory.CreateLogger("Default");
397+
var defaultLogger = loggerFactory.CreateLogger("Default");
398398

399399
// Act
400400
using (defaultLogger.BeginScope("First {0}", "scope123"))
@@ -477,25 +477,25 @@ public void TestDefaultLogLevel()
477477
.Build();
478478

479479
var loggerOptions = new LambdaLoggerOptions(configuration);
480-
var loggerfactory = new TestLoggerFactory()
480+
var loggerFactory = new TestLoggerFactory()
481481
.AddLambdaLogger(loggerOptions);
482482

483483
// act
484484
// creating named logger, `Default` category is set to "Debug"
485485
// (Default category has special treatment - it's not actually stored, named logger just falls to default)
486-
var defaultLogger = loggerfactory.CreateLogger("Default");
486+
var defaultLogger = loggerFactory.CreateLogger("Default");
487487
defaultLogger.LogTrace(SHOULD_NOT_APPEAR);
488488
defaultLogger.LogDebug(SHOULD_APPEAR);
489489
defaultLogger.LogInformation(SHOULD_APPEAR);
490490

491491
// `Dummy` category is not specified, we should use `Default` category instead
492-
var dummyLogger = loggerfactory.CreateLogger("Dummy");
492+
var dummyLogger = loggerFactory.CreateLogger("Dummy");
493493
dummyLogger.LogTrace(SHOULD_NOT_APPEAR);
494494
dummyLogger.LogDebug(SHOULD_APPEAR);
495495
dummyLogger.LogInformation(SHOULD_APPEAR);
496496

497497
// `Microsoft` category is specified, log accordingly
498-
var msLogger = loggerfactory.CreateLogger("Microsoft");
498+
var msLogger = loggerFactory.CreateLogger("Microsoft");
499499
msLogger.LogTrace(SHOULD_NOT_APPEAR);
500500
msLogger.LogDebug(SHOULD_NOT_APPEAR);
501501
msLogger.LogInformation(SHOULD_APPEAR);
@@ -519,18 +519,18 @@ public void TestDefaultLogLevelIfNotConfigured()
519519
.Build();
520520

521521
var loggerOptions = new LambdaLoggerOptions(configuration);
522-
var loggerfactory = new TestLoggerFactory()
522+
var loggerFactory = new TestLoggerFactory()
523523
.AddLambdaLogger(loggerOptions);
524524

525525
// act
526526
// `Dummy` category is not specified, we should stick with default: min level = INFO
527-
var dummyLogger = loggerfactory.CreateLogger("Dummy");
527+
var dummyLogger = loggerFactory.CreateLogger("Dummy");
528528
dummyLogger.LogTrace(SHOULD_NOT_APPEAR);
529529
dummyLogger.LogDebug(SHOULD_NOT_APPEAR);
530530
dummyLogger.LogInformation(SHOULD_APPEAR);
531531

532532
// `Microsoft` category is specified, log accordingly
533-
var msLogger = loggerfactory.CreateLogger("Microsoft");
533+
var msLogger = loggerFactory.CreateLogger("Microsoft");
534534
msLogger.LogTrace(SHOULD_NOT_APPEAR);
535535
msLogger.LogDebug(SHOULD_NOT_APPEAR);
536536
msLogger.LogInformation(SHOULD_NOT_APPEAR);
@@ -541,7 +541,47 @@ public void TestDefaultLogLevelIfNotConfigured()
541541
}
542542
}
543543

544-
private static string GetAppSettingsPath(string fileName)
544+
/// <summary>
545+
/// For this test we just need to make sure the _loggingWithLevelAndExceptionAction is called with parameters and exception.
546+
/// We can't confirm the JSON formatting is done because RuntimeSupport is not involved. That is okay because we have
547+
/// other tests that confirm RuntimeSupport formats the log as JSON. We jsut need to confirm the right callback is called
548+
/// with the parameters from the log message.
549+
/// </summary>
550+
[Fact]
551+
public void TestJSONParameterLogging()
552+
{
553+
Environment.SetEnvironmentVariable("AWS_LAMBDA_LOG_FORMAT", "JSON");
554+
try
555+
{
556+
using (var writer = new StringWriter())
557+
{
558+
ConnectLoggingActionToLogger(message => writer.Write(message));
559+
560+
var configuration = new ConfigurationBuilder()
561+
.AddJsonFile(GetAppSettingsPath("appsettings.json"))
562+
.Build();
563+
564+
var loggerOptions = new LambdaLoggerOptions(configuration);
565+
var loggerFactory = new TestLoggerFactory()
566+
.AddLambdaLogger(loggerOptions);
567+
568+
var logger = loggerFactory.CreateLogger("JSONLogging");
569+
570+
logger.LogError(new Exception("Too Cheap"), "User {name} fail to by {product} for {price}", "Gilmour", "Guitar", 55.55);
571+
572+
var text = writer.ToString();
573+
Assert.Contains("parameter count: 3", text);
574+
Assert.Contains("Too Cheap", text);
575+
}
576+
}
577+
finally
578+
{
579+
Environment.SetEnvironmentVariable("AWS_LAMBDA_LOG_FORMAT", null);
580+
}
581+
582+
}
583+
584+
private static string GetAppSettingsPath(string fileName)
545585
{
546586
return Path.Combine(APPSETTINGS_DIR, fileName);
547587
}
@@ -567,6 +607,18 @@ private static void ConnectLoggingActionToLogger(Action<string> loggingAction)
567607
Assert.NotNull(loggingActionField);
568608

569609
loggingWithLevelActionField.SetValue(null, loggingWithLevelAction);
610+
611+
Action<string, Exception, string, object[]> loggingWithExceptionLevelAction = (level, exception, message, parameters) => {
612+
var formattedMessage = $"{level}: {message}: parameter count: {parameters?.Length}\n{exception.Message}";
613+
loggingAction(formattedMessage);
614+
};
615+
616+
var loggingWithExceptionLevelActionField = lambdaLoggerType
617+
.GetTypeInfo()
618+
.GetField("_loggingWithLevelAndExceptionAction", BindingFlags.NonPublic | BindingFlags.Static);
619+
Assert.NotNull(loggingActionField);
620+
621+
loggingWithExceptionLevelActionField.SetValue(null, loggingWithExceptionLevelAction);
570622
}
571623

572624
private static int CountOccurences(string text, string substring)

0 commit comments

Comments
 (0)