Skip to content

Commit 974ab08

Browse files
normjnormj
authored
Merge pull request #1737 from aws/normj/json-logging-exceptions
Lambda JSON Exception handling and frame type
2 parents eb55d8f + 43d5248 commit 974ab08

File tree

10 files changed

+86
-28
lines changed

10 files changed

+86
-28
lines changed

‎Libraries/src/Amazon.Lambda.RuntimeSupport/Bootstrap/Constants.cs

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -33,6 +33,14 @@ internal class Constants
3333
internal const string AWS_LAMBDA_INITIALIZATION_TYPE_PC = "provisioned-concurrency";
3434
internal const string AWS_LAMBDA_INITIALIZATION_TYPE_ON_DEMAND = "on-demand";
3535

36+
internal const string NET_RIC_LOG_LEVEL_ENVIRONMENT_VARIABLE = "AWS_LAMBDA_HANDLER_LOG_LEVEL";
37+
internal const string NET_RIC_LOG_FORMAT_ENVIRONMENT_VARIABLE = "AWS_LAMBDA_HANDLER_LOG_FORMAT";
38+
39+
internal const string LAMBDA_LOG_LEVEL_ENVIRONMENT_VARIABLE = "AWS_LAMBDA_LOG_LEVEL";
40+
internal const string LAMBDA_LOG_FORMAT_ENVIRONMENT_VARIABLE = "AWS_LAMBDA_LOG_FORMAT";
41+
42+
internal const string LAMBDA_LOG_FORMAT_JSON = "Json";
43+
3644
internal enum AwsLambdaDotNetPreJit
3745
{
3846
Never,

‎Libraries/src/Amazon.Lambda.RuntimeSupport/Bootstrap/LambdaBootstrap.cs

Lines changed: 5 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -18,6 +18,7 @@
1818
using System.Net.Http;
1919
using System.Threading;
2020
using System.Threading.Tasks;
21+
using Amazon.Lambda.Core;
2122
using Amazon.Lambda.RuntimeSupport.Bootstrap;
2223
using Amazon.Lambda.RuntimeSupport.Helpers;
2324

@@ -252,9 +253,11 @@ public static HttpClient ConstructHttpClient()
252253

253254
private void WriteUnhandledExceptionToLog(Exception exception)
254255
{
255-
// Console.Error.WriteLine are redirected to the IConsoleLoggerWriter which
256-
// will take care of writing to the function's log stream.
256+
#if NET6_0_OR_GREATER
257+
Client.ConsoleLogger.FormattedWriteLine(LogLevel.Error.ToString(), exception, null);
258+
#else
257259
Console.Error.WriteLine(exception);
260+
#endif
258261
}
259262

260263
#if NET8_0_OR_GREATER

‎Libraries/src/Amazon.Lambda.RuntimeSupport/Client/IRuntimeApiClient.cs

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -13,6 +13,7 @@
1313
* permissions and limitations under the License.
1414
*/
1515

16+
using Amazon.Lambda.RuntimeSupport.Helpers;
1617
using System;
1718
using System.IO;
1819
using System.Threading;
@@ -25,6 +26,11 @@ namespace Amazon.Lambda.RuntimeSupport
2526
/// </summary>
2627
public interface IRuntimeApiClient
2728
{
29+
/// <summary>
30+
/// Logger used for formatting log messages into the user's CloudWatch Log stream.
31+
/// </summary>
32+
IConsoleLoggerWriter ConsoleLogger { get; }
33+
2834
/// <summary>
2935
/// Report an initialization error as an asynchronous operation.
3036
/// </summary>

‎Libraries/src/Amazon.Lambda.RuntimeSupport/Client/RuntimeApiClient.cs

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -39,6 +39,9 @@ public class RuntimeApiClient : IRuntimeApiClient
3939
internal Func<Exception, ExceptionInfo> ExceptionConverter { get; set; }
4040
internal LambdaEnvironment LambdaEnvironment { get; set; }
4141

42+
/// <inheritdoc/>
43+
public IConsoleLoggerWriter ConsoleLogger => _consoleLoggerRedirector;
44+
4245
/// <summary>
4346
/// Create a new RuntimeApiClient
4447
/// </summary>

‎Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/ConsoleLoggerWriter.cs

Lines changed: 3 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -288,12 +288,6 @@ class WrapperTextWriter : TextWriter
288288
private readonly TextWriter _innerWriter;
289289
private string _defaultLogLevel;
290290

291-
const string NET_RIC_LOG_LEVEL_ENVIRONMENT_VARIABLE = "AWS_LAMBDA_HANDLER_LOG_LEVEL";
292-
const string NET_RIC_LOG_FORMAT_ENVIRONMENT_VARIABLE = "AWS_LAMBDA_HANDLER_LOG_FORMAT";
293-
294-
const string LAMBDA_LOG_LEVEL_ENVIRONMENT_VARIABLE = "AWS_LAMBDA_LOG_LEVEL";
295-
const string LAMBDA_LOG_FORMAT_ENVIRONMENT_VARIABLE = "AWS_LAMBDA_LOG_FORMAT";
296-
297291
private LogLevel _minmumLogLevel = LogLevel.Information;
298292

299293
enum LogFormatType { Default, Unformatted, Json }
@@ -322,7 +316,7 @@ public WrapperTextWriter(TextWriter innerWriter, string defaultLogLevel)
322316
_innerWriter = innerWriter;
323317
_defaultLogLevel = defaultLogLevel;
324318

325-
var envLogLevel = GetEnviromentVariable(NET_RIC_LOG_LEVEL_ENVIRONMENT_VARIABLE, LAMBDA_LOG_LEVEL_ENVIRONMENT_VARIABLE);
319+
var envLogLevel = GetEnvironmentVariable(Constants.NET_RIC_LOG_LEVEL_ENVIRONMENT_VARIABLE, Constants.LAMBDA_LOG_LEVEL_ENVIRONMENT_VARIABLE);
326320
if (!string.IsNullOrEmpty(envLogLevel))
327321
{
328322
// Map Lambda's fatal logging level to the .NET RIC critical
@@ -340,7 +334,7 @@ public WrapperTextWriter(TextWriter innerWriter, string defaultLogLevel)
340334
}
341335
}
342336

343-
var envLogFormat = GetEnviromentVariable(NET_RIC_LOG_FORMAT_ENVIRONMENT_VARIABLE, LAMBDA_LOG_FORMAT_ENVIRONMENT_VARIABLE);
337+
var envLogFormat = GetEnvironmentVariable(Constants.NET_RIC_LOG_FORMAT_ENVIRONMENT_VARIABLE, Constants.LAMBDA_LOG_FORMAT_ENVIRONMENT_VARIABLE);
344338
if (!string.IsNullOrEmpty(envLogFormat))
345339
{
346340
if (Enum.TryParse<LogFormatType>(envLogFormat, true, out var result))
@@ -359,7 +353,7 @@ public WrapperTextWriter(TextWriter innerWriter, string defaultLogLevel)
359353
}
360354
}
361355

