Performance Issues: Slow Initial Calls

[MuadDib]

Describe the bug

We've observed that the initial call to DynamoDB is quite slow, often exceeding 2000ms, and sometimes even approaching 10,000ms. Subsequent calls improve significantly (usually under 20ms), but we occasionally see slower calls (500ms+) after periods of inactivity.

We are seeing the same performance using both IDynamoDBContext and the IAmazonDynamoDB.
We tried using strategies outlined here to improve the situation but no luck. I even tried hardcoding the accessKey but to no avail.

Regression Issue

• Select this option if this issue appears to be a regression.

Expected Behavior

Client execution time even for the first request should not be an outlier by such a huge margin.

Current Behavior

Example of metrics for the first request vs followup request

[
    {
        "properties": {
            "AsyncCall": "True",
            "CanonicalRequest": "",
            "StringToSign": "AWS4-HMAC-SHA256",
            "ServiceName": "Amazon.DynamoDBv2",
            "ServiceEndpoint": "https://dynamodb.eu-west-1.amazonaws.com/",
            "MethodName": "GetItemRequest",
            "RequestSize": "126",
            "StatusCode": "OK",
            "BytesProcessed": "209",
            "AWSRequestID": "K19J5R1DG85P5U40973N60VP7VVV4KQNSO5AEMVJF66Q9ASUAAJG"
        },
        "timings": {
            "CredentialsRequestTime": 0.9548,
            "RequestSigningTime": 244.6937,
            "HttpRequestTime": 502.974,
            "ResponseUnmarshallTime": 5.8003,
            "ResponseProcessingTime": 21.274,
            "ClientExecuteTime": 879.363
        },
        "counters": {}
    },
    {
        "properties": {
            "AsyncCall": "True",
            "CanonicalRequest": "",
            "ServiceName": "Amazon.DynamoDBv2",
            "ServiceEndpoint": "https://dynamodb.eu-west-1.amazonaws.com/",
            "MethodName": "GetItemRequest",
            "RequestSize": "126",
            "StatusCode": "OK",
            "BytesProcessed": "209",
            "AWSRequestID": "03U2E2TDLSRB3T87ACBEP0BEN3VV4KQNSO5AEMVJF66Q9ASUAAJG"
        },
        "timings": {
            "CredentialsRequestTime": 0.0058,
            "RequestSigningTime": 0.2945,
            "HttpRequestTime": 2.7207,
            "ResponseUnmarshallTime": 0.0642,
            "ResponseProcessingTime": 0.2808,
            "ClientExecuteTime": 3.6218
        },
        "counters": {}
    }
]

Reproduction Steps

Minimal code directly copied from tutorials exhibit the same issue. I pasted an example in lambda for IDynamoDBContext , but it's the same executing from ECS container.

public class Functions
{
    private IDynamoDBContext _dynamoDbContext;
    public Functions()
    {
        _dynamoDbContext = new DynamoDBContext(new AmazonDynamoDBClient());
    }
    [LambdaFunction]
    [RestApi(LambdaHttpMethod.Get, "/")]
    public async Task<IHttpResult> Get(ILambdaContext context)
    {
        var queryConfig = new DynamoDBOperationConfig
        {
            OverrideTableName = "paywall-cwwebsite-subscriptions-qa",
            QueryFilter = new List<ScanCondition>
            {
                new("sk", ScanOperator.Equal, "GLOBAL")
            }
        };

        var subscriberInfo = await _dynamoDbContext.QueryAsync<SubscriberInfoDto>("google.com", queryConfig).GetRemainingAsync();

        return HttpResults.Ok();
    }
}

Possible Solution

No response

Additional Information/Context

No response

AWS .NET SDK and/or Package version used

Targeted .NET Platform

net8.0

Operating System and version

Lambda

[ashishdhingra]

@MuadDib Good afternoon. Could you please review if your issue is similar to #3551.

Also, could you enable verbose logs and metrics using below code and share the same:

Amazon.AWSConfigs.LoggingConfig.LogResponses = Amazon.ResponseLoggingOption.Always;
Amazon.AWSConfigs.LoggingConfig.LogTo = Amazon.LoggingOptions.Console;
Amazon.AWSConfigs.LoggingConfig.LogMetrics = true;
 Amazon.AWSConfigs.AddTraceListener("Amazon", new System.Diagnostics.ConsoleTraceListener());

Verbose logs would enable us to measure the latency on .NET SDK side.

Also refer to #3551 (comment) if that helps.

Looks like your execution environment is Lambda. Initial latency could also be caused by Lambda cold starts.

You may also explore new feature Improving startup performance with Lambda SnapStart to improve initial latency.

Thanks,
Ashish

[MuadDib]

Hello Ashish,

Thank you for your reply!

Could you please let me know the approximate response time expected for the first request? I’m specifically wondering whether it falls within a range of tens of milliseconds or hundreds of milliseconds.

Additionally, do you know of any resources that showcase the performance of the .NET client? I’m particularly interested in understanding the expected response time for the first request. I understand that this has been identified as an issue, and you’re working to improve it in the next version of the client. However, it would be extremely helpful to know the expected response times for both the current version and the improved version. Even if you don’t have precise data, an approximate timing would still be very valuable to me.

To give some context about our tech stack:
We are moving towards a fully serverless architecture. Our clients connect to AWS API Gateway, which uses simple mapping lambdas to retrieve data directly from read models in DynamoDB. The client workload is relatively low volume, with extended periods of inactivity.

