Lambda Structured Logging Support

[normj]

Lambda Structured Logging Support

Status (September 5th, 2024)

Version 1.11.0 of Amazon.Lambda.RuntimeSupport and 2.3.0 of Amazon.Lambda.Core have been released with structured logging support. Lambda functions as .NET class libraries requiring the managed runtime to be updated with the new version of Amazon.Lambda.RuntimeSupport which is pending a deployment. Executable Lambda functions can get started with structured logging support but need to add <EnablePreviewFeatures>true</EnablePreviewFeatures> to the csproj file to access the new parameterized logging API in Amazon.Lambda.Core. Once the .NET managed runtime has been update a new version of Amazon.Lambda.Core will be release removing the preview flag for the logging APIs.

The new logging APIs

As part of the effort to support JSON logging, new parameterized logging methods have been added to Amazon.Lambda.Core. These new APIs are the ones marked as preview, requiring the EnablePreviewFeatures property to be set. This will be required until the new version of Amazon.Lambda.RuntimeSupport has been deployed to the managed runtime for class-library-based Lambda functions. These new logging APIs will also function for the existing Text logging mode providing the string replacement.

The following code shows the handler in the project using the parameterized logging to log the input property.

var handler = (string input, ILambdaContext context) =>
{
    context.Logger.LogInformation("The input provided is: {input}", input);

    return input.ToUpper();
};

The parameterized logging statement will produce the following JSON, adding the parameters to the log statement as properties of the JSON logging.

{
  "timestamp": "2024-04-26T00:40:04.236Z",
  "level": "Information",
  "requestId": "6ebb975f-b9fb-41e9-81f5-ab96586fb42e",
  "traceId": "Root=1-662af7e3-7076fd596550114013d8cd03;Parent=69ab02fe14dc7380;Sampled=0;Lineage=09ad9508:0",
  "message": "The input provided is: hello",
  "input": "hello"
}

Following the pattern of other logging libraries, exceptions can also be passed in for logging. For example, the following code will throw an exception if the input is equal to “fail”.

var handler = (string input, ILambdaContext context) =>
{
    context.Logger.LogInformation("The input provided is: {input}", input);

    if (input == "fail")
    {
        try
        {
            throw new ApplicationException("You forced a failure");
        }
        catch(Exception ex)
        {
            context.Logger.LogError(ex, "An error has happened with input {input}", input);
        }
    }

    return input.ToUpper();
};

This produces the following JSON.

{
  "timestamp": "2024-04-26T00:58:51.554Z",
  "level": "Error",
  "requestId": "1f8da9f0-7914-47c7-a129-e3974bba879e",
  "traceId": "Root=1-662afc4b-2b74361610fca0584cd2a46e;Parent=40bb090170fa2442;Sampled=0;Lineage=09ad9508:0",
  "message": "An error has happened with input fail",
  "input": "fail",
  "errorType": "System.ApplicationException",
  "errorMessage": "You forced a failure",
  "stackTrace": [
    "System.ApplicationException: You forced a failure",
    "at Program.<>c.<<Main>$>b__0_0(String input, ILambdaContext context) in C:\\Temp\\DotNetJsonLoggingPreview\\src\\DotNetJsonLoggingPreview\\Function.cs:line 14"
  ]
}

Serialization options

Formatting scalers: When using scalars like integers and doubles as logging parameters, the format can be customized by providing a format string using a suffix on the parameter name. For example,

var handler = (string input, ILambdaContext context) =>
{
   ...
   
   double cost = 8.12345;
   context.Logger.LogInformation("The cost is {cost:0.00}", cost);
   
   ...
}

The string after the colon in {cost:0.00} is the same as the formatString used in .NET’s composite formatting. The code above produces the following JSON logging statement.

