Lambda でPython のデコレーターが Cold Start に含まれるのか確認してみた

はじめに

Lambda で Python を動かす際に、Lambda Handler にデコレーターを付けることができます。デコレーターを利用する理由は、ソースコードをクリーンにするために、冗長的な記述を共通化したり、ロジックを分離できる点などがあげられます。

今回の記事では、デコレーターが Python のコールドスタート、ウォームスタート部分にどのような影響が有るか X-Ray で確認していきます。次の 2 点の疑問を解消するための検証です。

• デコレーターで定義した関数に時間が掛かった場合、X-Ray の画面ではコールドスタートに加算されるのか？ウォームスタートの加算されるのか？
• デコレーターを定義したファイルで、グローバルスコープで import を行った場合、コールドスタートに加算されるのか？ウォームスタートの加算されるのか？

といいつつ結論から書くと、次の通りの結果になりました。

• デコレーターで定義した関数に時間が掛かった場合、デコレーター部分の実行時間はウォームスタートに加算される。
• デコレーターを定義したファイルで、グローバルスコープで import を行った場合、コールドスタートに加算される。

冷静に考えてみれば当たり前の結果でした。具体的な検証内容を次に残しておきます。

SAM Project 作成

手元の環境に SAM が入っているので、sam init コマンドで適当にプロジェクトを作成します。SAM 利用方法の詳細は Google などで検索してみてください。

sam init

Python コード準備

SAM で作成されたプロジェクト内で、デコレーター用のファイルを新規作成します。

デコレーター定義ファイルとして、decorator.py の中身を次の内容にします。X-Ray で実行時間を把握するときにわかりやすくするため、以下の工夫を入れています。

• グローバルスコープで、時間のかかる Import を実行
• デコレーターの関数内で、Sleep 3 秒 を入れる

import boto3
import time
import json
import numpy as np
import matplotlib.pyplot as plt
import matplotlib.animation as animation
import scipy.ndimage
import scipy.signal


def decorator_test(func):
    def wrapper(*args, **kwargs):
        print('--start--')
        time.sleep(3)
        func(*args, **kwargs)
        print('--end--')
        return {
            "statusCode": 200,
            "body": json.dumps({
                "message": "hello world",
            }),
        }
    return wrapper

Lambda Handler 定義ファイルとして、app.py の中身を以下の内容に変更します。

• デコレーターの定義
• import に掛かる時間を計測するために、print 分を仕込む

import time

start_time = time.perf_counter()
import json
end_time = time.perf_counter()
elapsed_time = end_time - start_time
print(f"import json: {elapsed_time:.4f}秒")

start_time = end_time
from decorator import decorator_test
end_time = time.perf_counter()
elapsed_time = end_time - start_time
print(f"import decorator: {elapsed_time:.4f}秒")


@decorator_test
def lambda_handler(event, context):
    print('Hello Decorator!')

X-Ray 情報

Lambda 関数で X-Ray のトレーシングを有効にすると、コールドスタートとウォームスタートにどれくらい時間が掛かっているか確認ができます。下の X-Ray の画像にある、Initialization がコールドスタートの一部が計測されています。Invocation はウォームスタート部分が計測されています。

この時、app.pyに仕込んだ print は次のように確認できます。import そのものに、3.8 秒ほど掛かっている様子が見えます。

Python コード変更

デコレーター定義ファイルとして、decorator.py の中身を次の内容にします。あえて時間が掛かるようにしていた import 文をコメントアウトします。

# import boto3
import time
import json
# import numpy as np
# import matplotlib.pyplot as plt
# import matplotlib.animation as animation
# import scipy.ndimage
# import scipy.signal


def decorator_test(func):
    def wrapper(*args, **kwargs):
        print('--start--')
        time.sleep(3)
        func(*args, **kwargs)
        print('--end--')
        return {
            "statusCode": 200,
            "body": json.dumps({
                "message": "hello world",
            }),
        }
    return wrapper

このときの X-Ray の画面です。Initialization の部分が、3.95 秒から、104 ミリ秒に減っています。デコレーター側の Global Scope Import は、コールドスタートに影響を与えていることがわかります。

この時、app.pyに仕込んだ print は次のように確認できます。import そのものの時間が削減されていることがわかります。