Skip to content

Commit ca1c715

Browse files
hjgracahjgraca
committed
Add warning message when lambda and PT log level different
Add tests
1 parent fc742d7 commit ca1c715

File tree

9 files changed

+187
-38
lines changed

9 files changed

+187
-38
lines changed

‎docs/core/logging.md‎

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -29,6 +29,10 @@ Setting | Description | Environment variable | Attribute parameter
2929
**Service** | Sets **Service** key that will be present across all log statements | `POWERTOOLS_SERVICE_NAME` | `Service`
3030
**Logging level** | Sets how verbose Logger should be (Information, by default) | `POWERTOOLS_LOG_LEVEL` | `LogLevel`
3131

32+
!!! warning "When using Lambda Log Format JSON"
33+
- And Powertools Logger output is set to `PascalCase` **`Level`** property name will be replaced by **`LogLevel`** as a property name.
34+
- The Lambda Application log level setting will control what is sent to CloudWatch. It takes precedence over **`POWERTOOLS_LOG_LEVEL`** and when setting it in code using **`[Logging(LogLevel = )]`**
35+
3236
### Example using AWS Serverless Application Model (AWS SAM)
3337

3438
You can override log level by setting **`POWERTOOLS_LOG_LEVEL`** environment variable in the AWS SAM template.

‎libraries/src/AWS.Lambda.Powertools.Common/Core/Constants.cs‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -58,7 +58,7 @@ internal static class Constants
5858
/// <summary>
5959
/// Constant for POWERTOOLS_LOG_LEVEL environment variable
6060
/// </summary>
61-
internal const string AwsLogLevelNameEnv = "AWS_LAMBDA_LOG_LEVEL";
61+
internal const string AWSLambdaLogLevelNameEnv = "AWS_LAMBDA_LOG_LEVEL";
6262

6363
/// <summary>
6464
/// Constant for POWERTOOLS_LOGGER_SAMPLE_RATE environment variable

‎libraries/src/AWS.Lambda.Powertools.Common/Core/IPowertoolsConfigurations.cs‎

Lines changed: 7 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -57,10 +57,16 @@ public interface IPowertoolsConfigurations
5757
string MetricsNamespace { get; }
5858

5959
/// <summary>
60-
/// Gets the log level.
60+
/// Gets the Powertools log level.
6161
/// </summary>
6262
/// <value>The log level.</value>
6363
string LogLevel { get; }
64+
65+
/// <summary>
66+
/// Gets the AWS Lambda log level.
67+
/// </summary>
68+
/// <value>The log level.</value>
69+
string AWSLambdaLogLevel { get; }
6470

6571
/// <summary>
6672
/// Gets the logger sample rate.

‎libraries/src/AWS.Lambda.Powertools.Common/Core/PowertoolsConfigurations.cs‎

Lines changed: 5 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -147,13 +147,11 @@ public bool GetEnvironmentVariableOrDefault(string variable, bool defaultValue)
147147
public string MetricsNamespace =>
148148
GetEnvironmentVariable(Constants.MetricsNamespaceEnv);
149149

150-
/// <summary>
151-
/// Gets the log level.
152-
/// Dont' use this method directly use GetLogLevel extension method instead
153-
/// </summary>
154-
/// <value>The log level.</value>
155-
public string LogLevel =>
156-
GetEnvironmentVariableOrDefault(Constants.LogLevelNameEnv, GetEnvironmentVariable(Constants.AwsLogLevelNameEnv));
150+
/// <inheritdoc />
151+
public string LogLevel => GetEnvironmentVariable(Constants.LogLevelNameEnv);
152+
153+
/// <inheritdoc />
154+
public string AWSLambdaLogLevel => GetEnvironmentVariable(Constants.AWSLambdaLogLevelNameEnv);
157155

158156
/// <summary>
159157
/// Gets the logger sample rate.

‎libraries/src/AWS.Lambda.Powertools.Common/Core/SystemWrapper.cs‎

