Invocation time longer than expected on cold starts

yuriferretti commented 4 years ago

Expected behavior

Have consistent invocation duration even when lambda execution requires cold start

Actual behavior

When cold starting lambda function invocation takes more than 2s and the actual cold start only 200ms After cold start, invocation runs lower than 30ms for a dynamo operation.

Xray cloud watch link

Steps to reproduce

Use Lambda integrated with API Gateway and perform any operation on dynamo from lambda function

If possible, minimal yet complete reproducer code (or URL to code)

https://github.com/yuriferretti/lambda-test

SwiftAWSLambdaRuntime version/commit hash

2bac89639fffd7b1197ab597473a4d10c459a230

Swift & OS version (output of `swift --version && uname -a`)

swift 5.2

pokryfka commented 4 years ago

You could try to see whats happening during those 2s using https://github.com/swift-server/swift-aws-lambda-runtime/pull/162

Note that:

this is a very early PoC but it should just work if you import from my branch (please let me know if it does not):

 .package(url: "https://github.com/pokryfka/swift-aws-lambda-runtime.git", .branch("feature/tracing")),

AWSClient and AsyncHTTPClient are not (yet!) instrumented, you would need to create segments for specific operations like:

    private func handleList(_ request: In, context: Lambda.Context) -> EventLoopFuture<Out> {
       let segment = context.tracer.beginSegment(name: "handleList", baggage: context.baggage)
        return repository.listAllEntities()
            .endSegment(segment)
            .map { items in
                context.tracer.segment(name: "EncodeResponse") { _ in APIGateway.V2.Response(with: items, statusCode: .ok) }
            }
            .catchErrorAndReturn(APIError.notFound, context: context)
    }

fabianfett commented 4 years ago

@yuriferretti Thanks for bringing this up.

Have consistent invocation duration even when lambda execution requires cold start

I'm afraid, we'll not be able to achieve this goal, with AWS' current architecture. Though we should try to reduce the startup times. During the 2s you see (without the 200ms first invocation), AWS does a number of things:

Downloading your zip with your binary
Unzipping your executable and libraries
Then during initialization time: You'll have dynamic linking

Then in the 200ms first invocation a lot of stuff has to be done for the first time, that doesn't need to be redone for any further invocation. For example: If you make a connection to dynamodb, a TLS connection has to be created on first invocation, that will be reused for any further invocation and is therefore much faster. https://github.com/swift-aws/aws-sdk-swift/issues/202#issuecomment-673529471

Further you could use an alternative json encoder and decoder that improves performance: https://github.com/fabianfett/pure-swift-json Gist on how to use it

We will never be able to skip the download, unzipping and dynamic linking times. Though we can reduce the time they take. The most significant actions we can take are probably reducing the binary size and static stdlib linking.

In the end we are bound to a number of things that the stdlib provides and how Swift works nowadays. We should provide better documentation though how to increase lambdas performance.

yuriferretti commented 4 years ago

I'm afraid, we'll not be able to achieve this goal, with AWS' current architecture. Though we should try to reduce the startup times. During the 2s you see (without the 200ms first invocation), AWS does a number of things:

Downloading your zip with your binary

Unzipping your executable and libraries

Then during initialization time: You'll have dynamic linking

Then in the 200ms first invocation a lot of stuff has to be done for the first time, that doesn't need to be redone for any further invocation. For example: If you make a connection to dynamodb, a TLS connection has to be created on first invocation, that will be reused for any further invocation and is therefore much faster.

Thanks for your explanation. After diving deeper in logs as suggested by @pokryfka I realized that the first dynamo call is taking 2s. After this "dynamo warm up", all the other calls will hit single digit response times as expected. So I think it's not a swift lambda problem.

Also is worth noticing that dynamo client response times will increase the longer we take to make other dynamo calls until it reaches that 2s upper bound which is kinda strange.

tomerd commented 4 years ago

Also is worth noticing that dynamo client response times will increase the longer we take to make other dynamo calls until it reaches that 2s upper bound which is kinda strange.

what dynamo client are you using?

yuriferretti commented 4 years ago

@tomerd I'm using AWSDynamoDb from aws-swift-sdk

tomerd commented 4 years ago

cc @adam-fowler

adam-fowler commented 4 years ago

Most of the time spent in aws-sdk-swift is usually in the http client. The latest release v5 alpha6 ensures we are using async-http-client 1.2 or later. Version 1.2 has the connection pool enabled. Can you test with the latest v5 alpha release to see if the same issues exist. This won't resolve cold start issue but warm starts should be considerably faster.

adam-fowler commented 4 years ago

Sorry just noticed this is primarily about cold starts. Updating to latest v5 alpha should still improve things as the FoundationXML dependency has just been removed.

The only aws-sdk-swift code that is run at cold start, but not at warm is credential acquisition. As you are running on Lambda this shouldn't take any time at all as the credentials are extracted from environment variables.

yuriferretti commented 4 years ago

Thanks you all for the information! I will close this for now

swift-server / swift-aws-lambda-runtime