Skip to content
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

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

Open
samrobley opened this issue Jun 19, 2024 · 2 comments
Open

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

samrobley opened this issue Jun 19, 2024 · 2 comments
Labels
bug Unexpected, reproducible and unintended software behaviour revisit-in-3-months Blocked issues/PRs that need to be revisited tests

Comments

@samrobley
Copy link

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)
@samrobley samrobley added bug Unexpected, reproducible and unintended software behaviour triage Pending triage from maintainers labels Jun 19, 2024
Copy link

boring-cyborg bot commented Jun 19, 2024

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

@samrobley samrobley changed the title Bug: Logger not threadsafea cross multiple parallel test classes Bug: Logger not threadsafe across multiple parallel test classes Jun 19, 2024
@dreamorosi dreamorosi added revisit-in-3-months Blocked issues/PRs that need to be revisited and removed triage Pending triage from maintainers labels Jul 9, 2024
@hjgraca
Copy link
Contributor

hjgraca commented Jul 9, 2024

@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

@hjgraca hjgraca added the tests label Aug 23, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Unexpected, reproducible and unintended software behaviour revisit-in-3-months Blocked issues/PRs that need to be revisited tests
Projects
Status: ⏸️ On Hold
Development

No branches or pull requests

3 participants