Bug: Enum logging throws NotSupportedException and empty log entry when running under .net8 #656

nCubed · 2024-10-02T12:57:23Z

Expected Behaviour

When logging an Enum, the value of the enum should be logged.

Current Behaviour

Of note: this only occurs with the .net8 runtime; not the .net6 runtime.

v1.6 introduced a change in behavior when logging an Enum. Depending on the Enum, the logged value is either an empty json object or will throw a NotSupportedException.

Using the code snippet provided, the logging output has the following behavior.

v1.5.1 (and prior)

logging has no errors and logs the values

{
    "timestamp": "<snip>",
    "level": "Information",
    "service": "<snip>",
    "name": "<snip>",
    "message": 5
}

{
    "timestamp": "<snip>",
    "level": "Information",
    "service": "<snip>",
    "name": "<snip>",
    "message": {
        "r": 199,
        "g": 21,
        "b": 133,
        "a": 255,
        "is_known_color": true,
        "is_empty": false,
        "is_named_color": true,
        "is_system_color": false,
        "name": "MediumVioletRed"
    }
}

v1.6.0

custom enum is en empty json object
.net enum (and 3rd party dll enum) cause an exception

{
    "timestamp": "<snip>",
    "level": "Information",
    "service": "<snip>",
    "name": "<snip>",
    "message": {}
}

Exception for 2nd log entry:

System.NotSupportedException
  HResult=0x80131515
  Message=JsonTypeInfo metadata for type 'System.Drawing.Color' was not provided by TypeInfoResolver of type '[AWS.Lambda.Powertools.Logging.Serializers.PowertoolsLoggingSerializationContext]'. If using source generation, ensure that all root types passed to the serializer have been annotated with 'JsonSerializableAttribute', along with any types that might be serialized polymorphically. The unsupported member type is located on type 'System.Object'. Path: $.
  Source=System.Text.Json
  StackTrace:
   at System.Text.Json.ThrowHelper.ThrowNotSupportedException(WriteStack& state, NotSupportedException ex)
   at System.Text.Json.Serialization.JsonConverter`1.WriteCore(Utf8JsonWriter writer, T& value, JsonSerializerOptions options, WriteStack& state)
   at System.Text.Json.Serialization.Metadata.JsonTypeInfo`1.Serialize(Utf8JsonWriter writer, T& rootValue, Object rootValueBoxed)
   at System.Text.Json.Serialization.Metadata.JsonTypeInfo`1.SerializeAsObject(Utf8JsonWriter writer, Object rootValue)
   at System.Text.Json.Serialization.Metadata.JsonTypeInfo`1.Serialize(Utf8JsonWriter writer, T& rootValue, Object rootValueBoxed)
   at System.Text.Json.Serialization.Metadata.JsonTypeInfo`1.SerializeAsObject(Utf8JsonWriter writer, Object rootValue)
   at System.Text.Json.JsonSerializer.WriteStringAsObject(Object value, JsonTypeInfo jsonTypeInfo)
   at AWS.Lambda.Powertools.Logging.Serializers.PowertoolsLoggingSerializer.Serialize(Object value, Type inputType)
   at AWS.Lambda.Powertools.Logging.Internal.PowertoolsLogger.Log[TState](LogLevel logLevel, EventId eventId, TState state, Exception exception, Func`3 formatter)
   at Microsoft.Extensions.Logging.LoggerExtensions.Log(ILogger logger, LogLevel logLevel, EventId eventId, Exception exception, String message, Object[] args)
   at Microsoft.Extensions.Logging.LoggerExtensions.Log(ILogger logger, LogLevel logLevel, String message, Object[] args)
   at Microsoft.Extensions.Logging.LoggerExtensions.LogInformation(ILogger logger, String message, Object[] args)
   at AWS.Lambda.Powertools.Logging.LoggerExtensions.LogInformation(ILogger logger, Object message)
   at AWS.Lambda.Powertools.Logging.Logger.LogInformation(Object message)
   at Program.<Main>$(String[] args) in C:\.dev\tmp\AwsPowertoolsLogging\Console02\Program.cs:line 11

  This exception was originally thrown at this call stack:
    [External Code]