Our lambdas are optimized for minimal cold-start times, typically just a few milliseconds. However, this optimization becomes irrelevant if the connection to DynamoDB takes a long time to initialize. Since lambdas have a very short lifecycle (often only a few minutes before AWS destroys the running container), a lengthy initialization time for DynamoDB becomes a critical issue that could halt our progress.

Thank you for your insights and assistance!

PS as per your request I added the logging and simplified the code:

public class Functions
{
    private readonly AmazonDynamoDBClient _dynamoDbClient = new ();
    public Functions()
    {
        Amazon.AWSConfigs.LoggingConfig.LogResponses = Amazon.ResponseLoggingOption.Always;
        Amazon.AWSConfigs.LoggingConfig.LogTo = Amazon.LoggingOptions.Console;
        Amazon.AWSConfigs.LoggingConfig.LogMetrics = true;
        Amazon.AWSConfigs.AddTraceListener("Amazon", new System.Diagnostics.ConsoleTraceListener());
    }
    [LambdaFunction]
    [RestApi(LambdaHttpMethod.Get, "/")]
    public async Task<IHttpResult> Get(ILambdaContext context)
    {
        var queryConfig = new GetItemRequest()
        {
            TableName = "test-table",
            Key = {
                { "pk", new AttributeValue { S = "@google.com" } },
                { "sk", new AttributeValue { S = "GLOBAL" } }}
        };

        var subscriberInfo = await _dynamoDbClient.GetItemAsync(queryConfig);
        return HttpResults.Ok();
    }
}

Full log: log.txt
When deployed to AWS: logAws.txt

AmazonDynamoDBClient 1|2024-11-25T10:47:00.011Z|DEBUG|Received response (truncated to 1024 bytes): [{"Item":{"subscriptionStatus":{"S":"Active"},"sk":{"S":"GLOBAL"},"pk":{"S":"@google.com"},"subscriptionStartDate":{"S":"2024-05-28T00:00:00.0000000"},"subscriptionEndDate":{"S":"2025-05-28T00:00:00.0000000"}}}]

These are example metrics that we see for the Initial call vs subsequent call:

[
    //call 1
    {
        "properties": {
            "AsyncCall": "True",
            "CanonicalRequest": "",
            "StringToSign": "AWS4-HMAC-SHA256",
            "ServiceName": "Amazon.DynamoDBv2",
            "ServiceEndpoint": "https://dynamodb.eu-west-1.amazonaws.com/",
            "MethodName": "GetItemRequest",
            "RequestSize": "126",
            "StatusCode": "OK",
            "BytesProcessed": "209",
            "AWSRequestID": "K19J5R1DG85P5U40973N60VP7VVV4KQNSO5AEMVJF66Q9ASUAAJG"
        },
        "timings": {
            "CredentialsRequestTime": 0.9548,
            "RequestSigningTime": 244.6937,
            "HttpRequestTime": 502.974,
            "ResponseUnmarshallTime": 5.8003,
            "ResponseProcessingTime": 21.274,
            "ClientExecuteTime": 879.363
        },
        "counters": {}
    },
    //call 2
    {
        "properties": {
            "AsyncCall": "True",
            "CanonicalRequest": "",
            "ServiceName": "Amazon.DynamoDBv2",
            "ServiceEndpoint": "https://dynamodb.eu-west-1.amazonaws.com/",
            "MethodName": "GetItemRequest",
            "RequestSize": "126",
            "StatusCode": "OK",
            "BytesProcessed": "209",
            "AWSRequestID": "03U2E2TDLSRB3T87ACBEP0BEN3VV4KQNSO5AEMVJF66Q9ASUAAJG"
        },
        "timings": {
            "CredentialsRequestTime": 0.0058,
            "RequestSigningTime": 0.2945,
            "HttpRequestTime": 2.7207,
            "ResponseUnmarshallTime": 0.0642,
            "ResponseProcessingTime": 0.2808,
            "ClientExecuteTime": 3.6218
        },
        "counters": {}
    }
]

[MuadDib]

After conducting further investigation into the issue, I drew inspiration from similar challenges reported in the Java SDK, particularly those described in this GitHub issue. My aim was to evaluate whether changes in allocated memory for the Lambda function would influence the response time from DynamoDB.

As part of this analysis, I tested the DynamoDBv2 4.0.0-preview.4 client to determine if the newer version offers any significant performance improvements. Additionally, I implemented a Node.js Lambda function that executes the same GetItem request for comparison. Finally, I experimented with mapping API Gateway directly to DynamoDB using VTL (Velocity Template Language). While RAM allocation had no effect in the API Gateway direct mapping scenario, I included it in the graph for comparative purposes.

The results of my experiments are summarized in the graphs below:

Key Findings

• A clear correlation exists between memory allocation and response time, with higher memory resulting in faster execution.
• The gain is logarithmic, the greatest difference is observed between 512 and 2048 Gb of RAM
• The upcoming version of the DynamoDB .NET client demonstrates some performance improvements.
• Both the VTL mapping and Node.js Lambda options are 5 to 7 times faster than the .NET-based implementation.
• As a side note, the lambda was reporting that "Max Memory Used: 98 MB" for every execution. Not sure how it calcualtes that but found it interesting none the less.

Based on these results, it appears that the .NET DynamoDB client may not be well-suited for our performance requirements.