362-
private string GetEnviromentVariable(string envName, string fallbackEnvName)
356+
private string GetEnvironmentVariable(string envName, string fallbackEnvName)
363357
{
364358
var value = Environment.GetEnvironmentVariable(envName);
365359
if(string.IsNullOrEmpty(value) && fallbackEnvName != null)

‎Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/FileDescriptorLogStream.cs

Lines changed: 11 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -19,6 +19,7 @@
1919
using System.Text;
2020
using Microsoft.Win32.SafeHandles;
2121
using System.Collections.Concurrent;
22+
using Amazon.Lambda.RuntimeSupport.Bootstrap;
2223

2324
namespace Amazon.Lambda.RuntimeSupport.Helpers
2425
{
@@ -33,7 +34,8 @@ public static class FileDescriptorLogFactory
3334
// max cloudwatch log event size, 256k - 26 bytes of overhead.
3435
internal const int MaxCloudWatchLogEventSize = 256 * 1024 - 26;
3536
internal const int LambdaTelemetryLogHeaderLength = 16;
36-
internal const uint LambdaTelemetryLogHeaderFrameType = 0xa55a0003;
37+
internal const uint LambdaTelemetryLogHeaderFrameTypeText = 0xa55a0003;
38+
internal const uint LambdaTelemetryLogHeaderFrameTypeJson = 0xa55a0002;
3739
internal static readonly DateTimeOffset UnixEpoch = new DateTimeOffset(1970, 1, 1, 0, 0, 0, TimeSpan.Zero);
3840

3941
/// <summary>
@@ -84,12 +86,19 @@ private class FileDescriptorLogStream : Stream
8486
{
8587
private readonly Stream _fileDescriptorStream;
8688
private readonly byte[] _frameTypeBytes;
89+
private readonly uint _frameType;
8790

8891
public FileDescriptorLogStream(Stream logStream)
8992
{
93+
var logFormat = Environment.GetEnvironmentVariable(Constants.LAMBDA_LOG_FORMAT_ENVIRONMENT_VARIABLE);
94+
_frameType = string.Equals(logFormat, Constants.LAMBDA_LOG_FORMAT_JSON, StringComparison.InvariantCultureIgnoreCase)
95+
? LambdaTelemetryLogHeaderFrameTypeJson : LambdaTelemetryLogHeaderFrameTypeText;
96+
97+
InternalLogger.GetDefaultLogger().LogDebug("FileDescriptorLogStream FrameType: " + _frameType);
98+
9099
_fileDescriptorStream = logStream;
91100

92-
_frameTypeBytes = BitConverter.GetBytes(LambdaTelemetryLogHeaderFrameType);
101+
_frameTypeBytes = BitConverter.GetBytes(_frameType);
93102
if (BitConverter.IsLittleEndian)
94103
{
95104
Array.Reverse(_frameTypeBytes);

‎Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/DefaultLogMessageFormatter.cs

Lines changed: 35 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,7 @@
11
#if NET6_0_OR_GREATER
22

3+
using System.Text;
4+
35
namespace Amazon.Lambda.RuntimeSupport.Helpers.Logging
46
{
57
/// <summary>
@@ -48,21 +50,47 @@ public override string FormatMessage(MessageState state)
4850
message = ApplyMessageProperties(state.MessageTemplate, messageProperties, state.MessageArguments);
4951
}
5052

51-
if (!AddPrefix)
53+
var displayLevel = state.Level != null ? ConvertLogLevelToLabel(state.Level.Value) : null;
54+
55+
var sb = new StringBuilder(
56+
25 + // Length for timestamp
57+
(state.AwsRequestId?.Length).GetValueOrDefault() +
58+
displayLevel.Length +
59+
(message?.Length).GetValueOrDefault() +
60+
5 // Padding for tabs
61+
);
62+
63+
if (AddPrefix)
5264
{
53-
return message;
65+
sb.Append(FormatTimestamp(state));
66+
sb.Append('\t');
67+
sb.Append(state.AwsRequestId);
68+
69+
if (!string.IsNullOrEmpty(displayLevel))
70+
{
71+
sb.Append('\t');
72+
sb.Append(displayLevel);
73+
}
74+
75+
sb.Append('\t');
5476
}
5577

56-
var displayLevel = state.Level != null ? ConvertLogLevelToLabel(state.Level.Value) : null;
5778

58-
if (!string.IsNullOrEmpty(displayLevel))
79+
if (!string.IsNullOrEmpty(message))
5980
{
60-
return $"{FormatTimestamp(state)}\t{state.AwsRequestId}\t{displayLevel}\t{message ?? string.Empty}";
81+
sb.Append(message);
6182
}
62-
else
83+
84+
if (state.Exception != null)
6385
{
64-
return $"{FormatTimestamp(state)}\t{state.AwsRequestId}\t{message ?? string.Empty}";
86+
if (!string.IsNullOrEmpty(message))
87+
{
88+
sb.Append('\n');
89+
}
90+
sb.Append(state.Exception.ToString());
6591
}
92+
93+
return sb.ToString();
6694
}
6795

6896
/// <summary>

‎Libraries/src/Amazon.Lambda.RuntimeSupport/Helpers/Logging/JsonLogMessageFormatter.cs

Lines changed: 4 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -191,11 +191,10 @@ private void WriteException(Utf8JsonWriter writer, MessageState state)
191191
writer.WriteString("errorMessage", state.Exception.Message);
192192
writer.WritePropertyName("stackTrace");
193193
writer.WriteStartArray();
194-
195-
// TODO: Right now for stack trace we are just using a single array element doing a ToString to get the
196-
// inner excepions. Working with the Lambda team to figure out how they want to handle inner exceptions with
197-
// stackTrace array.
198-
writer.WriteStringValue(state.Exception.ToString());
194+
foreach(var line in state.Exception.ToString().Split('\n'))
195+
{
196+
writer.WriteStringValue(line.Trim());
197+
}
199198
writer.WriteEndArray();
200199
}
201200
}

‎Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/LogMessageFormatterTests.cs

Lines changed: 8 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -3,6 +3,7 @@
33
using Microsoft.VisualStudio.TestPlatform.CommunicationUtilities;
44
using System;
55
using System.Collections.Generic;
6+
using System.Linq;
67
using System.Runtime.Serialization;
78
using System.Text.Json;
89
using Xunit;
@@ -470,10 +471,14 @@ public void FormatJsonException()
470471
Assert.Equal("This Will Fail", doc.RootElement.GetProperty("errorMessage").GetString());
471472
Assert.Equal("System.ApplicationException", doc.RootElement.GetProperty("errorType").GetString());
472473
Assert.Equal(JsonValueKind.Array, doc.RootElement.GetProperty("stackTrace").ValueKind);
473-
Assert.Equal(ex.ToString(), doc.RootElement.GetProperty("stackTrace")[0].GetString());
474474

475-
// Confirm inner exceptions are being captured
476-
Assert.Contains("System.NullReferenceException", doc.RootElement.GetProperty("stackTrace")[0].GetString());
475+
var stackLines = ex.ToString().Split('\n').Select(x => x.Trim()).ToList();
476+
var jsonExArray = doc.RootElement.GetProperty("stackTrace");
477+
Assert.Equal(stackLines.Count, jsonExArray.GetArrayLength());
478+
for(var i = 0; i < stackLines.Count; i++)
479+
{
480+
Assert.Equal(stackLines[i], jsonExArray[i].GetString());
481+
}
477482
}
478483
}
479484

‎Libraries/test/Amazon.Lambda.RuntimeSupport.Tests/Amazon.Lambda.RuntimeSupport.UnitTests/TestHelpers/TestRuntimeApiClient.cs

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -12,6 +12,7 @@
1212
* express or implied. See the License for the specific language governing
1313
* permissions and limitations under the License.
1414
*/
15+
using Amazon.Lambda.RuntimeSupport.Helpers;
1516
using Amazon.Lambda.RuntimeSupport.UnitTests.TestHelpers;
1617
using System;
1718
using System.Collections.Generic;
@@ -28,6 +29,8 @@ internal class TestRuntimeApiClient : IRuntimeApiClient
2829
private IEnvironmentVariables _environmentVariables;
2930
private Dictionary<string, IEnumerable<string>> _headers;
3031

32+
public IConsoleLoggerWriter ConsoleLogger { get; } = new LogLevelLoggerWriter();
33+
3134
public TestRuntimeApiClient(IEnvironmentVariables environmentVariables, Dictionary<string, IEnumerable<string>> headers)
3235
{
3336
_environmentVariables = environmentVariables;

0 commit comments

Comments
 (0)