Inner Exception 1:
NotSupportedException: JsonTypeInfo metadata for type 'System.Drawing.Color' was not provided by TypeInfoResolver of type '[AWS.Lambda.Powertools.Logging.Serializers.PowertoolsLoggingSerializationContext]'. If using source generation, ensure that all root types passed to the serializer have been annotated with 'JsonSerializableAttribute', along with any types that might be serialized polymorphically.

Code snippet

using System.Drawing;
using AWS.Lambda.Powertools.Logging;

Logger.LogInformation(Pet.Lizard);
Logger.LogInformation(Color.MediumVioletRed);

public enum Pet
{
    Cat = 1,
    Dog = 3,
    Lizard = 5
}

Possible Solution

n/a

Steps to Reproduce

Use the .net8 runtime
Use the code snippet provided with v1.5.1 and then 1.6.0

Powertools for AWS Lambda (.NET) version

v1.6.0

AWS Lambda function runtime

dotnet6

Debugging logs

No response

The text was updated successfully, but these errors were encountered:

hjgraca · 2024-10-02T13:21:52Z

Hi @nCubed thanks for opening the issue. and I will be looking at it shortly
Question, is this an AOT Lambda?

nCubed · 2024-10-02T13:31:10Z

Good question @hjgraca - this is not an AOT Lambda.

edit: In reading through the release notes, I was wondering if AOT may have been the underlying issue for the logger.

hjgraca · 2024-10-02T13:34:28Z

I asked because the error is very AOT, because of source generation.
Can you do another test, instead of an enum, can you create a simple class with one property and instanciate it and pass it to the logger to see if it complains about that type not being resolved (JsonTypeInfoResolver error).
I will do some tests on my side as well.

Edit: I was able to reproduce the enum error

nCubed · 2024-10-02T14:49:57Z

@hjgraca We discovered this issue when upgrading our lambdas to .net8. We have some startup unit tests that perform some logging w/ some complex objects (classes w/ nested child classes); the enum broke the logging; removing the enum and all was fine, so standard class/properties are looking good still. It's just the enum.

Thanks for taking a look so quickly. LMK if I can help.

nCubed · 2024-10-02T14:53:15Z

p.s. the issue UI has a dropdown for "AWS Lambda function runtime"; the only option is .net6. Can your team add .net8 as an option?

hjgraca · 2024-10-02T14:58:56Z

@nCubed
Fix is on the way #657
Thank you for reporting and helping me diagnose the issue.
I am planing on releasing v1.6.1 in a few moments.

hjgraca · 2024-10-02T15:34:50Z

@nCubed version 1.6.1 available on NuGet https://www.nuget.org/packages/AWS.Lambda.Powertools.Logging/1.6.1
Can you try updating and let me know if that works as expected? thanks

nCubed · 2024-10-02T16:04:34Z

@hjgraca Here's what I'm seeing. The built-in .net enum works as expected. The custom enum still logs an empty object.

Custom

empty json object

{
    "timestamp": "<snip>",
    "level": "Information",
    "service": "<snip>",
    "name": "<snip>",
    "message": {}
}

.net System.Color

full serialization of the enum

{
    "timestamp": "<snip>",
    "level": "Information",
    "service": "<snip>",
    "name": "<snip>",
    "message": {
        "r": 199,
        "g": 21,
        "b": 133,
        "a": 255,
        "is_known_color": true,
        "is_empty": false,
        "is_named_color": true,
        "is_system_color": false,
        "name": "MediumVioletRed"
    }
}

Original Source
Updated our source where we discovered the issue and the 3rd party dll enum is now serializing correctly.

Couple of things:

Looks like a standard enum still needs some tweaks
Is there a setting we can provide to serialize enums as the string value instead of the int value?

hjgraca · 2024-10-02T17:01:06Z

@nCubed for your second question, yes, you can, add a JsonConverter to your enum declaration

    [JsonConverter(typeof(JsonStringEnumConverter))]
    public enum Pet
    {
        Cat = 1,
        Dog = 3,
        Lizard = 5
    }

