SnapStartでコールドスタートが高速化することを確認してみた

CX事業本部@大阪の岩田です。

Lambdaのコールドスタートを高速化するSnapStartがリリースされましたね。

現状は対応しているランタイムがJava11(Corretto)だけと限定的ですが、非常に期待値の高い新機能ではないでしょうか。このブログでは実際にJava11(Corretto)のLambdaでSnapStartが有効/無効それぞれの設定で簡易な並列アクセス実行後にLambdaのログを分析、SnapStartによってコールドスタートが高速化していることを確認してみます。

Lambdaの準備

まずはLambdaのコードを準備します。sam initでサクっとJava11のテンプレートを作成します。

雛形作成

$ sam init --runtime java11

Which template source would you like to use?
	1 - AWS Quick Start Templates
	2 - Custom Template Location
Choice: 1

Choose an AWS Quick Start application template
	1 - Hello World Example
	2 - Infrastructure event management
	3 - Multi-step workflow
Template: 1

Based on your selections, the only Package type available is Zip.
We will proceed to selecting the Package type as Zip.

Which dependency manager would you like to use?
	1 - gradle
	2 - maven
Dependency manager: 2

Would you like to enable X-Ray tracing on the function(s) in your application?  [y/N]: n

Project name [sam-app]: SnapStart

Cloning from https://github.com/aws/aws-sam-cli-app-templates (process may take a moment)

    -----------------------
    Generating application:
    -----------------------
    Name: SnapStart
    Runtime: java11
    Architectures: x86_64
    Dependency Manager: maven
    Application Template: hello-world
    Output Directory: .

    Next steps can be found in the README file at ./SnapStart/README.md


    Commands you can use next
    =========================
    [*] Create pipeline: cd SnapStart && sam pipeline init --bootstrap
    [*] Validate SAM template: cd SnapStart && sam validate
    [*] Test Function in the Cloud: cd SnapStart && sam sync --stack-name {stack-name} --watch

関数コードの修正

作成された雛形コードを少し修正し、2秒のスリープ処理を追加します

    public APIGatewayProxyResponseEvent handleRequest(final APIGatewayProxyRequestEvent input, final Context context) {
        Map<String, String> headers = new HashMap<>();
        headers.put("Content-Type", "application/json");
        headers.put("X-Custom-Header", "application/json");

        APIGatewayProxyResponseEvent response = new APIGatewayProxyResponseEvent()
                .withHeaders(headers);
        try {
            final String pageContents = this.getPageContents("https://checkip.amazonaws.com");
            String output = String.format("{ \"message\": \"hello world\", \"location\": \"%s\" }", pageContents);

            // 追加
            Thread.sleep(2000);

            return response
                    .withStatusCode(200)
                    .withBody(output);
        } catch (Exception e) {
            return response
                    .withBody("{}")
                    .withStatusCode(500);
        }
    }

これでLambda1回のInvokeに2秒弱の時間が必要になります。レスポンスがすぐに返却できなくなるので、Lambdaの同時実行数とコールドスタートの発生率が簡単に上がってくれるはずです。

SAM テンプレート修正

コードが準備できたのでSAMテンプレートを少し修正します。

API GWの/normalというパスの背後にSnapStartが無効のLambdaを、/snap-startというパスの背後にSnapStartが有効なLambdaをデプロイします。Lambdaの実行速度に影響するパラメータであるメモリは128Mとしました。メモリ割り当てが少ないとCPUパワーが貧弱なためInit処理により多くの時間がかかり、SnapStartとの比較が分かりやすくなりそうなのでこの値にしています。

また、SnapStartを有効化する方のLamdbaはAutoPublishAliasを指定してバージョンを発行する必要があることに注意して下さい。

AWSTemplateFormatVersion: '2010-09-09'
Transform: AWS::Serverless-2016-10-31
Globals:
  Function:
    Timeout: 40
    MemorySize: 1024
Resources:
  SnapStartFunc:
    Type: AWS::Serverless::Function
    Properties:
      CodeUri: HelloWorldFunction
      Handler: helloworld.App::handleRequest
      Runtime: java11
      AutoPublishAlias: SnapStart
      Events:
        HelloWorld:
          Type: Api
          Properties:
            Path: /snap-start
            Method: get
      SnapStart:
        ApplyOn: PublishedVersions
  NormalFunc:
    Type: AWS::Serverless::Function
    Properties:
      CodeUri: HelloWorldFunction
      Handler: helloworld.App::handleRequest
      Runtime: java11
      Events:
        HelloWorld:
          Type: Api
          Properties:
            Path: /normal
            Method: get
