digdagを利用していて時おり困ることの一つに、何らかのジョブ*1がハングなどで長時間実行されてしてしまい、ジョブのキューが溜まり後続のジョブが実行されない問題があります。その対策として sla ディレクティブを利用した、という内容です。
digdagのsla ディレクティブとは
slaディレクティブを使用することで、digdagのジョブが特定の時間を超えた、または経過した場合に特定の処理を実行したり、エラーを発生させることができます。*2
ドキュメントのslaについての記載
には Setting an alert if a workflow doesn’t finish within expected time とあります。
slaディレクティブのオプション
sla ディレクティブで利用可能なオプションは、2019/10/12現在で以下の通りです。*3
- sla: parameter supports
duration: HH:MM:SSsyntax in addition totime: HH:MM:SSsyntax. - sla: parameter supports
fail: BOOLEANandalert: BOOLEANoptions. Setting fail: true makes the workflow failed. Setting alert: true sends an notification using above notification mechanism.
経過時間を指定する場合は duration 、終了時間を指定する場合は time を使い、終了時にfailさせるのか、現状隠しパラメタ的なアラート処理を実行するのかを指定できます。噛み砕くと以下のようになります。
- duration か time のどちらかを選択する
- 経過時間を指定したい場合は duration
- 終了時間を指定したい場合は time
- 超過した場合、終了時にfailさせて、
_error:の処理も実行したい場合はfail: true - 超過した場合、終了時にnotificateion.typeによる通知を実行する場合は
alert: true*4
余談ですが time: と duration を両方指定した場合は以下のエラーとなります、親切ですね。
error: SLA must be specified using either the 'time' or 'duration' option (config)
slaディレクティブのサンプル
slaディレクティブのサンプルを記載します。
durationによる経過時間の超過を検知するサンプル
以下の条件を満たすサンプルコードです。
- 6秒を超過した場合 (duration: 00:00:06)
- エラー終了とし(fail: true)
- "#### Long Running !!!###" と表示する (+alert:から続くジョブ)
timezone: Asia/Tokyo schedule: daily>: 22:00:00 sla: duration: 00:00:06 fail: true +alert: sh>: echo "#### Long Running !!!###" _export: workflow_name: "test-sla" +start: +sub1: sh>: echo "job1" ;sleep 5 +sub2: sh>: echo "job2" ;sleep 5 +job_end: echo>: Success _error: echo>: Error!!!!!
以下のようなメッセージが出力されます
019-10-15 00:51:45 +0900 [INFO] (main): Starting a new session project id=1 workflow name=test-sla session_time=2019-10-13T01:00:00+09:00
2019-10-15 00:51:46 +0900 [INFO] (0017@[0:default]+test-sla+start+sub1): sh>: echo "job1" ;sleep 5
job1
2019-10-15 00:51:51 +0900 [INFO] (0017@[0:default]+test-sla+start+sub2): sh>: echo "job2" ;sleep 5
job2
2019-10-15 00:51:52 +0900 [INFO] (0019@[0:default]+test-sla^sla^alert): type: notify
2019-10-15 00:51:52 +0900 [INFO] (0020@[0:default]+test-sla^sla^fail): type: fail
2019-10-15 00:51:52 +0900 [ERROR] (0020@[0:default]+test-sla^sla^fail): Task +test-sla^sla^fail failed.
SLA violation
2019-10-15 00:51:52 +0900 [INFO] (0021@[0:default]+test-sla^sla+alert): sh>: echo "#### Long Running !!!###"
#### Long Running !!!###
2019-10-15 00:51:56 +0900 [INFO] (0017@[0:default]+test-sla+job_end): echo>: Success
Success
2019-10-15 00:51:57 +0900 [INFO] (0021@[0:default]+test-sla^error): echo>: Error!!!!!
Error!!!!!
2019-10-15 00:51:57 +0900 [INFO] (0017@[0:default]+test-sla^failure-alert): type: notify
error:
* +test-sla^sla^fail:
SLA violation
timeによる終了時刻の超過を検知するサンプル
以下の条件を満たすサンプルコードです。
- 01:42:00を超過した場合 (time: 01:42:00)
- エラー終了とする(fail: true)
timezone: Asia/Tokyo schedule: daily>: 01:41:37 sla: time: 01:42:00 fail: true _export: workflow_name: "test-sla" +start: +sub1: sh>: echo "job1" ;sleep 5 +sub2: sh>: echo "job2" ;sleep 50 +job_end: echo>: Success _error: echo>: Error!!!!!
以下のようなメッセージが出力されます
2019-10-13 01:41:37 +0900 [INFO] (main): Starting a new session project id=1 workflow name=test-sla session_time=2019-10-13T01:00:00+09:00
2019-10-13 01:41:38 +0900 [INFO] (0017@[0:default]+test-sla+start+sub1): sh>: echo "job1" ;sleep 5
job1
2019-10-13 01:41:43 +0900 [INFO] (0017@[0:default]+test-sla+start+sub2): sh>: echo "job2" ;sleep 50
job2
2019-10-13 01:42:04 +0900 [INFO] (0019@[0:default]+test-sla^sla^fail): type: fail
2019-10-13 01:42:04 +0900 [ERROR] (0019@[0:default]+test-sla^sla^fail): Task +test-sla^sla^fail failed.
SLA violation
2019-10-13 01:42:33 +0900 [INFO] (0017@[0:default]+test-sla+job_end): echo>: Success
Success
2019-10-13 01:42:34 +0900 [INFO] (0019@[0:default]+test-sla^error): echo>: Error!!!!!
Error!!!!!
2019-10-13 01:42:34 +0900 [INFO] (0017@[0:default]+test-sla^failure-alert): type: notify
error:
* +test-sla^sla^fail:
SLA violation
alert: true によるログ記録を行うサンプル
fail: true と違い、現在のドキュメントからは使い方がわからない alert: true のサンプルです。
GitHubのissueに古橋さんが例を記載してくれています。以下は単純なshellを利用していますが、mailやhttpも利用とのことです。
どうにもExperimental感が強いので、ローカルで試したのみで本番利用するつもりは今のところ...
- config
notification.type = shell notification.shell.command = echo "workflow error" >> /tmp/hoge
- code
timezone: Asia/Tokyo schedule: daily>: 22:00:00 sla: duration: 00:00:06 alert: true _export: workflow_name: "test-sla" +start: +sub1: sh>: echo "job1" ;sleep 5 +sub2: sh>: echo "job2" ;sleep 5 +job_end: echo>: Success _error: echo>: Error!!!!!
以下のようなメッセージが出力されます
2019-10-13 02:07:05 +0900 [INFO] (main): Starting a new session project id=1 workflow name=test-sla session_time=2019-10-13T01:00:00+09:00 2019-10-13 02:07:06 +0900 [INFO] (0017@[0:default]+test-sla+start+sub1): sh>: echo "job1" ;sleep 5 job1 2019-10-13 02:07:11 +0900 [INFO] (0017@[0:default]+test-sla+start+sub2): sh>: echo "job2" ;sleep 5 2019-10-13 02:07:11 +0900 [INFO] (0019@[0:default]+test-sla^sla^alert): type: notify job2 2019-10-13 02:07:16 +0900 [INFO] (0017@[0:default]+test-sla+job_end): echo>: Success Success
configで指定した notification.type = shell の処理も動作していました。
# cat /tmp/hoge workflow error
slaディレクティブを使用し、一定時間以上が経過したジョブを自動キャンセルする
そして個人的にはこれが一番やりたかったことですが、slaディレクティブを使うことで、長時間実行されてしまうジョブをキャンセルすることが可能です。
以下のコードではjob2の実行中に digdag kill によるキャンセルが発生し、job3は実行されません。
**digdagはserverモードでの利用を前提としています
timezone: Asia/Tokyo schedule: daily>: 22:00:00 sla: duration: 00:00:06 +kill: +alert: sh>: bin/nothice.sh +kill: sh>: digdag kill ${attempt_id} _export: workflow_name: "test-sla" +start: +sub1: sh>: echo "job1" ;sleep 5 +sub2: sh>: echo "job2" ;sleep 5 +sub3: sh>: echo "job3" ;sleep 5 +job_end: echo>: Success _error: echo>: Error!!!!!
ポイントはslaディレクティブのジョブで digdag kill ${attempt_id} を行なっている点です。attempt_idは0.9.32から利用できるようになりましたが、slaディレクティブと組み合わせることで「slaを守れない自分をキャンセル(digdag kill)する」ことができます。なおキャンセルをするため faile: true を指定する意味はありません。
加えて、digdag killする前に +alert で行なっているようにSlackやメールなどの通知を行なっておくことをお勧めします。理由としてキャンセルを行う場合 _error 処理は実行されず、_error 処理による検知に頼っている場合キャンセル発生を見逃してしまう可能性があるためです。
digdag kill で止まるケース
以下のようなケースはdigdag killが有効で、job2までは実行されますが、job3、job4は実行されません。
timezone: Asia/Tokyo schedule: daily>: 22:00:00 sla: duration: 00:00:06 +kill: +alert: sh>: bin/nothice.sh +kill: sh>: digdag kill ${attempt_id} _export: workflow_name: "test-sla" +start: +sub1: sh>: echo "job1" ;sleep 5 +sub2: sh>: echo "job2" ;sleep 5 +sub3: sh>: echo "job3" ;sleep 5 +sub4: sh>: echo "job4" ;sleep 5 +job_end: echo>: Success _error: echo>: Error!!!!!
digdag kill で止まらないケース
以下のようなケースはdigdag killは行われますが、job2が途中で中断されることはなく、digdagはjob2の終了を待ってしまいます。私の期待としては6秒を超えた時点でsh>実行中のプロセスに対してもkillシグナルを発行してもらいたいのですが、現状は待ち続けるようでした。このように特定の長時間化した処理をどうしても止めたい場合はdigdagの外部(OS上など)から強制停止を行う必要がありそうです。
timezone: Asia/Tokyo schedule: daily>: 22:00:00 sla: duration: 00:00:06 +kill: +alert: sh>: bin/nothice.sh +kill: sh>: digdag kill ${attempt_id} ; date _export: workflow_name: "test-sla" +start: +sub1: sh>: echo "job1" ;sleep 5 +sub2: sh>: echo "job2" ;sleep 100 +job_end: echo>: Success _error: echo>: Error!!!!!
まとめ
以上、slaディレクティブを使った想定外に長時間実行してしまうジョブへの対策、でした。 「キューが溜まってdigdag serverで管理するジョブがある時点から全停止してる？！」なんて悲劇が起きる前に仕込んでおきたいですね。
参考になったサイト
- Digdagのスケジュール設定 | 酒と涙とRubyとRailsと
- digdagの調べ物をするとちょいちょい辿り着くブログです、いつもありがとうございます
- Qiita: digdagのsla/fail/error/waitについてのメモ
digdag killによるキャンセル時に_error:処理が動かない点について言及されていて気づきを得ました、感謝
- Qiita: ワークフローエンジンdigdagで困ったこと
- slaをTimeoutと呼ばれている点に共感したり、killでキャンセルされている点がさすがでした、私のこの記事いらなかったというくらい内容が被っており、失礼しました感あります
- Qiita: Digdagのexport時のエラーはerrorのタスクが実行されない
- slaディレクティブのalertオプションを調べていて、この記事で紹介されているissueをみてなるほどこれは！となりました、ドキュメントに無いものはなかなか知らないですね...
- GithubのIssue#669
- 現状ドキュメントには無い notification の設定方法を古橋さんが記載されています、ドキュメント化しないのは何故なんでしょう
*1:digdagではWorkflowと呼ぶけどここでは一般用語として"ジョブ"とします
*2:SLA(Service Level Agreement)を定義する意味からのオプション名でしょうが、Timeoutとかの方が個人的には分かりやすいです
*3:このオプションの説明がRelease Noteにしかなくて分かりづらいので、ドキュメント修正のPRを出したりしました
*4:そもそもこのnotification.typeが現状ドキュメントにないのはなぜなんだろ
