aws-powertools / powertools-lambda-dotnet

Powertools is a developer toolkit to implement Serverless best practices and increase developer velocity.
https://docs.powertools.aws.dev/lambda/dotnet/
MIT No Attribution
151 stars 23 forks source link

Bug: Logger not threadsafe across multiple parallel test classes #601

Open samrobley opened 2 months ago

samrobley commented 2 months ago

Expected Behaviour

Run until failure completes without failure

Current Behaviour

Random failures after anywhere from 1 to 10 test runs

    Message: 
System.AggregateException : One or more errors occurred. (An item with the same key has already been added. Key: ColdStart)
---- System.ArgumentException : An item with the same key has already been added. Key: ColdStart

    Stack Trace: 
Task.ThrowIfExceptional(Boolean includeTaskCanceledExceptions)
Task`1.GetResultCore(Boolean waitCompletionNotification)
UnitTest2.Test2() line 24
RuntimeMethodHandle.InvokeMethod(Object target, Void** arguments, Signature sig, Boolean isConstructor)
MethodBaseInvoker.InvokeWithNoArgs(Object obj, BindingFlags invokeAttr)
----- Inner Stack Trace -----
Dictionary`2.TryInsert(TKey key, TValue value, InsertionBehavior behavior)
Dictionary`2.Add(TKey key, TValue value)
Logger.AppendKey(String key, Object value)
LoggingAspectHandler.OnEntry(AspectEventArgs eventArgs)
MethodAspectAttribute.WrapAsync[T](Func`2 target, Object[] args, AspectEventArgs eventArgs)

Code snippet

using Amazon.Lambda.CloudWatchEvents;
using Amazon.Lambda.CloudWatchEvents.S3Events;
using Amazon.Lambda.Core;
using Amazon.Lambda.TestUtilities;
using AWS.Lambda.Powertools.Logging;
using FluentAssertions;
using Xunit;

namespace TestProject1;

public class Function
{
    public Function()
    {
    }

    [Logging(Service = "TestExample")]
    // cloudwatch s3 eventbridge event
    public async Task<bool> Invoke(CloudWatchEvent<S3ObjectCreate> cloudWatchEvent, ILambdaContext context)
    {
        Logger.LogInformation("Processing S3 event");
        return true;
    }
}

public class UnitTest1
{
    [Fact]
    public void Test1()
    {
        // Arrange
        Function function = new Function();
        CloudWatchEvent<S3ObjectCreate> cloudWatchEvent = new CloudWatchEvent<S3ObjectCreate>();
        var context = new TestLambdaContext();

        // Act
        var response = function.Invoke(cloudWatchEvent, context);

        // Assert
        response.Result.Should().BeTrue();
    }
}

public class UnitTest2
{
    [Fact]
    public void Test2()
    {
        // Arrange
        Function function = new Function();
        CloudWatchEvent<S3ObjectCreate> cloudWatchEvent = new CloudWatchEvent<S3ObjectCreate>();
        var context = new TestLambdaContext();

        // Act
        var response = function.Invoke(cloudWatchEvent, context);

        // Assert
        response.Result.Should().BeTrue();
    }
}

Possible Solution

Noted a similar issue cropped up with the Python lambda powertools append keys: [https://github.com/aws-powertools/powertools-lambda-python/issues/2040]

Steps to Reproduce

This is re-producible with the code snippet above.

The workaround is to decorate the classes with: [Collection("Sequential")]

Powertools for AWS Lambda (.NET) version

latest

AWS Lambda function runtime

dotnet6

Debugging logs

Message: 
System.AggregateException : One or more errors occurred. (An item with the same key has already been added. Key: ColdStart)
---- System.ArgumentException : An item with the same key has already been added. Key: ColdStart

    Stack Trace: 
Task.ThrowIfExceptional(Boolean includeTaskCanceledExceptions)
Task`1.GetResultCore(Boolean waitCompletionNotification)
UnitTest2.Test2() line 59
RuntimeMethodHandle.InvokeMethod(Object target, Void** arguments, Signature sig, Boolean isConstructor)
MethodBaseInvoker.InvokeWithNoArgs(Object obj, BindingFlags invokeAttr)
----- Inner Stack Trace -----
Dictionary`2.TryInsert(TKey key, TValue value, InsertionBehavior behavior)
Dictionary`2.Add(TKey key, TValue value)
Logger.AppendKey(String key, Object value)
LoggingAspectHandler.OnEntry(AspectEventArgs eventArgs)
MethodAspectAttribute.WrapAsync[T](Func`2 target, Object[] args, AspectEventArgs eventArgs)
boring-cyborg[bot] commented 2 months ago

Thanks for opening your first issue here! We'll come back to you as soon as we can. In the meantime, check out the #dotnet channel on our Powertools for AWS Lambda Discord: Invite link

hjgraca commented 1 month ago

@samrobley thanks for opening the issue and sorry for the late reply. We are currently focused on releasing AOT features and are delaying low priority issues. If you have the time and could contribute to this it would be great, if not, rest assured we will work on it once we have released AOT support. Thanks