Lines changed: 19 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -1,19 +1,20 @@
11
/*
22
* Copyright Amazon.com, Inc. or its affiliates. All Rights Reserved.
3-
*
3+
*
44
* Licensed under the Apache License, Version 2.0 (the "License").
55
* You may not use this file except in compliance with the License.
66
* A copy of the License is located at
7-
*
7+
*
88
* http://aws.amazon.com/apache2.0
9-
*
9+
*
1010
* or in the "license" file accompanying this file. This file is distributed
1111
* on an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either
1212
* express or implied. See the License for the specific language governing
1313
* permissions and limitations under the License.
1414
*/
1515

1616
using System;
17+
using System.IO;
1718
using System.Text;
1819

1920
namespace AWS.Lambda.Powertools.Common;
@@ -39,6 +40,15 @@ public SystemWrapper(IPowertoolsEnvironment powertoolsEnvironment)
3940
{
4041
_powertoolsEnvironment = powertoolsEnvironment;
4142
_instance ??= this;
43+
44+
45+
// Clear AWS SDK Console injected parameters StdOut and StdErr
46+
var standardOutput = new StreamWriter(Console.OpenStandardOutput());
47+
standardOutput.AutoFlush = true;
48+
Console.SetOut(standardOutput);
49+
var errordOutput = new StreamWriter(Console.OpenStandardError());
50+
errordOutput.AutoFlush = true;
51+
Console.SetError(errordOutput);
4252
}
4353

4454
/// <summary>
@@ -97,21 +107,21 @@ public void SetExecutionEnvironment<T>(T type)
97107
var envValue = new StringBuilder();
98108
var currentEnvValue = GetEnvironmentVariable(envName);
99109
var assemblyName = ParseAssemblyName(_powertoolsEnvironment.GetAssemblyName(type));
100-
110+
101111
// If there is an existing execution environment variable add the annotations package as a suffix.
102-
if(!string.IsNullOrEmpty(currentEnvValue))
112+
if (!string.IsNullOrEmpty(currentEnvValue))
103113
{
104114
// Avoid duplication - should not happen since the calling Instances are Singletons - defensive purposes
105115
if (currentEnvValue.Contains(assemblyName))
106116
{
107117
return;
108118
}
109-
119+
110120
envValue.Append($"{currentEnvValue} ");
111121
}
112122

113123
var assemblyVersion = _powertoolsEnvironment.GetAssemblyVersion(type);
114-
124+
115125
envValue.Append($"{assemblyName}/{assemblyVersion}");
116126

117127
SetEnvironmentVariable(envName, envValue.ToString());
@@ -127,13 +137,14 @@ private string ParseAssemblyName(string assemblyName)
127137
{
128138
try
129139
{
130-
var parsedName = assemblyName.Substring(assemblyName.LastIndexOf(".", StringComparison.Ordinal)+1);
140+
var parsedName = assemblyName.Substring(assemblyName.LastIndexOf(".", StringComparison.Ordinal) + 1);
131141
return $"{Constants.FeatureContextIdentifier}/{parsedName}";
132142
}
133143
catch
134144
{
135145
//NOOP
136146
}
147+
137148
return $"{Constants.FeatureContextIdentifier}/{assemblyName}";
138149
}
139150
}

‎libraries/src/AWS.Lambda.Powertools.Logging/Internal/PowertoolsConfigurations.cs‎

Lines changed: 14 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -37,17 +37,25 @@ internal static LogLevel GetLogLevel(this IPowertoolsConfigurations powertoolsCo
3737
if (logLevel.HasValue)
3838
return logLevel.Value;
3939

40-
var logFromEnv = (powertoolsConfigurations.LogLevel ?? "").Trim();
41-
42-
if (AwsLogLevelMapper.TryGetValue(logFromEnv.ToUpper(), out var awsLogLevel))
43-
logFromEnv = awsLogLevel;
44-
45-
if (Enum.TryParse(logFromEnv, true, out LogLevel result))
40+
if (Enum.TryParse((powertoolsConfigurations.LogLevel ?? "").Trim(), true, out LogLevel result))
4641
return result;
4742

4843
return LoggingConstants.DefaultLogLevel;
4944
}
5045

