Bug: AoT does not work with metrics or logger

Question

Bug: AoT does not work with metrics or logger

Opened this issue 9 days ago · 9 comments

Expected Behaviour

Logger should work with AoT trimming enabled.

Current Behaviour

The following exception is thrown

10-Oct-2024 9:34:07 AM	2024-10-10T13:34:07.448Z 9bc362e6-76bc-4f22-b004-8c5622ca8078 fail System.InvalidOperationException: Reflection-based serialization has been disabled for this application. Either use the source generator APIs or explicitly configure the 'JsonSerializerOptions.TypeInfoResolver' property.
   at System.Text.Json.ThrowHelper.ThrowInvalidOperationException_JsonSerializerIsReflectionDisabled()
   at System.Text.Json.JsonSerializerOptions.ConfigureForJsonSerializer()
   at System.Text.Json.JsonSerializer.GetTypeInfo(JsonSerializerOptions, Type)
   at System.Text.Json.JsonSerializer.GetTypeInfo[T](JsonSerializerOptions)
   at System.Text.Json.JsonSerializer.Serialize[TValue](TValue, JsonSerializerOptions )
   at AWS.Lambda.Powertools.Logging.Serializers.PowertoolsLoggingSerializer.Serialize(Object, Type)
   at AWS.Lambda.Powertools.Logging.Internal.PowertoolsLogger.Log[TState](LogLevel, EventId, TState, Exception, Func`3)
   at Microsoft.Extensions.Logging.LoggerExtensions.Log(ILogger , LogLevel, EventId, Exception, String, Object[] )
   at Microsoft.Extensions.Logging.LoggerExtensions.LogInformation(ILogger, String , Object[] )
   at submit_feedback.Function.FunctionHandlerAsync(SubmitFeedbackRequest request, ILambdaContext context) in ./Function.cs:line 63
   at Amazon.Lambda.RuntimeSupport.HandlerWrapper.<>c__DisplayClass14_0`1.<<GetHandlerWrapper>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at Amazon.Lambda.RuntimeSupport.LambdaBootstrap.InvokeOnceAsync(CancellationToken )

Code snippet

Here are the relevant lines of what I have in my csproj file (Let me know if you need more context):

<PropertyGroup>
    <PublishReadyToRun>true</PublishReadyToRun>
    <StripSymbols>true</StripSymbols>
    <PublishTrimmed>true</PublishTrimmed>
    <TrimMode>partial</TrimMode>
</PropertyGroup>
<ItemGroup>
    <!-- Exclude EF Core assemblies from being trimmed (not supported) -->
    <TrimmerRootAssembly Include="Microsoft.EntityFrameworkCore" />
    <TrimmerRootAssembly Include="Microsoft.EntityFrameworkCore.Relational" />
    <TrimmerRootAssembly Include="Npgsql.EntityFrameworkCore.PostgreSQL" />
    <TrimmerRootAssembly Include="EFCore.NamingConventions" />
</ItemGroup>

Here's how I've been able to minimally reproduce this issue:

public class Function
{
    private static async Task Main()
    {
        Console.WriteLine("Starting up");
        Func<SubmitFeedbackRequest, ILambdaContext, Task> handler = FunctionHandlerAsync;
        await LambdaBootstrapBuilder.Create(handler, new PowertoolsSourceGeneratorSerializer<LambdaFunctionJsonContext>())
            .Build()
            .RunAsync();

        Console.WriteLine("Shutting down");
    }

   [Logging]
   public static async Task FunctionHandlerAsync(SubmitFeedbackRequest request, ILambdaContext context)
   {
       Logger.LogInformation("Starting up!");
    }
}

[JsonSerializable(typeof(SubmitFeedbackRequest))]
public partial class LambdaFunctionJsonContext : JsonSerializerContext { }

For reference, here are my package versions:

Possible Solution

No response

Steps to Reproduce

See code snippet.

Powertools for AWS Lambda (.NET) version

latest

AWS Lambda function runtime

dotnet8 (AOT)

Debugging logs

No response

Answer 1 · 2024-10-10T17:03:48.000Z

@Euclidite I can reproduce the error you are getting when I have the PublishTrimmed
The correct configuration to run Lambda on AOT would be <PublishAot>true</PublishAot> instead of <PublishTrimmed>true</PublishTrimmed>:

<!-- Generate Native AOT image during publishing to improve cold start time. -->
    <PublishAot>true</PublishAot>
    <!-- StripSymbols tells the compiler to strip debugging symbols from the final executable if we're on Linux and put them into their own file. 
    This will greatly reduce the final executable's size.-->
    <StripSymbols>true</StripSymbols>
    <!-- TrimMode partial will only trim assemblies marked as trimmable. To reduce package size make all assemblies trimmable and set TrimMode to full.
    If there are trim warnings during build, you can hit errors at runtime.-->
    <TrimMode>partial</TrimMode>

One explanation for the differences between both those properties dotnet/runtime#97288 (comment)
Also you don't need the <PublishReadyToRun>true</PublishReadyToRun> property

Answer 2 · 2024-10-10T19:44:37.000Z

The config I was using was to slowly get to full AoT because using true forces it to use a docker build, so I wanted to chip away at a single problem at a time 😉

Regardless, I tested out with your suggested changes, but I still get the same error message.

Answer 3 · 2024-10-10T20:25:51.000Z

Indeed local dev docker is required, I usually use a dev box ie: an ec2 AL2023 and develop/piblish from there, no docker needed 😀
Same error message? On the code you shared?

Answer 4 · 2024-10-10T20:42:21.000Z

Oh! I might look into setting that up once we iron out some of our build pipelines - thanks for the tip!

And yes:

I didn't change anything from my sample Function code
I updated the .csproj with your suggested changes
Published (it invoked docker, built, pushed)
Invoked - same error as originally noted

Answer 5 · 2024-10-10T21:37:27.000Z

I can't seem to replicate the issue, here is my code:
I even changed main to the initial code you had.

Function.cs

using Amazon.Lambda.Core;
using Amazon.Lambda.RuntimeSupport;
using AWS.Lambda.Powertools.Logging;
using AWS.Lambda.Powertools.Logging.Serializers;
using System.Text.Json.Serialization;

namespace pt_aot_test;

public class Function
{
    private static async Task Main()
    {
        await LambdaBootstrapBuilder.Create<SubmitFeedbackRequest>(
                                        FunctionHandlerAsync,
                                        new PowertoolsSourceGeneratorSerializer<LambdaFunctionJsonContext>())
            .Build()
            .RunAsync();
    }

    [Logging]
    public static async Task FunctionHandlerAsync(SubmitFeedbackRequest request, ILambdaContext context)
    {
        Logger.LogInformation("Starting up!");
    }
}

public class SubmitFeedbackRequest
{
    public int Id { get; set; }
}

[JsonSerializable(typeof(SubmitFeedbackRequest))]
public partial class LambdaFunctionJsonContext : JsonSerializerContext { }

csproj

<Project Sdk="Microsoft.NET.Sdk">
  <PropertyGroup>
    <OutputType>Exe</OutputType>
    <TargetFramework>net8.0</TargetFramework>
    <ImplicitUsings>enable</ImplicitUsings>
    <Nullable>enable</Nullable>
    <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>false</CopyLocalLockFileAssemblies>
    <!-- Generate Native AOT image during publishing to improve cold start time. -->
    <PublishAot>true</PublishAot>
    <!-- StripSymbols tells the compiler to strip debugging symbols from the final executable if we're on Linux and put them into their own file. 
    This will greatly reduce the final executable's size.-->
    <StripSymbols>true</StripSymbols>
    <!-- TrimMode partial will only trim assemblies marked as trimmable. To reduce package size make all assemblies trimmable and set TrimMode to full.
    If there are trim warnings during build, you can hit errors at runtime.-->
    <TrimMode>partial</TrimMode>
  </PropertyGroup>
  <ItemGroup>
    <PackageReference Include="Amazon.Lambda.APIGatewayEvents" Version="2.7.1" />
    <PackageReference Include="Amazon.Lambda.RuntimeSupport" Version="1.11.0" />
    <PackageReference Include="Amazon.Lambda.Core" Version="2.3.0" />
    <PackageReference Include="Amazon.Lambda.Serialization.SystemTextJson" Version="2.4.3" />
    <PackageReference Include="AWS.Lambda.Powertools.Logging" Version="1.6.1" />
  </ItemGroup>
</Project>

aws-lambda-tools-defaults.json (don't think it matters)

  "profile": "",
  "region": "eu-west-1",
  "configuration": "Release",
  "function-runtime": "dotnet8",
  "function-memory-size": 512,
  "function-timeout": 5,
  "function-handler": "pt-aot-test",
  "function-architecture": "x86_64",
  "framework": "net8.0",
  "msbuild-parameters": "--self-contained true"

Answer 6 · 2024-10-11T05:32:06.000Z

I've compared the values, and I have them set identically. I retested just in case and still get the same error (or well slightly different, but I think that's simply because of the AoT)

11-Oct-2024 1:19:49 AM	2024-10-11T05:19:49.133Z da531fee-6b61-46b3-bda9-ac09127aa30c fail System.InvalidOperationException: Reflection-based serialization has been disabled for this application. Either use the source generator APIs or explicitly configure the 'JsonSerializerOptions.TypeInfoResolver' property.
   at System.Text.Json.ThrowHelper.ThrowInvalidOperationException_JsonSerializerIsReflectionDisabled()
   at System.Text.Json.JsonSerializerOptions.ConfigureForJsonSerializer()
   at System.Text.Json.JsonSerializer.GetTypeInfo(JsonSerializerOptions, Type)
   at System.Text.Json.JsonSerializer.GetTypeInfo[T](JsonSerializerOptions)
   at System.Text.Json.JsonSerializer.Serialize[TValue](TValue, JsonSerializerOptions )
   at AWS.Lambda.Powertools.Logging.Serializers.PowertoolsLoggingSerializer.Serialize(Object, Type)
   at AWS.Lambda.Powertools.Logging.Internal.PowertoolsLogger.Log[TState](LogLevel, EventId, TState, Exception, Func`3)
   at Microsoft.Extensions.Logging.LoggerExtensions.Log(ILogger , LogLevel, EventId, Exception, String, Object[] )
   at Microsoft.Extensions.Logging.LoggerExtensions.LogInformation(ILogger, String , Object[] )
   at submit_feedback.Function.FunctionHandlerAsync(SubmitFeedbackRequest request, ILambdaContext context)
   at Amazon.Lambda.RuntimeSupport.HandlerWrapper.<>c__DisplayClass14_0`1.<<GetHandlerWrapper>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at Amazon.Lambda.RuntimeSupport.LambdaBootstrap.InvokeOnceAsync(CancellationToken )

For reference, here's the SubmitFeedbackRequest class - but I don't see anything that would cause an issue

public class SubmitFeedbackRequest
{
    [Required(AllowEmptyStrings = false)]
    public required string SessionId { get; set; }

    [MinLength(1)] // This logs an AOT warning, but its safe to ignore and will be fixed in a future release
    public required IEnumerable<int> FeedbackType { get; set; }

    [Range(1, int.MaxValue)]
    public required int ReferenceId { get; set; }

    [EmailAddress]
    public required string UserEmail { get; set; }
}

I do see these warnings in the build:

... docker run: /tmp/dotnet/.nuget/packages/aws.lambda.powertools.logging/1.6.1/lib/net8.0/AWS.Lambda.Powertools.Logging.dll : warning IL3053: Assembly 'AWS.Lambda.Powertools.Logging' produced AOT analysis warnings. [/tmp/source/submitFeedback/submit-feedback.csproj]
... docker run: /tmp/dotnet/.nuget/packages/aws.lambda.powertools.logging/1.6.1/lib/net8.0/AWS.Lambda.Powertools.Logging.dll : warning IL2104: Assembly 'AWS.Lambda.Powertools.Logging' produced trim warnings. For more information see https://aka.ms/dotnet-illink/libraries [/tmp/source/submitFeedback/submit-feedback.csproj]
... docker run: ILC : Trim analysis warning IL2026: AWS.Lambda.Powertools.Logging.Serializers.PowertoolsLoggingSerializationContext.ExceptionSerializeHandler(Utf8JsonWriter,Exception): Using member 'System.Exception.TargetSite.get' which has 'RequiresUnreferencedCodeAttribute' can break functionality when trimming application code. Metadata for the method might be incomplete or removed. [/tmp/source/submitFeedback/submit-feedback.csproj]
... docker run: ILC : Trim analysis warning IL2026: AWS.Lambda.Powertools.Logging.Serializers.PowertoolsLoggingSerializationContext.<>c.<ExceptionPropInit>b__70_10(Object): Using member 'System.Exception.TargetSite.get' which has 'RequiresUnreferencedCodeAttribute' can break functionality when trimming application code. Metadata for the method might be incomplete or removed. [/tmp/source/submitFeedback/submit-feedback.csproj]

Answer 7 · 2024-10-11T07:35:06.000Z

Thanks for providing more details @Euclidite .
I am having a hard time reproducing the error. Does the code work without Powertools?
I have updated my code to match your SubmitFeedbackRequest with DataAnnotations and still works.

Function.cs

using Amazon.Lambda.Core;
using Amazon.Lambda.RuntimeSupport;
using AWS.Lambda.Powertools.Logging;
using AWS.Lambda.Powertools.Logging.Serializers;
using System.ComponentModel.DataAnnotations;
using System.Text.Json.Serialization;

namespace pt_aot_test;

public class Function
{
    private static async Task Main()
    {
        await LambdaBootstrapBuilder.Create<SubmitFeedbackRequest>(
                                        FunctionHandlerAsync,
                                        new PowertoolsSourceGeneratorSerializer<LambdaFunctionJsonContext>())
            .Build()
            .RunAsync();
    }

    [Logging]
    public static async Task FunctionHandlerAsync(SubmitFeedbackRequest request, ILambdaContext context)
    {
        Logger.LogInformation("Starting up!");

        Logger.LogInformation(request);
    }
}

public class SubmitFeedbackRequest
{
    [Required(AllowEmptyStrings = false)]
    public required string SessionId { get; set; }

    [MinLength(1)] // This logs an AOT warning, but its safe to ignore and will be fixed in a future release
    public required IEnumerable<int> FeedbackType { get; set; }

    [Range(1, int.MaxValue)]
    public required int ReferenceId { get; set; }

    [EmailAddress]
    public required string UserEmail { get; set; }
}

[JsonSerializable(typeof(SubmitFeedbackRequest))]
public partial class LambdaFunctionJsonContext : JsonSerializerContext { }

Request

{
  "SessionId": "123",
  "FeedbackType": [1,2],
  "ReferenceId": 1,
  "UserEmail": "mail@mail.com"
}

Response

{
  "coldStart": true,
  "xrayTraceId": "1-6708d42c-7547436656f7808d4abaafd9",
  "functionName": "pt-aot-test",
  "functionVersion": "$LATEST",
  "functionMemorySize": 512,
  "functionArn": "-",
  "functionRequestId": "7ddfcf41-436e-45c7-bcec-f56cc530f469",
  "timestamp": "2024-10-11T07:30:52.9777292Z",
  "level": "Information",
  "service": "henrique_service",
  "name": "AWS.Lambda.Powertools.Logging.Logger",
  "message": "Starting up!"
}
{
  "coldStart": true,
  "xrayTraceId": "1-6708d42c-7547436656f7808d4abaafd9",
  "functionName": "pt-aot-test",
  "functionVersion": "$LATEST",
  "functionMemorySize": 512,
  "functionArn": "-",
  "functionRequestId": "7ddfcf41-436e-45c7-bcec-f56cc530f469",
  "timestamp": "2024-10-11T07:30:52.9778246Z",
  "level": "Information",
  "service": "henrique_service",
  "name": "AWS.Lambda.Powertools.Logging.Logger",
  "message": {
    "sessionId": "123",
    "feedbackType": [
      1,
      2
    ],
    "referenceId": 1,
    "userEmail": "mail@mail.com"
  }
}

Answer 8 · 2024-10-11T07:37:23.000Z

If you want we can have a chat to go over this issue, just send me an email henrigra@amazon.com, or reach out on our discord

Answer 9 · 2024-10-15T14:38:14.000Z

@hjgraca apologies for the delay - I'm following up on a few things from my end & then I'll be able to retest this issue again (hopefully in a day or so). Thank you!