Excessive KMS Decrypt API Calls When Using Concurrent Client

[jshlbrd]

Hi folks,

I'm seeing anomalous KMS decrypt behavior when concurrently using a DynamoDB client (with a customer managed key) -- the number of Decrypt API calls appears to correlate with the call originating in a new thread. For example, the first pseudo-code below produces less API calls than the second pseudo-code:

client := dynamodb.NewFromConfig(cfg)

for i := 0; i < 100; i++ {
  client.GetItem(ctx, &dynamodb.GetItemInput{})
}

client := dynamodb.NewFromConfig(cfg)

for i := 0; i < 100; i++ {
  go func() {
    client.GetItem(ctx, &dynamodb.GetItemInput{})
  }()
}

I'm seeing this when only a single DynamoDB client is used and the DDB API call is always GetItem (though I assume other API calls are equally effected). With production workloads the number of Decrypt calls significantly drives up the price of KMS. Anyone know if this is expected or how to debug it further?

[jshlbrd]

Here's a complete program that consistently shows the problem:

// Example program for https://github.com/aws/aws-sdk-go-v2/discussions/2128. To setup,
// create two DynamoDB tables that use a customer managed key (CMK) for encryption:
// - aws_sdk_go_v2_2128
// - aws_sdk_go_v2_2128_concurrency
//
// Run this program with default credentials for decrypting the CMK and reading from the
// tables. After running, check the CloudTrail logs for the number of Decrypt API calls
// made for each table. The non-concurrent table makes 1 call while the concurrent
// table makes between 1 to 25 calls (usually closer to 25).
package main

import (
	"context"

	"github.com/aws/aws-sdk-go-v2/aws"
	"github.com/aws/aws-sdk-go-v2/config"
	"github.com/aws/aws-sdk-go-v2/feature/dynamodb/attributevalue"
	"github.com/aws/aws-sdk-go-v2/service/dynamodb"
	"golang.org/x/sync/errgroup"
)

func main() {
	ctx := context.TODO()
	cfg, err := config.LoadDefaultConfig(ctx)
	if err != nil {
		panic(err)
	}

	client := dynamodb.NewFromConfig(cfg)

	// put the same partition key into both tables for testing
	key, err := attributevalue.MarshalMap(map[string]interface{}{
		"PK": "a",
	})
	if err != nil {
		panic(err)
	}

	// read from the first table without concurrency
	for i := 0; i < 25; i++ {
		_, err := client.GetItem(ctx, &dynamodb.GetItemInput{
			TableName: aws.String("aws_sdk_go_v2_2128"),
			Key:       key,
		})
		if err != nil {
			panic(err)
		}
	}

	// read from the second table with concurrency
	e, ctx := errgroup.WithContext(ctx)
	for i := 0; i < 25; i++ {
		e.Go(func() error {
			_, err := client.GetItem(ctx, &dynamodb.GetItemInput{
				TableName: aws.String("aws_sdk_go_v2_2128_concurrency"),
				Key:       key,
			})
			if err != nil {
				return err
			}

			return nil
		})
	}

	if err := e.Wait(); err != nil {
		panic(err)
	}
}

[RanVaknin]

Hi @jshlbrd,

I see you opened an issue about this as well. I will close this discussion in favor of tracking this in the issue itself.

I'm a bit confused by the problem you are describing. When creating a table on Dynamo, you can specify which key you want to use for encryption at rest (whether its AWS managed or a CMK), the encryption is happening on the service side as described in this doc:

When you access an encrypted table, DynamoDB decrypts the table data transparently. You don't have to change any code or applications to use or manage encrypted tables. DynamoDB continues to deliver the same single-digit millisecond latency that you have come to expect, and all DynamoDB queries work seamlessly on your encrypted data.

In other words, the SDK does not know / care about encryption at rest for dynamo.

To make sure I'm not wrong, I provisioned Dynamodb tables with CMK per your description:

$ aws dynamodb describe-table --table-name aws_sdk_go_v2_2128

{
    "Table": {
        "AttributeDefinitions": [
            {
                "AttributeName": "pk",
                "AttributeType": "S"
            }
        ],
        "TableName": "aws_sdk_go_v2_2128",
        "KeySchema": [
            {
                "AttributeName": "pk",
                "KeyType": "HASH"
            }
        ],
        "TableStatus": "ACTIVE",
        "CreationDateTime": "2023-05-15T15:46:02.519000-07:00",
        "ProvisionedThroughput": {
            "NumberOfDecreasesToday": 0,
            "ReadCapacityUnits": 1,
            "WriteCapacityUnits": 1
        },
        "TableSizeBytes": 0,
        "ItemCount": 0,
        "TableArn": "arn:aws:dynamodb:us-east-1:REDACTED:table/aws_sdk_go_v2_2128",
        "TableId": "REDACTED",
        "SSEDescription": {
            "Status": "ENABLED",
            "SSEType": "KMS",
            "KMSMasterKeyArn": "arn:aws:kms:us-east-1:REDACTED"
        },
        "TableClassSummary": {
            "TableClass": "STANDARD"
        },
        "DeletionProtectionEnabled": false
    }
}

Using the code you have provided I'm not seeing any network calls to KMS.
You can enable client logs on your config like so:

	ctx := context.TODO()
	cfg, err := config.LoadDefaultConfig(ctx, config.WithClientLogMode(aws.LogResponseWithBody|aws.LogRequestWithBody))
	if err != nil {
		panic(err)
	}

You will see 25 network calls to the Dynamodb service, but no calls are made to KMS.

Please refer to the issue you have opened for following steps.

Thanks,
Ran~