46+
internal static LogLevel GetLambdaLogLevel(this IPowertoolsConfigurations powertoolsConfigurations)
47+
{
48+
AwsLogLevelMapper.TryGetValue((powertoolsConfigurations.AWSLambdaLogLevel ?? "").Trim().ToUpper(), out var awsLogLevel);
49+
50+
if (Enum.TryParse(awsLogLevel, true, out LogLevel result))
51+
{
52+
//Logger.LogWarning("Oopss!!");
53+
return result;
54+
}
55+
56+
return LogLevel.None;
57+
}
58+
5159
internal static LoggerOutputCase GetLoggerOutputCase(this IPowertoolsConfigurations powertoolsConfigurations,
5260
LoggerOutputCase? loggerOutputCase = null)
5361
{

‎libraries/src/AWS.Lambda.Powertools.Logging/Internal/PowertoolsLogger.cs‎

Lines changed: 33 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -61,6 +61,10 @@ internal sealed class PowertoolsLogger : ILogger
6161
/// </summary>
6262
private JsonSerializerOptions _jsonSerializerOptions;
6363

64+
private LogLevel _lambdaLogLevel;
65+
private LogLevel _logLevel;
66+
private bool _lambdaLogLevelEnabled;
67+
6468
/// <summary>
6569
/// Initializes a new instance of the <see cref="PowertoolsLogger" /> class.
6670
/// </summary>
@@ -78,14 +82,17 @@ public PowertoolsLogger(
7882
powertoolsConfigurations, systemWrapper, getCurrentConfig);
7983

8084
_powertoolsConfigurations.SetExecutionEnvironment(this);
85+
CurrentConfig = GetCurrentConfig();
86+
87+
if (_lambdaLogLevelEnabled && _logLevel < _lambdaLogLevel)
88+
{
89+
var message =
90+
$"Current log level ({_logLevel}) does not match AWS Lambda Advanced Logging Controls minimum log level ({_lambdaLogLevel}). This can lead to data loss, consider adjusting them.";
91+
this.LogWarning(message);
92+
}
8193
}
8294

83-
/// <summary>
84-
/// Sets the current configuration.
85-
/// </summary>
86-
/// <value>The current configuration.</value>
87-
private LoggerConfiguration CurrentConfig =>
88-
_currentConfig ??= GetCurrentConfig();
95+
private LoggerConfiguration CurrentConfig { get; }
8996

9097
/// <summary>
9198
/// Sets the minimum level.
@@ -255,8 +262,15 @@ private Dictionary<string, object> GetLogEntry(LogLevel logLevel, DateTime times
255262
}
256263
}
257264

