ENECHANGE の CTO 室でインフラエンジニアを務めている岩本です。
今回の記事では、Provisioned Concurrency（プロビジョニングされた同時実行数）を設定した AWS Lambda 関数について、実行時間をどのように監視すべきか考えてみます。
Duration メトリクスを監視すればよいのでは、と思われる方もいらっしゃるかもしれませんが、本当にそれでよいのでしょうか。見ていきましょう。
Duration メトリクスの値は Init Duration を含む
Lambda の Provisioned Concurrency は、暖機のための機能です。リクエストが来る前に Lambda インスタンスを初期化することで、コールドスタートを抑制できます。
Provisioned Concurrency を設定した関数を呼び出していると、ときおり Duration メトリクスの値が大きくなることがあります。
しかしながら、Duration メトリクスの値が大きくなった場合でも、呼び出し側への応答時間はさほど増えません。下記の例をご覧ください。
■ Duration メトリクスの値が 2913.52 ms となった呼び出し $ time aws lambda invoke --function-name test-function \ --log-type Tail --cli-binary-format raw-in-base64-out \ --query 'LogResult' --output text response.json | base64 -d START RequestId: 3732b5d9-64da-4ddb-9eb2-15c34e33e555 Version: 3 END RequestId: 3732b5d9-64da-4ddb-9eb2-15c34e33e555 REPORT RequestId: 3732b5d9-64da-4ddb-9eb2-15c34e33e555 Duration: 166.25 ms Billed Duration: 2914 ms Memory Size: 768 MB Max Memory Used: 184 MB Init Duration: 2747.27 ms real 0m1.310s user 0m0.484s sys 0m0.080s ■ Duration メトリクスの値が 41.42 ms となった呼び出し $ time aws lambda invoke --function-name test-function \ --log-type Tail --cli-binary-format raw-in-base64-out \ --query 'LogResult' --output text response.json | base64 -d START RequestId: 273a4dc6-71ce-4c2c-a3ed-8c8204a9bb3f Version: 3 END RequestId: 273a4dc6-71ce-4c2c-a3ed-8c8204a9bb3f REPORT RequestId: 273a4dc6-71ce-4c2c-a3ed-8c8204a9bb3f Duration: 41.42 ms Billed Duration: 42 ms Memory Size: 768 MB Max Memory Used: 185 MB real 0m1.094s user 0m0.507s sys 0m0.044s
| ログの Duration 値 | ログの Init Duration 値 | Duration メトリクスの値 | real |
|---|---|---|---|
| 166.25 ms | 2747.27 ms | 2913.52 ms | 1.310 s |
| 41.42 ms | - | 41.42 ms | 1.094 s |
Duration メトリクスの値が 2747.27 ms となった呼び出しでも、time コマンドの real 値は 1.3 秒に留まっています。
検証結果から推測するに、暖機された Lambda インスタンスに対する初回のリクエストのみ、Init Duration 値を記録して Duration メトリクスの値に含める仕様なのでしょう。
監視すべきは「ログの Duration 値」
上記の仕様は、請求時間の監視には便利です。AWS のドキュメントにも以下の記載があります。
Duration- 関数コードがイベントの処理に費やす時間。呼び出しの請求期間は、最も近いミリ秒に切り上げたDurationの値です。
しかし、実行時間の監視には不便です。先に見たとおり、Provisioned Concurrency を設定した関数では、Init Duration 値が大きかろうが、呼び出し側への応答時間は増えません。
したがって、快適なユーザー体験を維持するには、Duration メトリクスの値ではなく「ログの Duration 値」を監視すべきでしょう。
CloudWatch Logs のメトリクスフィルターで監視する
以下、ログの Duration 値を監視する方法をご紹介します。
まず、CloudWatch Logs のロググループにメトリクスフィルターを作成します。適切なフィルターパターンの例は [type=REPORT, request_id_label, request_id, duration_label, duration, ...] です。
Lambda のログデータでパターンをテストすると、$duration としてログの Duration 値が抽出できることが分かります。
あとは、好みの設定値を入力するだけです。ただしメトリクス値は $duration、Unit は ミリ秒 とします。
メトリクスフィルターができたら、CloudWatch アラームを作成すれば OK です。以上の手順で、ログの Duration 値が監視できます。
まとめ
- Lambda の Duration メトリクスの値は、Init Duration を含みます
- Provisioned Concurrency を設定した関数では、Duration メトリクスの値よりも、ログの Duration 値を監視したほうが、快適なユーザー体験の維持には有用でしょう
- ログの Duration 値を監視するには、CloudWatch Logs のメトリクスフィルターが利用できます
