第2世代Cloud Functionsのタイムアウト時の挙動について注意したいこと

Cloud Monitoringでログベースのアラートを作成する際は気をつけたほうが良いかも。
2023.12.07

クラスメソッド株式会社データアナリティクス事業本部所属のニューシロです。
今回はGoogle Cloudのサービスである第2世代Cloud Functionsのタイムアウト時の挙動について注意したいことについてまとめました。

前提

タイムアウトとは

以下公式ドキュメントからの引用です。

関数の実行時間はタイムアウト時間によって制限されます。この時間は、関数のデプロイ時に指定できます。デフォルトでは、関数は 1 分(60 秒)後にタイムアウトしますが、この期間は延長できます。

Cloud Functionsの実行時間には制限があります。それがタイムアウト時間です。

トリガーによる最大タイムアウト時間の違い

以下公式ドキュメントからの引用です。

Cloud Functions(第 2 世代)の最大タイムアウト時間は、HTTP 関数の場合は 60 分(3,600 秒)、イベント ドリブン関数の場合は 9 分(540 秒)です。

第2世代Cloud Functionsはデフォルトではタイムアウト時間は1分(60秒)ですが、設定によって伸ばすことができます。HTTPトリガーとイベントトリガーでそれぞれ設定できる最大値は違い、HTTPトリガーは最大60分イベントトリガーは最大9分です。

本題

検証項目

それでは、タイムアウトエラーを実際に出力させ、その結果を元に注意したいことについて確認していきたいと思います。

全ての検証環境について、共通している項目は以下の通りです。

  • タイムアウト時間はデフォルトの1分(60秒)で設定
  • Cloud Functionsは第2世代を選択
  • ランタイムはPython3.11

それでは、以下の3点について検証していきましょう。

  • 1. HTTPトリガーで70秒かかるコードを実行してタイムアウトエラーを発生させる
  • 2. HTTPトリガーで1000秒かかるコードを実行してタイムアウトエラーを発生させる
  • 3. イベントトリガーで1000秒かかるコードを実行してタイムアウトエラーを発生させる

1. HTTPトリガーで70秒かかるコードを実行してタイムアウトエラーを発生させる

第2世代Cloud FunctionsをHTTPトリガーでデプロイします。
コード内でtime.sleep()を用いて意図的にタイムアウトを出力します。
今回はtime.sleep(70)を用いることで、Cloud Functionsの実行時間が70秒程度かかるように設定します。

以下の通り、関数の開始時にはログにStart.と出力し、70秒後ログにEnd.と出力するコードを用います。 Cloud Functionsの実行時間が70秒に対しタイムアウト時間60秒のため、タイムアウトになるはずです。

main.py

import time

import functions_framework


@functions_framework.http
def timeout_test(request):

    print("Start.")
    # 70秒待機する
    time.sleep(70)
    print('End.')

    return 'OK'

requirements.txt

functions-framework==3.*

Cloud Shellでcurlコマンドを入力してCloud Functionsを起動してみます。
60秒後、ログでは以下のようなエラーログが出力されます。

画像が小さいのですが、The request has been terminated because it has reached the maximum request timeout.と記載があります。 これで、想定通りCloud Functionsがタイムアウトになっていることがわかりました。

しかし、想定外のログも出力されています。ログの流れを見てみましょう。

赤枠では60秒後、レスポンス504(タイムアウトエラー)が返ってきており、タイムアウトしていることがわかります。 このログに先ほどの画像にあるThe request has been terminated because it has reached the maximum request timeout.も記載されていました。

しかし、青枠では70秒後に実行されるはずのprint('End.')まで実行されていることが確認できます。
60秒で処理が終了されるならprint('End.')は実行されないはずです。

タイムアウト後も処理が続く場合がある

実はCloud Functionsでは、タイムアウト後も処理が続く場合があるようです。
こちらは私の想定外の挙動でしたが、ドキュメントに記載がありました。以下公式ドキュメントからの引用です。

場合によっては、一時停止した処理がバックグラウンドで続行されたり、後続のリクエストで再開されることがあります。