Outputs:
  HelloWorldApi:
    Description: "API Gateway endpoint URL for Prod stage for Hello World function"
    Value: !Sub "https://${ServerlessRestApi}.execute-api.${AWS::Region}.amazonaws.com/Prod/hello/"

Build & Deploy

準備できたのでビルドしてデプロイします。

$ sam build
Your template contains a resource with logical ID "ServerlessRestApi", which is a reserved logical ID in AWS SAM. It could result in unexpected behaviors and is not recommended.
Building codeuri: /Users/...略/HelloWorldFunction runtime: java11 metadata: {} architecture: x86_64 functions: SnapStartFunc, NormalFunc
Running JavaMavenWorkflow:CopySource
Running JavaMavenWorkflow:MavenBuild
Running JavaMavenWorkflow:MavenCopyDependency
Running JavaMavenWorkflow:MavenCopyArtifacts

Build Succeeded

Built Artifacts  : .aws-sam/build
Built Template   : .aws-sam/build/template.yaml

Commands you can use next
=========================
[*] Validate SAM template: sam validate
[*] Invoke Function: sam local invoke
[*] Test Function in the Cloud: sam sync --stack-name {{stack-name}} --watch
[*] Deploy: sam deploy --guided

sam deploy --guided

Configuring SAM deploy
======================

	Looking for config file [samconfig.toml] :  Not found

	Setting default arguments for 'sam deploy'
	=========================================
	Stack Name [sam-app]: snap-start-test
	AWS Region [ap-northeast-1]: us-east-1

...略

Successfully created/updated stack - snap-start-test in us-east-1

Lambdaに並列アクセスしてみる

準備できたのでAPI GWに対してabコマンドを実行してみます。今回は以下のコマンドを実行し、100並列で合計100リクエストを発行しています。100台にクライアントが1回づつアクセスするイメージです。

ab -c 100 -n 100 <APIのエンドポイント>

これをSnapStart無効/有効それぞれのエンドポイントに対して実行します。

abコマンド実行完了後にLambdaのログを確認してみましょう。

まずはSnapStart無効のLambda

END RequestId: 4bce3c4e-79ef-4b76-a6f8-e0cdc492fbcc
REPORT RequestId: 4bce3c4e-79ef-4b76-a6f8-e0cdc492fbcc	Duration: 21834.31 ms	Billed Duration: 21835 ms	Memory Size: 128 MB	Max Memory Used: 115 MB	Init Duration: 416.50 ms
...略

Init Durationが出力されており、Initフェーズを伴う通常のコールドスタートが発生していることが分かります。

続いてSnapStart有効のLambdaです

END RequestId: b429035e-237d-4e7e-823e-20b5922c2074
REPORT RequestId: b429035e-237d-4e7e-823e-20b5922c2074	Duration: 22980.33 ms	Billed Duration: 23134 ms	Memory Size: 128 MB	Max Memory Used: 110 MB	Restore Duration: 229.35 ms

こちらはInit DurationではなくRestore Durationが出力されており、スナップショットからLambda実行環境が復元されていることが読み取れます。

CW Logs Insightsで集計してみる

準備ができたのでCW Logs InsightsからSnapStart有効/無効それぞれのLambdaのログを集計してみます。以下のクエリを実行し、InitDuration/RestoreDurationの最小値、最大値、平均値...を集計してみました。

filter @type = "REPORT"
  | parse @log /\d+:\/aws\/lambda\/(?<function>.*)/
  | parse @message /Restore Duration: (?<restoreDuration>.*) ms/
  | stats
count(*) as invocations,
min(coalesce(@initDuration,0)+coalesce(restoreDuration,0)) as min,
max(coalesce(@initDuration,0)+coalesce(restoreDuration,0)) as max,
avg(coalesce(@initDuration,0)+coalesce(restoreDuration,0)) as avg,
pct(coalesce(@initDuration,0)+coalesce(restoreDuration,0), 50) as p50,
pct(coalesce(@initDuration,0)+coalesce(restoreDuration,0), 90) as p90,
pct(coalesce(@initDuration,0)+coalesce(restoreDuration,0), 99) as p99
group by function, (ispresent(@initDuration) or ispresent(restoreDuration)) as coldstart
  | sort by coldstart desc

結果は以下のようになりました

いずれの指標についてもInitDurationよりもRestoreDurationの方が優秀な結果が出ていることが分かります。

まとめ

SnapStartによってコールドスタートが高速化していることを実際に確認してみました。Java11(Corretto)以外の他のランタイムでもSnapStartが使えるようになるのが待ち遠しいですね！