{
  "timestamp": "2024-05-07T21:30:47.157Z",
  "level": "Information",
  "requestId": "4ce09890-4c13-41eb-8d62-9a6c90e10e5b",
  "traceId": "Root=1-663a9d86-530f9b9c5db0148471607964;Parent=480ce27c09876e32;Sampled=0;Lineage=cd25c10f:0",
  "message": "The cost is 8.12",
  "cost": "8.12"
}

Custom types: When using instances of custom types as parameters to logging, the ToString method is used as the value for the property. If the @ prefix is used, the object will be serialized into the JSON logging statement. For example, the code below:

var handler = (string input, ILambdaContext context) =>
{
   ...
   
   var user = new User {FirstName = "Norm", LastName = "Johanson"};
   context.Logger.LogInformation("User {@user} logged in", user);
   
   ...
}


...

public class User
{
    public string FirstName { get; set; }
    public string LastName { get; set; }
}

Produce the following JSON document:

{
    "timestamp": "2023-09-07T01:30:06.977Z",
    "level": "Information",
    "requestId": "8f711428-7e55-46f9-ae88-2a65d4f85fc5",
    "traceId": "1-6408af34-50f56f5b5677a7d763973804",
    "message": "User {@user} logged in",
    "user": 
    {
        "FirstName": "Norm",
        "LastName": "Johanson"
    }
}

Collections: When using lists and dictionaries as parameters, the items in the collections are written to the JSON log using the ToString method. The @ prefix can be used to indicate that the items should be serialized into the JSON log message.

Example JSON using ToString:

{
    "timestamp": "2023-09-07T01:30:06.977Z",
    "level": "Information",
    "requestId": "8f711428-7e55-46f9-ae88-2a65d4f85fc5",
    "traceId": "1-6408af34-50f56f5b5677a7d763973804",
    "message": "Request {metrics}",
    "metrics": 
    {
        "Requests" : "50rpm",
        "Latency" : "145.1ms"       
    } 
}

Example JSON using serialization:

{
    "timestamp": "2023-09-07T01:30:06.977Z",
    "level": "Information",
    "requestId": "8f711428-7e55-46f9-ae88-2a65d4f85fc5",
    "traceId": "1-6408af34-50f56f5b5677a7d763973804",
    "message": "Request {@metrics}",
    "metrics": 
    {
        "Requests" : 
        {
           "Value": 50,
           "Unit": "rpm"
        }
        "Latency" : 
        {
           "Value": 145.1,
           "Unit": "ms"        
        }       
    } 
}

[Lanayx]

Some other requirements for production-ready structured logging support:

1. Ability to configure default field names (like change timestamp to ts)
2. Ability to configure values formatting (like change Information to INFO)
3. Ability to enrich logger with new values to use downstream (like userId)
4. Enriched logger should work normally in parallel and async/await situations
5. Ability to configure whether log should be skipped based on level

[martincostello]

I haven't specifically played with the new capabilities yet, but I have updated an existing lambda using .NET 8 with AoT where I use .NET's own built-in AddJsonConsole() to log things and get this warning:

ILC : AOT analysis warning IL3050: Amazon.Lambda.RuntimeSupport.Helpers.Logging.JsonLogMessageFormatter.FormatJsonValue(Utf8JsonWriter,Object,String,MessageProperty.Directive): Using member 'System.Text.Json.JsonSerializer.Serialize<Object>(Object,JsonSerializerOptions)' which has 'RequiresDynamicCodeAttribute' can break functionality when AOT compiling. JSON serialization and deserialization might require types that cannot be statically analyzed and might need runtime code generation. Use System.Text.Json source generation for native AOT applications. [/home/runner/work/alexa-london-travel/alexa-london-travel/src/LondonTravel.Skill/LondonTravel.Skill.csproj]

This is with the provided.al2023 custom runtime. It seems that the docs are out of date though, as that runtime isn't listed as supported in the table. It is noted later that a custom runtime needs to honour the log-level settings, but I think the documentation isn't clear that it's supported (albeit not Just Works™️).