今回のようにタイムアウト時間後も処理が続行されることもあるようです。
注意したいこととして、タイムアウト後に必ず処理が続行し、完了するわけではありません。次の検証で確認しましょう。

2. HTTPトリガーで1000秒かかるコードを実行してタイムアウトエラーを発生させる

コードを1行だけ変えてみます。time.sleep(70)time.sleep(1000)に変えて1000秒待機させてみます。

main.py

import time

import functions_framework


@functions_framework.http
def timeout_test(request):

    print("Start.")
    # 1000秒待機する
    time.sleep(1000)
    print('End.')

    return 'OK'

実行後30分(1800秒)ほど待って、ログを確認しました。

今回はprint('End.')までは実行できていません。先ほどと違い、処理が途中で終了しています。

タイムアウト後の処理は続かない場合もある

Cloud Functionsのドキュメントにはこのような記載もあります。

一時停止した作業が再開するかどうかはわからないため、この動作には依存しないでください。

タイムアウト後の処理については保証されていないようです。気をつけましょう。

3. イベントトリガーで1000秒かかるコードを実行してタイムアウトエラーを発生させる

今まではHTTPトリガーでしたので、最後にイベントトリガーを用いた検証です。

コードはほぼ同じで、Pub/Subトリガーで実装します。
Cloud Functionsのタイムアウト時間は60秒に設定し、コード内のtime.sleep(1000)でタイムアウトを発生させましょう。

main.py

import time

import functions_framework


@functions_framework.cloud_event
def timeout_test(cloud_event):

    print("Start.")
    # 1000秒待機する
    time.sleep(1000)
    print('End.')

requirements.txt

functions-framework==3.*

Pub/Subトピックに適当なメッセージを送ってCloud Functionsを起動させます。
Cloud Functions起動後30分(1800秒)ほど待ってからログを見てみます。

先ほどのHTTPトリガーでのログと比較してみましょう。
print('End.')まで起動できていないことまでは同じですが、Cloud Functionsがタイムアウト時間60秒に達した際、レスポンスがタイムアウト時の504ではなく200で返ってきています。
レスポンス200はリクエストが正常に終了したことを示すコードですので、エラーログ扱いではありません。
つまり、HTTPトリガーと違いタイムアウトについてのエラーログは出力されていません。

イベントトリガーはタイムアウトに関するエラーログが出力されないことがある

以下公式ドキュメントからの引用です。

関数の再試行がデフォルトで有効になっていない場合、再試行は正常に実行されたと関数により常に報告され、200 OK レスポンス コードがログに記録されます。これは、関数でエラーが発生した場合でも同様です。

どうやらドキュメントによると、関数の再試行を無効にしていたため、このような挙動になったようです。
以下はCloud Functions作成時の画面です。

試しに関数の再試行を有効にすると、HTTPトリガーと同様にタイムアウト時にレスポンス504が返ってきました。
ただ、その場合は関数が再試行されてしまうため、再試行を無効にした際とは異なる挙動をとることには注意しましょう。

警告: 「失敗時に再試行する」を設定すると、関数は、正常に実行されるか、または最大再試行期間(数日間の場合もあります)が経過するまで繰り返し実行されます。そのため、失敗の原因がバグやその他の永続的なエラーの場合、関数が再試行ループに陥る恐れがあります。

イベントトリガーで実装している場合には気をつけなければいけませんね。
特に、再試行を無効にしており、エラーログを拾うようにMonitoringアラートなどを設定している場合、この仕様には注意しましょう。

最後にまとめ

第2世代Cloud Functionsのタイムアウト時の挙動について注意したいことについてまとめます。

  1. タイムアウト後も処理が続く場合がある
  2. タイムアウト後の処理は続かない場合もある
  3. イベントトリガーはタイムアウトに関するエラーログが出力されないことがある

Cloud Functionsの挙動を理解するには、実際に色々と実験してみることが一番早いです。
皆さんも実際に色々触って挙動を確認してみましょう。

引用・参照まとめ