search

aws / aws-lambda-dotnet

Libraries, samples and tools to help .NET Core developers develop AWS Lambda functions.
Apache License 2.0
1.56k stars 480 forks source link

Lambda JSON logging feedback request #1747

Open normj opened 3 months ago

normj commented 3 months ago

Lambda JSON logging feedback request

TL;DR version

Looking for users to try the preview versions of Lambda NuGet packages supporting JSON logging. This zip file LambdaJsonLoggingPreview.zip was uploaded May 9th 2024 containing the following NuGet packages.

Intro

In November 2023, Lambda released new advanced logging controls. These new controls allow you to configure log levels and format, including JSON formatting. To take advantage of these new features, the Lambda runtime client of each language must be updated. In .NET the Lambda runtime client is the Amazon.Lambda.RuntimeSupport NuGet package with Amazon.Lambda.Core providing interfaces to access features like logging. We have been working on updating these packages to support Lambda’s advanced logging controls and are looking for feedback from the community on our implementation before rolling the changes out to NuGet and the managed runtime.

The JSON support for .NET and logging is modeled similarly to other Lambda runtimes. In our research on JSON logging, also called structured logging, points to Serilog being the most popular library of choice. Where possible this Lambda JSON support follows the patterns on Serilog. As a rule, the .NET Lambda runtime client does not take dependencies on other packages. This rule comes about for startup and maintenance reasons as well as avoiding collisions with packages brought in by the Lambda deployment bundle. This means that Amazon.Lambda.RuntimeSupport cannot directly use Serilog.

We are looking for feedback in the following areas:

Getting started

.NET Lambda functions can be written either as a class library or an executable. When deployed as an executable Amazon.Lambda.RuntimeSupport is included as part of the deployment package, as opposed to being provided by the managed runtime. Deploying an executable function allows us to try a newer version of the .NET Lambda runtime client that hasn’t been deployed to the managed runtime yet.

Project step

These steps set up a .NET Lambda project as an executable with the preview versions of the .NET Lambda runtime client using the .NET CLI.

Note: We have seen when having .NET 9 preview installed that we still get build errors requiring EnablePreviewFeatures be set even though it was added to the project. To work around this add a global.json file to force the .NET 8 SDK to be used.

dotnet new globaljson --sdk-version 8.0.204

Deploy project and test project

The Lambda project can be deployed with your preferred tool. This section demonstrates how to deploy using the .NET CLI tool called Amazon.Lambda.Tools, but any Lambda deployment tooling that supports .NET should work.

To test the project from the command line, execute the following:

dotnet lambda invoke-function -p "hello"

By default, functions will still use text based logging, so you will see an output similar to following:

> dotnet lambda invoke-function -p "hello"
Amazon Lambda Tools for .NET Core applications (5.10.5)
Project Home: https://github.com/aws/aws-extensions-for-dotnet-cli, https://github.com/aws/aws-lambda-dotnet

Payload:
"HELLO"

Log Tail:
START RequestId: 26dd24f3-30d6-4dd7-a079-aa8b8336d9cc Version: $LATEST
END RequestId: 26dd24f3-30d6-4dd7-a079-aa8b8336d9cc
REPORT RequestId: 26dd24f3-30d6-4dd7-a079-aa8b8336d9cc  Duration: 157.12 ms     Billed Duration: 158 ms Memory Size: 512 MB     Max Memory Used: 66 MB  Init Duration: 229.29 ms

The following AWS CLI command can be used to enable JSON logging. You can also enable JSON in the AWS Console. To change back to text based logging run the AWS CLI command again replacing “JSON” with “Text”

aws lambda update-function-configuration --function-name DotNetJsonLoggingPreview --logging-config '{"LogFormat": "JSON"}'

After running the previous command, invoke the function again to see that the output will be in JSON.

> dotnet lambda invoke-function -p "hello"
Amazon Lambda Tools for .NET Core applications (5.10.5)
Project Home: https://github.com/aws/aws-extensions-for-dotnet-cli, https://github.com/aws/aws-lambda-dotnet

Payload:
"HELLO"

Log Tail:
{"time":"2024-04-26T00:40:03.983Z","type":"platform.initStart","record":{"initializationType":"on-demand","phase":"init","runtimeVersion":"dotnet:8.v9","runtimeVersionArn":"arn:aws:lambda:us-west-2::runtime:b5d61a5821af5a4fb1343bc9428c1f0129a22926e9d830140c50ce5db911c592","functionName":"DotNetJsonLoggingPreview","functionVersion":"$LATEST"}}
{"time":"2024-04-26T00:40:04.183Z","type":"platform.initRuntimeDone","record":{"initializationType":"on-demand","phase":"init","status":"success"}}
{"time":"2024-04-26T00:40:04.184Z","type":"platform.initReport","record":{"initializationType":"on-demand","phase":"init","status":"success","metrics":{"durationMs":200.423}}}
{"time":"2024-04-26T00:40:04.185Z","type":"platform.start","record":{"requestId":"6ebb975f-b9fb-41e9-81f5-ab96586fb42e","version":"$LATEST"}}

{"time":"2024-04-26T00:40:04.297Z","type":"platform.runtimeDone","record":{"requestId":"6ebb975f-b9fb-41e9-81f5-ab96586fb42e","status":"success","spans":[{"name":"responseLatency","start":"2024-04-26T00:40:04.185Z","durationMs":108.942},{"name":"responseDuration","start":"2024-04-26T00:40:04.294Z","durationMs":0.081},{"name":"runtimeOverhead","start":"2024-04-26T00:40:04.294Z","durationMs":3.236}],"metrics":{"durationMs":112.544,"producedBytes":7}}}
{"time":"2024-04-26T00:40:04.314Z","type":"platform.report","record":{"requestId":"6ebb975f-b9fb-41e9-81f5-ab96586fb42e","status":"success","metrics":{"durationMs":112.941,"billedDurationMs":113,"memorySizeMB":512,"maxMemoryUsedMB":66,"initDurationMs":201.073}}}

The new logging APIs

As part of the effort to support JSON logging, new parameterized logging methods have been added to Amazon.Lambda.Core that you downloaded in the steps above. 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"        
        }       
    } 
}

Feedback

Please try these NuGet packages with enabling JSON logging. Any issues or suggestions found please add a comment to this issue. Feedback that these changes are useful to you is also helpful in letting us know if the changes are ready to be deployed.

Lanayx commented 3 months ago

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 commented 3 months ago

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 commented 3 months ago

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

andremantaswow commented 3 months ago

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 commented 3 days ago

@martincostello Sorry for the delay but I put out a PR to address the Native AOT warning. https://github.com/aws/aws-lambda-dotnet/pull/1795