[normj]

Thanks @martincostello, I'll take a look to see what we need to do.

[andremantaswow]

It would be very useful to have consistent logging between lambda startup logs and .NET ILogger logs (Microsoft.Extensions.Logging).
Maybe not as default since not everyone might be using it; but an option for lambdas that use Microsoft.Extensions stack.

[normj]

@martincostello Sorry for the delay but I put out a PR to address the Native AOT warning. #1795

[normj]

Update the packages have been release as GA and can be used for executable assembly Lambda functions today if you reference version 1.11.0 of Amazon.Lambda.RuntimeSupport. Class library based Lambda functions can use the functionality until the managed runtime gets redeployed with the latest changes. Till managed runtime is updated the new logging APIs in Amazon.Lambda.Core are marked as preview using the RequiresPreviewFeatures .NET attribute.

[RowlandBanks]

Will destructuring an object using the {@thing} syntax support customizing how the destructuring occurs?

As a motivating example, we often want to log a complex AWS object such as an SQSEvent.SQSMessage. However, we don't want to log all the properties - just a handful like the MessageId and the EventSourceArn or similar. We do not want to log potentially very large properties like Body or properties that would not be useful like the ReceiptHandle.

A good implementation is found in Serilog, which supports either attributing the properties on your classes, or defining a destructuring function when creating the logger.

Another interesting implementation is to support a richer destructuring syntax, e.g.:

logger.Log("Message received: {@TheMessage(MessageId, EventSourceArn)}", message);

Note that this isn't an essential feature - it can be implemented by creating a "loggable" version of an object using an extension method or wrapper class, for example:

public static object ToLoggable(this SQSEvent.SQSMessage message) => new
{
    // Use a property as-is
    message.MessageArn,

    // Rename a property
    TheIdOfTheMessage = message.MessageId,

    // Construct a brand new property
    MessageLength = message.Body?.Length ?? 0
}

However, discoverability and ease-of-use both suffer with this approach.

[normj]

@RowlandBanks The JSON serialization is using System.Text.Json so you can use the attributes for System.Text.Json to control what to included. For example this User type would exclude the password from being logged.

public class User
{
    public string? Name { get; set; }

    [JsonIgnore]
    public string? Password { get; set; }

    public override string ToString()
    {
        return Name ?? "Noname";
    }
}

[Dreamescaper]

Is this logger functionality actually tied to lambda in any way?
It looks like another logging library, which could be used outside of Lambda?

[normj]

@Dreamescaper This an expansion of the ILambdaLogger in Amazon.Lambda.Core functionality.

[normj]

I'm still waiting on the Lambda deployment for the managed runtime for the class library programming model to have access structured logging. It is the busy time of year and deployments get backed up. I did push out version 5.11.0 of Amazon.Lambda.Tools that has new switches for the deploy-function command for configuring logging.

[ryancormack]

Hey 👋🏻
This looks really handy, but I was wondering if there are any plans to further extend the capabilities of the Logger provided by the Runtime? The Lambda Powertools .NET lib has their own Logger.
Was the primary driver of this to help support the Lambda JSON logging feature, and any further, or more feature rich logging features might still be best served by the Powertools (or any other logger) logging library?

(I realise I'm late to the party here :S)

[normj]

What features are you thinking for enriching? The challenging working at the Amazon.LambdaRuntimeSupport level is we have to keep it lean for cold start performance reasons and avoid any conflicts with dependencies brought in by the Lambda function. This means we can't take on dependencies like Microsoft.Extensions.Logging.

[ryancormack]

That makes sense 👍🏻, thanks.

The specific things I was thinking of was being able to add log properties for the whole scope of an invocation (request ID, user ID etc). As well as being able to flush logs only on error. Maybe both could be implemented without taking any other dependencies, but might not be worth it - I imagine that once consumers start getting past logging single lines they may already have other libs installed?