As for the empty enum logged, I am replicating your example with that enum and I see the value in the Message field.
Maybe I am missing something

nCubed · 2024-10-02T17:11:48Z

Currently, I'm testing locally and still seeing the empty object when decorating the Pet enum w/ the JsonConverter. I'd need to deploy out to AWS and re-test.

We're currently prepping for a deployment, so it may be a day or so before I can run a live test.

This may be better for as a feature request, but it'd be nice to have an option to provide a JsonConverter to the logger itself, rather than decorating our types, re: when referencing 3rd party dll's, we have no control over their attribute usage.

hjgraca · 2024-10-02T17:26:55Z

Thanks for the feedback and suggestion, will take that into consideration.
Please let us know how the tests go.

nCubed · 2024-10-04T13:06:04Z

@hjgraca I deployed a .net8 Lambda w/ v1.6.1 logger to AWS. The results are the same as my local testing:

System.Color - full serialization
Custom Enum - empty object
Custom Enum decorated with JsonStringEnumConverter - empty object

Here is the logger for each line followed by the logger output.

Logger Assembly

Assembly a = Assembly.GetAssembly(typeof(Logger))!;
Logger.LogInformation(a.FullName);

{
    "cold_start": true,
    "xray_trace_id": "<snip>",
    "function_name": "<snip>",
    "function_version": "$LATEST",
    "function_memory_size": 330,
    "function_arn": "arn:aws:lambda:us-east-2:<snip>:function:<snip>",
    "function_request_id": "<snip>",
    "timestamp": "2024-10-04T12:55:01.4118710Z",
    "level": "Information",
    "service": "StartupBootstrapper",
    "name": "AWS.Lambda.Powertools.Logging.Logger",
    "message": "AWS.Lambda.Powertools.Logging, Version=1.6.1.0, Culture=neutral, PublicKeyToken=null"
}

Custom Enum Decorated w/ Attribute

Logger.LogInformation(Pet.Lizard);

{
    "cold_start": true,
    "xray_trace_id": "<snip>",
    "function_name": "<snip>",
    "function_version": "$LATEST",
    "function_memory_size": 330,
    "function_arn": "arn:aws:lambda:us-east-2:<snip>:function:<snip>",
    "function_request_id": "<snip>",
    "timestamp": "2024-10-04T12:55:01.4121302Z",
    "level": "Information",
    "service": "StartupBootstrapper",
    "name": "AWS.Lambda.Powertools.Logging.Logger",
    "message": {}
}

Custom Enum w/o Attribute

Logger.LogInformation(Thing.Three);

{
    "cold_start": true,
    "xray_trace_id": "<snip>",
    "function_name": "<snip>",
    "function_version": "$LATEST",
    "function_memory_size": 330,
    "function_arn": "arn:aws:lambda:us-east-2:<snip>:function:<snip>",
    "function_request_id": "<snip>",
    "timestamp": "2024-10-04T12:55:01.4296977Z",
    "level": "Information",
    "service": "StartupBootstrapper",
    "name": "AWS.Lambda.Powertools.Logging.Logger",
    "message": {}
}

.net System.Color

Logger.LogInformation(Color.MediumVioletRed);

{
    "cold_start": true,
    "xray_trace_id": "<snip>",
    "function_name": "<snip>",
    "function_version": "$LATEST",
    "function_memory_size": 330,
    "function_arn": "arn:aws:lambda:us-east-2:<snip>:function:<snip>",
    "function_request_id": "<snip>",
    "timestamp": "2024-10-04T12:55:01.4300233Z",
    "level": "Information",
    "service": "StartupBootstrapper",
    "name": "AWS.Lambda.Powertools.Logging.Logger",
    "message": {
        "r": 199,
        "g": 21,
        "b": 133,
        "a": 255,
        "is_known_color": true,
        "is_empty": false,
        "is_named_color": true,
        "is_system_color": false,
        "name": "MediumVioletRed"
    }
}

And here are the 2 enums:

[JsonConverter(typeof(JsonStringEnumConverter))]
public enum Pet
{
    Cat = 1,
    Dog = 3,
    Lizard = 5
}

