Skip to content

Bug: AoT does not work with metrics or logger #668

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
Euclidite opened this issue Oct 10, 2024 · 11 comments
Closed

Bug: AoT does not work with metrics or logger #668

Euclidite opened this issue Oct 10, 2024 · 11 comments
Assignees
Labels
aot area/logging Core logging utility area/metrics Core metrics utility bug Unexpected, reproducible and unintended software behaviour

Comments

@Euclidite
Copy link

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:
Image

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

@Euclidite Euclidite added bug Unexpected, reproducible and unintended software behaviour triage Pending triage from maintainers labels Oct 10, 2024
@hjgraca hjgraca added area/metrics Core metrics utility area/logging Core logging utility aot and removed triage Pending triage from maintainers labels Oct 10, 2024
@hjgraca hjgraca moved this to 📋 Backlog in Powertools for AWS Lambda (.NET) Oct 10, 2024
@hjgraca
Copy link
Contributor

hjgraca commented Oct 10, 2024

@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

@hjgraca hjgraca self-assigned this Oct 10, 2024
@Euclidite
Copy link
Author

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.

@hjgraca
Copy link
Contributor

hjgraca commented Oct 10, 2024

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?

@Euclidite
Copy link
Author

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

@hjgraca
Copy link
Contributor

hjgraca commented Oct 10, 2024

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"

@Euclidite
Copy link
Author

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]

@hjgraca
Copy link
Contributor

hjgraca commented Oct 11, 2024

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": "[email protected]"
}

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": "[email protected]"
  }
}

@hjgraca
Copy link
Contributor

hjgraca commented Oct 11, 2024

If you want we can have a chat to go over this issue, just send me an email [email protected], or reach out on our discord

@Euclidite
Copy link
Author

@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!

@hjgraca
Copy link
Contributor

hjgraca commented Oct 24, 2024

@Euclidite if you need we can have a call to see what is failing?

@dreamorosi dreamorosi removed the triage Pending triage from maintainers label Oct 28, 2024
@hjgraca
Copy link
Contributor

hjgraca commented Nov 4, 2024

@Euclidite could not replicate. closing this for now, feel free to reach out and reopen the issue if you still find this bug.
Thanks.

@hjgraca hjgraca closed this as completed Nov 4, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
aot area/logging Core logging utility area/metrics Core metrics utility bug Unexpected, reproducible and unintended software behaviour
Projects
Status: 📋 Backlog
Development

No branches or pull requests

3 participants