Step Functions ステートマシンのタイムアウト設定して、タイムアウトで処理がキャンセルされたときの動作を確認してみた
以下のブログポストでStep Functionsの検証をしていました。検証するなかでWait stateによる待機処理がタイムアウトしてステートマシンがキャンセルされ失敗しました。「どうして明示的に待機させたいのにタイムアウトになるの?」となり、その際にTimeoutSecondsの設定を知り、ついでにタイムアウトして処理がキャンセルされた後の挙動を確認したのでまとめておきます。
検証結果
- ステートマシン全体のタイムアウトはTimeoutSecondsで設定できる
- ステートマシン全体とはワークフローのSltartからEndまでのこと
- TimeoutSecondsの設定値より、Wait stateの待機時間が長い設定をしたらタイムアウトで処理がキャンセルされる
- 明示的に待機指示をしてもタイムアウトの設定が優先される
- ステートマシンから呼び出されたLambdaが実行中に、呼び出し元のステートマシンがタイムアウトした場合、実行中のLambdaは最後まで実行される
- 呼び出し元のステートマシンは先にタイムアウトしてキャンセルされているため、Lambdaの実行結果はステートマシンへ返されない
タイムアウト設定ありなしで試してみる
Step Functions ステートマシンのTimeoutSeconds設定をする、しないと、タイムアウトした場合どうなるのかを確認していきます。
タイムアウト設定なし
シンプルなステートマシン(ワークフロー)を作成しました。3分待機してからLambdaを実行するだけです。
{ "Comment": "This is your state machine", "StartAt": "Wait 3min", "States": { "Wait 3min": { "Type": "Wait", "Seconds": 180, "Next": "Lambda Invoke" }, "Lambda Invoke": { "Type": "Task", "Resource": "arn:aws:states:::lambda:invoke", "OutputPath": "$.Payload", "Parameters": { "Payload.$": "$", "FunctionName": "arn:aws:lambda:ap-northeast-1:123456789012:function:stopEC2instance:$LATEST" }, "Retry": [ { "ErrorEquals": [ "Lambda.ServiceException", "Lambda.AWSLambdaException", "Lambda.SdkClientException" ], "IntervalSeconds": 2, "MaxAttempts": 6, "BackoffRate": 2 } ], "End": true } } }
ステートマシンを実行しました。3分待機してからLambdaを実行し正常に完了しました。ステータスは成功です、至って普通です。 次にはじめてステートマシンを作成したときの「よかれと思って設定してダメだったパターン」を紹介します。
タイムアウト設定あり
Step Functions Workflow Studio のおかげで簡単にステートマシンを作成できるようになりました。GUIからぽちぽちワークフローを作成できるので気軽に設定できます。右ペインにTimeoutSecondsというステートマシン全体の実行時間のタイムアウト設定項目が用意されています。
何か設定の誤って終了しなかったら困るから設定しておこうと思い、深く考えずに60秒の設定入れました。
ステートマシンを実行してみるとWait stateがキャンセルされてステートマシンが終了しました。なぜ?となったのですが明示的に指定した秒数を待機させるWait stateよりも、ステートマシン全体のタイムアウト設定(TimeoutSeconds)が優先されたためでした。
TimeoutSecondsを設定するとASLに1行追加されます。
{ "Comment": "This is your state machine", "StartAt": "Wait 3min", "States": { "Wait 3min": { "Type": "Wait", "Seconds": 180, "Next": "Lambda Invoke" }, "Lambda Invoke": { "Type": "Task", "Resource": "arn:aws:states:::lambda:invoke", "OutputPath": "$.Payload", "Parameters": { "Payload.$": "$", "FunctionName": "arn:aws:lambda:ap-northeast-1:123456789012:function:stopEC2instance:$LATEST" }, "Retry": [ { "ErrorEquals": [ "Lambda.ServiceException", "Lambda.AWSLambdaException", "Lambda.SdkClientException" ], "IntervalSeconds": 2, "MaxAttempts": 6, "BackoffRate": 2 } ], "End": true } }, "TimeoutSeconds": 60 }
ステートマシン全体の実行時間に対してのタイムアウトなのか?
TimeoutSecondsを60秒に設定し10秒待ちが6連続してからLambdaを実行するステートマシンを実行してみます。
6個目のWait stateでタイムアウトし、ステートマシンの実行がキャンセルされました。
1個目のWait state実行するまで36msのオーバヘッドがあり、全体の実行時間のタイムアウト60秒設定では6個目のWait stateで待機中にタイムアウトしたことがわかります。
ステートマシンのStartからEndまで通した時間に対してのタイムアウト設定だということが確認できました。
タイムアウト1秒で試してみる
Lambdaを呼び出し中にステートマシンがタイムアウトしたらどうなるのか気になったので試してみます。TimeoutSecondsを1秒に設定し、ステートマシンは実行順序をWate stateとLambda Invokeを入れ替えました。
ステートマシンを実行すると、1個目のLambda呼び出し中にタイムアウトでキャンセルされました。
実行イベント履歴を確認すると、Lambda呼び出しまでは1秒かかっていないのでLambdaの呼び出しには成功しています。
ステートマシンからLambdaは呼び出され、Lambdaはおそらく実行中。その間に呼び出し元のステートマシンはキャンセルされた状況です。Lambdaの処理もキャンセルされたのか疑問です。Lambdaの実行ログをCloudWatch Logsから確認します。
Lambdaのログを確認するとfailed
と文字列があるのですが、このLambdaは実行中のEC2インスタンスを停止するとSucceed
を返し、実行中以外のステータスのインスタンスに停止処理をかけようとするとfailed
を返すように実装しています。
実行結果を確認する限り、Lambdaの戻り値がログに記録されているため、Lambdaは最後まで実行されていることが確認できました。
まとめ
ステートマシンのタイムアウト設定によりステートマシンがキャンセルされても、ステートマシン外で動いているLambdaは実行されていた。ステートマシンはキャンセルされているため、Lambdaの実行結果の戻り値はステートマシンには返されない。ステートマシン実行中に安易な停止は良からぬ結果を引き起こす原因になる。冪等性の確保は大切。
おわりに
Step Functions Workflow Studioでステートマシンを作成すると、タイムアウトの設定項目があったのでついつい設定したら思わぬところでつまづきました。ASLでステートマシンを記述していたらタイムアウト設定を入れたいと思わない限り、設定を書かないのでつまづかなかったかもしれません。Wait stateは頻繁に使われるイメージはないのですが、この記事がどなたかのお役にたてれば幸いです。