public enum Thing
{
    One = 1,
    Three = 3,
    Five = 5
}

Please let me know if you need any other information.

hjgraca · 2024-10-04T13:28:33Z

@nCubed thank you for the details.
Unfortunately I am not seeing that issue.
Sharing my full demo code, to check if there is something I might be missing. I also don't have any environment variables set in Lambda.

Code

using System.Drawing;
using System.Reflection;
using System.Text.Json.Serialization;
using Amazon.Lambda.Core;
using AWS.Lambda.Powertools.Logging;

[assembly: LambdaSerializer(typeof(Amazon.Lambda.Serialization.SystemTextJson.DefaultLambdaJsonSerializer))]

namespace dotnet8_lambda;

public class Function
{
    [Logging]
    public string FunctionHandler(string input, ILambdaContext context)
    {
        Assembly a = Assembly.GetAssembly(typeof(Logger))!;
        Logger.LogInformation(a.FullName);

        Logger.LogInformation(Pet.Lizard);
        Logger.LogInformation(Thing.Three);

        Logger.LogInformation(Color.MediumVioletRed);

        return input.ToUpper();
    }
}

[JsonConverter(typeof(JsonStringEnumConverter))]
public enum Pet
{
    Cat = 1,
    Dog = 3,
    Lizard = 5
}

public enum Thing
{
    One = 1,
    Three = 3,
    Five = 5
}

csproj

<Project Sdk="Microsoft.NET.Sdk">
  <PropertyGroup>
    <TargetFramework>net8.0</TargetFramework>
    <ImplicitUsings>enable</ImplicitUsings>
    <Nullable>enable</Nullable>
    <GenerateRuntimeConfigurationFiles>true</GenerateRuntimeConfigurationFiles>
    <AWSProjectType>Lambda</AWSProjectType>
    <!-- This property makes the build directory similar to a publish directory and helps the AWS
    .NET Lambda Mock Test Tool find project dependencies. -->
    <CopyLocalLockFileAssemblies>true</CopyLocalLockFileAssemblies>
    <!-- Generate ready to run images during publishing to improve cold start time. -->
    <PublishReadyToRun>true</PublishReadyToRun>
  </PropertyGroup>
  <ItemGroup>
    <PackageReference Include="Amazon.Lambda.Core" Version="2.2.0" />
    <PackageReference Include="Amazon.Lambda.Serialization.SystemTextJson" Version="2.4.3" />
    <PackageReference Include="AWS.Lambda.Powertools.Logging" Version="1.6.1" />
  </ItemGroup>
</Project>

Output