265+
var keyLogLevel = LoggingConstants.KeyLogLevel;
266+
// If ALC is enabled and PascalCase we need to convert Level to LogLevel for it to be parsed and sent to CW
267+
if (_lambdaLogLevelEnabled && CurrentConfig.LoggerOutputCase == LoggerOutputCase.PascalCase)
268+
{
269+
keyLogLevel = "LogLevel";
270+
}
271+
258272
logEntry.TryAdd(LoggingConstants.KeyTimestamp, timestamp.ToString("o"));
259-
logEntry.TryAdd(LoggingConstants.KeyLogLevel, logLevel.ToString());
273+
logEntry.TryAdd(keyLogLevel, logLevel.ToString());
260274
logEntry.TryAdd(LoggingConstants.KeyService, Service);
261275
logEntry.TryAdd(LoggingConstants.KeyLoggerName, _name);
262276
logEntry.TryAdd(LoggingConstants.KeyMessage, message);
@@ -371,14 +385,22 @@ internal void ClearConfig()
371385
private LoggerConfiguration GetCurrentConfig()
372386
{
373387
var currConfig = _getCurrentConfig();
374-
var minimumLevel = _powertoolsConfigurations.GetLogLevel(currConfig?.MinimumLevel);
388+
_logLevel = _powertoolsConfigurations.GetLogLevel(currConfig?.MinimumLevel);
375389
var samplingRate = currConfig?.SamplingRate ?? _powertoolsConfigurations.LoggerSampleRate;
376390
var loggerOutputCase = _powertoolsConfigurations.GetLoggerOutputCase(currConfig?.LoggerOutputCase);
377-
391+
_lambdaLogLevel = _powertoolsConfigurations.GetLambdaLogLevel();
392+
_lambdaLogLevelEnabled = _lambdaLogLevel != LogLevel.None;
393+
394+
var minLogLevel = _logLevel;
395+
if (_lambdaLogLevelEnabled)
396+
{
397+
minLogLevel = _lambdaLogLevel;
398+
}
399+
378400
var config = new LoggerConfiguration
379401
{
380402
Service = currConfig?.Service,
381-
MinimumLevel = minimumLevel,
403+
MinimumLevel = minLogLevel,
382404
SamplingRate = samplingRate,
383405
LoggerOutputCase = loggerOutputCase
384406
};
@@ -388,7 +410,7 @@ private LoggerConfiguration GetCurrentConfig()
388410

389411
if (samplingRate.Value < 0 || samplingRate.Value > 1)
390412
{
391-
if (minimumLevel is LogLevel.Debug or LogLevel.Trace)
413+
if (minLogLevel is LogLevel.Debug or LogLevel.Trace)
392414
_systemWrapper.LogLine(
393415
$"Skipping sampling rate configuration because of invalid value. Sampling rate: {samplingRate.Value}");
394416
config.SamplingRate = null;

‎libraries/tests/AWS.Lambda.Powertools.Logging.Tests/PowertoolsLoggerTest.cs‎

Lines changed: 100 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -1349,7 +1349,6 @@ public void Log_Should_Use_Powertools_Log_Level_When_Lambda_Log_Level_Enabled(bo
13491349
[Theory]
13501350
[InlineData(true, "WARN", LogLevel.Warning)]
13511351
[InlineData(false, "Fatal", LogLevel.Critical)]
1352-
[InlineData(true, "NotValid", LogLevel.Information)]
13531352
public void Log_Should_Use_AWS_Lambda_Log_Level_When_Enabled(bool willLog, string awsLogLevel, LogLevel logLevel)
13541353
{
13551354
// Arrange
@@ -1381,18 +1380,115 @@ public void Log_Should_Use_AWS_Lambda_Log_Level_When_Enabled(bool willLog, strin
13811380

13821381
// Assert
13831382
Assert.True(logger.IsEnabled(logLevel));
1384-
Assert.Equal(logLevel, configuration.GetLogLevel());
1383+
Assert.Equal(LogLevel.Information, configuration.GetLogLevel()); //default
1384+
Assert.Equal(logLevel, configuration.GetLambdaLogLevel());
13851385
Assert.Equal(willLog, systemWrapper.LogMethodCalled);
13861386
}
13871387

1388+
[Fact]
1389+
public void Log_Should_Show_Warning_When_AWS_Lambda_Log_Level_Enabled()
1390+
{
1391+
// Arrange
1392+
var loggerName = Guid.NewGuid().ToString();
1393+
1394+
var environment = Substitute.For<IPowertoolsEnvironment>();
1395+
environment.GetEnvironmentVariable("POWERTOOLS_LOG_LEVEL").Returns("Debug");
1396+
environment.GetEnvironmentVariable("AWS_LAMBDA_LOG_LEVEL").Returns("Warn");
1397+
1398+
var systemWrapper = new SystemWrapperMock(environment);
1399+
var configuration = new PowertoolsConfigurations(systemWrapper);
1400+
1401+
var logger = new PowertoolsLogger(loggerName, configuration, systemWrapper, () =>
1402+
new LoggerConfiguration
1403+
{
1404+
LoggerOutputCase = LoggerOutputCase.CamelCase
1405+
});
1406+
1407+
var logLevel = configuration.GetLogLevel();
1408+
var lambdaLogLevel = configuration.GetLambdaLogLevel();
1409+
1410+
// Assert
1411+
Assert.True(logger.IsEnabled(LogLevel.Warning));
1412+
Assert.Equal(LogLevel.Debug, logLevel);
1413+
Assert.Equal(LogLevel.Warning, lambdaLogLevel);
1414+
Assert.True(systemWrapper.LogMethodCalled);
1415+
Assert.Contains($"Current log level ({logLevel}) does not match AWS Lambda Advanced Logging Controls minimum log level ({lambdaLogLevel}). This can lead to data loss, consider adjusting them.",
1416+
systemWrapper.LogMethodCalledWithArgument);
1417+
}
1418+
1419+
[Theory]
1420+
[InlineData(true,"LogLevel")]
1421+
[InlineData(false,"Level")]
1422+
public void Log_PascalCase_Outputs_Correct_Level_Property_When_AWS_Lambda_Log_Level_Enabled_Or_Disabled(bool alcEnabled, string levelProp)
1423+
{
1424+
// Arrange
1425+
var loggerName = Guid.NewGuid().ToString();
1426+
1427+
var environment = Substitute.For<IPowertoolsEnvironment>();
1428+
environment.GetEnvironmentVariable("POWERTOOLS_LOG_LEVEL").Returns("Information");
1429+
if(alcEnabled)
1430+
environment.GetEnvironmentVariable("AWS_LAMBDA_LOG_LEVEL").Returns("Info");
1431+
1432+
var systemWrapper = new SystemWrapperMock(environment);
1433+
var configuration = new PowertoolsConfigurations(systemWrapper);
1434+
var logger = new PowertoolsLogger(loggerName, configuration, systemWrapper, () =>
1435+
new LoggerConfiguration
1436+
{
1437+
LoggerOutputCase = LoggerOutputCase.PascalCase
1438+
});
1439+
1440+
var message = new
1441+
{
1442+
PropOne = "Value 1",
1443+
};
1444+
1445+
logger.LogInformation(message);
1446+
1447+
// Assert
1448+
Assert.True(systemWrapper.LogMethodCalled);
1449+
Assert.Contains($"\"{levelProp}\":\"Information\"",systemWrapper.LogMethodCalledWithArgument);
1450+
}
1451+
1452+
[Theory]
1453+
[InlineData(LoggerOutputCase.CamelCase)]
1454+
[InlineData(LoggerOutputCase.SnakeCase)]
1455+
public void Log_CamelCase_Outputs_Level_When_AWS_Lambda_Log_Level_Enabled(LoggerOutputCase casing)
1456+
{
1457+
// Arrange
1458+
var loggerName = Guid.NewGuid().ToString();
1459+
1460+
var environment = Substitute.For<IPowertoolsEnvironment>();
1461+
environment.GetEnvironmentVariable("POWERTOOLS_LOG_LEVEL").Returns(string.Empty);
1462+
environment.GetEnvironmentVariable("AWS_LAMBDA_LOG_LEVEL").Returns("Info");
1463+
1464+
var systemWrapper = new SystemWrapperMock(environment);
1465+
var configuration = new PowertoolsConfigurations(systemWrapper);
1466+
var logger = new PowertoolsLogger(loggerName, configuration, systemWrapper, () =>
1467+
new LoggerConfiguration
1468+
{
1469+
LoggerOutputCase = casing
1470+
});
1471+
1472+
var message = new
1473+
{
1474+
PropOne = "Value 1",
1475+
};
1476+
1477+
logger.LogInformation(message);
1478+
1479+
// Assert
1480+
Assert.True(systemWrapper.LogMethodCalled);
1481+
Assert.Contains("\"level\":\"Information\"",systemWrapper.LogMethodCalledWithArgument);
1482+
}
1483+
13881484
[Theory]
13891485
[InlineData("TRACE", LogLevel.Trace)]
13901486
[InlineData("debug", LogLevel.Debug)]
13911487
[InlineData("Info", LogLevel.Information)]
13921488
[InlineData("WARN", LogLevel.Warning)]
13931489
[InlineData("ERROR", LogLevel.Error)]
13941490
[InlineData("Fatal", LogLevel.Critical)]
1395-
[InlineData("DoesNotExist", LogLevel.Information)]
1491+
[InlineData("DoesNotExist", LogLevel.None)]
13961492
public void Should_Map_AWS_Log_Level_And_Default_To_Information(string awsLogLevel, LogLevel logLevel)
13971493
{
13981494
// Arrange
@@ -1403,7 +1499,7 @@ public void Should_Map_AWS_Log_Level_And_Default_To_Information(string awsLogLev
14031499
var configuration = new PowertoolsConfigurations(systemWrapper);
14041500

14051501
// Act
1406-
var logLvl = configuration.GetLogLevel();
1502+
var logLvl = configuration.GetLambdaLogLevel();
14071503

14081504
// Assert
14091505
Assert.Equal(logLevel, logLvl);

0 commit comments

Comments
 (0)