今回は、AWS Lambda関数の Init フェーズでタイムアウトが発生した場合の動作を検証してみます。

AWS Lambda関数の実行環境のライフサイクルについては、次のドキュメントで説明されています。

docs.aws.amazon.com

このドキュメントにもあるように、Lambda関数は最初に呼び出されると Init フェーズが実行され初期化処理が行われれます。このフェーズでは、Lambda関数のハンドラー関数の外側にあるコードも実行されます。

次に Invoke フェーズでLambda関数のハンドラー関数が実行されます。また、しばらくLambda関数が呼び出されない状態になると、Shutdown フェーズがトリガーされ、Lambda関数の実行環境は停止、削除されます。

Init フェーズは、Lambda関数の実行環境が作成されたときに 1回だけ実行されます。つまり、その実行環境が Shutdown フェーズで削除されない限りは、2回目以降のLambda関数の呼び出しでは Invoke フェーズから実行されます。

また、前述の AWS Lambda関数の実行環境のライフサイクルのドキュメントをみると、次のような記述があります。

Init フェーズは 10 秒に制限されています。3 つのタスクすべてが 10 秒以内に完了しない場合、Lambda は最初の関数呼び出し時に Init フェーズを再試行します。

これはLambda関数を扱う上では、重要な記述だと思います。

Lambda関数には、最大 15分のタイムアウトを設定できます。(2022年 7月現在）

しかし、この最大 15分のタイムアウトというのは Invokeフェース に対する設定であり、Init フェーズに対する設定ではないということになります。

Init フェーズには、固定で 10 秒というタイムアウトがあり、しかも、もしタイムアウトが発生した場合は、Init フェーズ の処理が Invokeフェーズとして再試行されます。

つまり、Lambda関数のハンドラー関数の外側にあるコードは10秒以内に完了しないと、再試行により再度同じコードが実行されることになります。

実際に試してみましょう。今回は、Python 3.9 のLambda関数を使って検証します。

（なお、次から紹介するコードは、動作検証を目的としたものであり本番環境を想定したものではないことはご了承ください。）

Init フェーズでタイムアウトしないケース

次のLambda関数のコードでは、ハンドラー関数の外側で1回だけ Amazon SQS の Queue に日時のデータを含めたメッセージを送信しています。 Lambda関数のタイムアウト、つまり Invoke フェーズのタイム後は 3分に設定しています。

import json
import time
import datetime
import boto3
import logging
logger = logging.getLogger()
logger.setLevel(logging.INFO)

# ハンドラー関数の外
logger.info('--- Init sleep start ---')
sqs = boto3.resource('sqs', region_name='ap-northeast-1') # SQSのリソースの取得
queue = sqs.get_queue_by_name(QueueName='DemoQ')          # Queueの取得
current = datetime.datetime.now()                         # 日時を取得
message = 'current: ' + str(current)                      # Queueに送信するメッセージを用意
queue.send_message(MessageBody=message)                   # Queueにメッセージを送信
time.sleep(5)                                             # 5秒 sleep
logger.info('--- Init sleep end ---')

# ハンドラー関数
def lambda_handler(event, context):
    # TODO implement
    return {
        'statusCode': 200,
        'body': json.dumps('Hello from Lambda!')
    }

このコードは Init フェーズでは 5秒強ほどの時間はかかりますが、10秒のタイムアウトにはひっかからりません。 Amazon SQS の対象のQueue 内のメッセージを確認すると、1つのメッセージしか送信されていませんでした。

メッセージの本文

current: 2022-07-09 04:41:38.200748

また、実行ログをみても、ハンドラー関数の外側のコードは一度しか実行されていないことがわかります。

START RequestId: 2c1d6bb0-5be9-45e3-8905-ba9716b9e539 Version: $LATEST
[INFO]  2022-07-09T05:17:11.153Z        --- Init sleep start ---
[INFO]  2022-07-09T05:17:11.208Z        Found credentials in environment variables.
[INFO]  2022-07-09T05:17:16.301Z        --- Init sleep end ---
END RequestId: 2c1d6bb0-5be9-45e3-8905-ba9716b9e539
REPORT RequestId: 2c1d6bb0-5be9-45e3-8905-ba9716b9e539  Duration: 1.05 ms   Billed Duration: 2 ms   Memory Size: 128 MB Max Memory Used: 66 MB  Init Duration: 5387.97 ms

Init フェーズでタイムアウトするケース

次は、Init フェーズで10秒以上実行されるようにして試してみます。 time.sleep(5) を time.sleep(11) に変更するだけです。

import json
import time
import datetime
import boto3
import logging
logger = logging.getLogger()
logger.setLevel(logging.INFO)

# ハンドラー関数の外
logger.info('--- Init sleep start ---')
sqs = boto3.resource('sqs', region_name='ap-northeast-1') # SQSのリソースの取得
queue = sqs.get_queue_by_name(QueueName='DemoQ')          # Queueの取得
current = datetime.datetime.now()                         # 日時を取得
message = 'current: ' + str(current)                      # Queueに送信するメッセージを用意
queue.send_message(MessageBody=message)                   # Queueにメッセージを送信
time.sleep(11)                                            # 11秒 sleep
logger.info('--- Init sleep end ---')

# ハンドラー関数
def lambda_handler(event, context):
    # TODO implement
    return {
        'statusCode': 200,
        'body': json.dumps('Hello from Lambda!')
    }

このコードを実行すると、正常には修了しますが、Amazon SQS の対象のQueue 内のメッセージを確認すると、2つのメッセージが送信されています。

1つ目のメッセージの本文

current: 2022-07-09 04:55:14.241178

2つ目のメッセージの本文

current: 2022-07-09 04:55:27.429081

2つのメッセージが送信されたということは、ハンドラー関数の外側のコードが 2回実行されたことになります。

また、実行ログをみても、ハンドラー関数の外側のコードが再試行されていることがわかります。

[INFO]   2022-07-09T05:02:04.432Z        --- Init sleep start ---
[INFO]  2022-07-09T05:02:04.489Z        Found credentials in environment variables.
START RequestId: f5bf8835-42ba-4134-92e1-c75544cc3e42 Version: $LATEST
[INFO]  2022-07-09T05:02:16.883Z        --- Init sleep start ---
[INFO]  2022-07-09T05:02:17.183Z        Found credentials in environment variables.
[INFO]  2022-07-09T05:02:28.840Z        --- Init sleep end ---
END RequestId: f5bf8835-42ba-4134-92e1-c75544cc3e42
REPORT RequestId: f5bf8835-42ba-4134-92e1-c75544cc3e42  Duration: 14592.69 ms   Billed Duration: 14593 ms   Memory Size: 128 MB Max Memory Used: 25 MB

ドキュメントの記載通りですね。