START RequestId: ebabe9cf-b8ad-4a60-ab95-083193c57d23 Version: $LATEST
{
  "cold_start": true,
  "xray_trace_id": "1-66ffedaf-79b1a03a1a45356a1bbd0064",
  "function_name": "dotnet8-lambda",
  "function_version": "$LATEST",
  "function_memory_size": 512,
  "function_arn": "arn:aws:lambda:eu-west-1:123:function:dotnet8-lambda",
  "function_request_id": "ebabe9cf-b8ad-4a60-ab95-083193c57d23",
  "timestamp": "2024-10-04T13:29:19.7455479Z",
  "level": "Information",
  "service": "service_undefined",
  "name": "AWS.Lambda.Powertools.Logging.Logger",
  "message": "AWS.Lambda.Powertools.Logging, Version=1.6.1.0, Culture=neutral, PublicKeyToken=null"
}
{
  "cold_start": true,
  "xray_trace_id": "1-66ffedaf-79b1a03a1a45356a1bbd0064",
  "function_name": "dotnet8-lambda",
  "function_version": "$LATEST",
  "function_memory_size": 512,
  "function_arn": "arn:aws:lambda:eu-west-1:123:function:dotnet8-lambda",
  "function_request_id": "ebabe9cf-b8ad-4a60-ab95-083193c57d23",
  "timestamp": "2024-10-04T13:29:19.8664396Z",
  "level": "Information",
  "service": "service_undefined",
  "name": "AWS.Lambda.Powertools.Logging.Logger",
  "message": "Lizard"
}
{
  "cold_start": true,
  "xray_trace_id": "1-66ffedaf-79b1a03a1a45356a1bbd0064",
  "function_name": "dotnet8-lambda",
  "function_version": "$LATEST",
  "function_memory_size": 512,
  "function_arn": "arn:aws:lambda:eu-west-1:123:function:dotnet8-lambda",
  "function_request_id": "ebabe9cf-b8ad-4a60-ab95-083193c57d23",
  "timestamp": "2024-10-04T13:29:19.9045154Z",
  "level": "Information",
  "service": "service_undefined",
  "name": "AWS.Lambda.Powertools.Logging.Logger",
  "message": 3
}
{
  "cold_start": true,
  "xray_trace_id": "1-66ffedaf-79b1a03a1a45356a1bbd0064",
  "function_name": "dotnet8-lambda",
  "function_version": "$LATEST",
  "function_memory_size": 512,
  "function_arn": "arn:aws:lambda:eu-west-1:123:function:dotnet8-lambda",
  "function_request_id": "ebabe9cf-b8ad-4a60-ab95-083193c57d23",
  "timestamp": "2024-10-04T13:29:19.9076990Z",
  "level": "Information",
  "service": "service_undefined",
  "name": "AWS.Lambda.Powertools.Logging.Logger",
  "message": {
    "r": 199,
    "g": 21,
    "b": 133,
    "a": 255,
    "is_known_color": true,
    "is_empty": false,
    "is_named_color": true,
    "is_system_color": false,
    "name": "MediumVioletRed"
  }
}
END RequestId: ebabe9cf-b8ad-4a60-ab95-083193c57d23
REPORT RequestId: ebabe9cf-b8ad-4a60-ab95-083193c57d23	Duration: 452.85 ms	Billed Duration: 453 ms	Memory Size: 512 MB	Max Memory Used: 69 MB	Init Duration: 282.30 ms	
XRAY TraceId: 1-66ffedaf-79b1a03a1a45356a1bbd0064	SegmentId: 50ec4715c09b65cb	Sampled: true

nCubed · 2024-10-04T13:51:41Z

The only differences I'm seeing between your sample project and mine are:

we are using top level statement Lambdas
we explicitly define the output type: <OutputType>Exe</OutputType>

The rest of the .csproj definitions are identical for all intents and purposes.

Doubt it matters, but we also decorate our Handler with some Logging attributes:

[Logging(
    Service = "Our Service Name",
    ClearState = true,
    LoggerOutputCase = LoggerOutputCase.SnakeCase)]
async Task Handler(CloudWatchEvent<object> evt, ILambdaContext ctx)

The other difference we probably have is we deploy our lambdas as a zip file to S3. Here's the ADO pipeline template that builds the project:

- bash: |
    set -eou pipefail

    echo 'Running dotnet publish...'
    dotnet publish "${{ parameters.project_file }}" \
      --output bin/ \
      --configuration Release \
      --runtime linux-x64 \
      --self-contained False \
      /p:GenerateRuntimeConfigurationFiles=true

    echo 'Zipping publish artifacts...'
    cd bin
    zip -r "../${{ parameters.aws_bucket_object_key }}" ./*
    cd ..

    rm -rf bin/
    echo 'Done!'
  displayName: Build .Net Lambda

We then have a couple of the ADO tasks that upload to S3 and then update the Lambda with the latest zip.

Please let me know if you need any other information.

hjgraca · 2024-10-04T14:27:31Z

@nCubed , your deployment is similar to what I am doing.
Can you reach out to me so we can jump on a call?
email: henrigra@amazon.com or discord https://discord.com/channels/@me/hjgraca/

nCubed · 2024-10-04T16:01:36Z

@hjgraca - email sent. Thanks!

hjgraca · 2024-10-22T08:34:46Z

Release 1.16 - Logging 1.6.2

nCubed added bug Unexpected, reproducible and unintended software behaviour triage Pending triage from maintainers labels Oct 2, 2024

github-project-automation bot added this to Powertools for AWS Lambda (.NET) Oct 2, 2024

hjgraca moved this to 📋 Backlog in Powertools for AWS Lambda (.NET) Oct 2, 2024

hjgraca added area/logging Core logging utility and removed triage Pending triage from maintainers labels Oct 2, 2024

hjgraca mentioned this issue Oct 2, 2024

chore: Remove TypeInfoResolver from non AOT mode. #657

Merged

7 tasks

github-actions bot added the pending-release Fix or implementation already in dev waiting to be released label Oct 2, 2024

hjgraca mentioned this issue Oct 2, 2024

chore: Sync main with develop for release #658

Merged

7 tasks

hjgraca moved this from 📋 Backlog to ✅ Done in Powertools for AWS Lambda (.NET) Oct 2, 2024

hjgraca linked a pull request Oct 2, 2024 that will close this issue

chore: Remove TypeInfoResolver from non AOT mode. #657

Merged

7 tasks

hjgraca added released Fix or implementation already in main and released and removed pending-release Fix or implementation already in dev waiting to be released labels Oct 3, 2024

dreamorosi mentioned this issue Oct 7, 2024

Roadmap update reminder weekly - .NET aws-powertools/actions#41

Open

dreamorosi mentioned this issue Oct 7, 2024

Roadmap update reminder weekly - Python aws-powertools/powertools-lambda-python#4929

Open

hjgraca self-assigned this Oct 8, 2024

This was referenced Oct 22, 2024

chore: Fix logging enum serialization #670

Merged

Maintenance: Release 1.16 #671

Closed

hjgraca closed this as completed Oct 22, 2024

github-actions bot added the pending-release Fix or implementation already in dev waiting to be released label Oct 22, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Bug: Enum logging throws NotSupportedException and empty log entry when running under .net8 #656

Bug: Enum logging throws NotSupportedException and empty log entry when running under .net8 #656

nCubed commented Oct 2, 2024

hjgraca commented Oct 2, 2024

nCubed commented Oct 2, 2024 •

edited

Loading

hjgraca commented Oct 2, 2024 •

edited

Loading

nCubed commented Oct 2, 2024

nCubed commented Oct 2, 2024

hjgraca commented Oct 2, 2024

hjgraca commented Oct 2, 2024

nCubed commented Oct 2, 2024

hjgraca commented Oct 2, 2024

nCubed commented Oct 2, 2024

hjgraca commented Oct 2, 2024

nCubed commented Oct 4, 2024

hjgraca commented Oct 4, 2024 •

edited

Loading

nCubed commented Oct 4, 2024

hjgraca commented Oct 4, 2024

nCubed commented Oct 4, 2024

hjgraca commented Oct 22, 2024

Bug: Enum logging throws NotSupportedException and empty log entry when running under .net8 #656

Bug: Enum logging throws NotSupportedException and empty log entry when running under .net8 #656

Comments

nCubed commented Oct 2, 2024

Expected Behaviour

Current Behaviour

Code snippet

Possible Solution

Steps to Reproduce

Powertools for AWS Lambda (.NET) version

AWS Lambda function runtime

Debugging logs

hjgraca commented Oct 2, 2024

nCubed commented Oct 2, 2024 • edited Loading

hjgraca commented Oct 2, 2024 • edited Loading

nCubed commented Oct 2, 2024

nCubed commented Oct 2, 2024

hjgraca commented Oct 2, 2024

hjgraca commented Oct 2, 2024

nCubed commented Oct 2, 2024

hjgraca commented Oct 2, 2024

nCubed commented Oct 2, 2024

hjgraca commented Oct 2, 2024

nCubed commented Oct 4, 2024

hjgraca commented Oct 4, 2024 • edited Loading

Code

csproj

Output

nCubed commented Oct 4, 2024

hjgraca commented Oct 4, 2024

nCubed commented Oct 4, 2024

hjgraca commented Oct 22, 2024

nCubed commented Oct 2, 2024 •

edited

Loading

hjgraca commented Oct 2, 2024 •

edited

Loading

hjgraca commented Oct 4, 2024 •

edited

Loading