Digdag タスク実践:タスクの正常系&異常系判定について #digdag

2016.11.13

この記事は公開されてから1年以上経過しています。情報が古い可能性がありますので、ご注意ください。

Digdagを理解してみるシリーズ、直近3本は概要や仕組みに関する部分について書いてみましたが4本目となる当エントリは処理の正常終了・異常終了に関する部分について見て行きたいと思います。

正常系&異常系判定

Digdagにおける処理の正常終了・異常終了の判定についての記述というか関連箇所は、下記『コンセプト』内部の1セクションに記載があります。

正常終了・異常終了の判定条件は?

上記ドキュメントに記載があるように、正常に処理が終了していた場合は_checkタスクでその内容を確認するタイミングとして使える、また_errorについてはエラーが発生してた際にこの場所に来るのでエラーメッセージの表示や通知をこのタイミングで行える、という風になっています。ですが、そもそもの実践した処理が何を以って『正常終了』または『異常終了』していたのか?については特に記載が見当たりませんでした。恐らくは、プログラミングにおける『終了ステータス』がその条件となっているのだとは思いますが...まずはここから試してみましょう。

まずは以下2つのシェルスクリプトを用意。シンプルにメッセージを表示し、任意のステータスコードを返して終わる、というものです。

success-job.sh

#!/bin/sh

echo "this job is successful job."
exit 0

failure-job.sh

#!/bin/sh

echo "this job is failure job."
exit 1

実行権限を与え、実行後にステータスコードを確認。それぞれ正常終了(0)、異常終了(1=0以外を異常終了とみなす)で処理が終わっています。

$ chmod +x success-job.sh 
$ chmod +x failure-job.sh
$ ./success-job.sh 
this job is successful job.
$ echo $?
0
$ ./failure-job.sh 
this job is failure job.
$ echo $?
1

上記スクリプトを使ったdigファイルを作成してみます。+success-job:タスクでは処理が正常終了して_checkタスクの文字が出力され、+failure-job:では異常終了となり_errorタスクの文字が出力、結果として最上位レベルにある_errorタスクの文字も出力される、という流れを想定しています。

check-and-error.dig

timezone: Asia/Tokyo

_error:
  sh>: echo "failure!!!"

+success-job:
  sh>: /home/ec2-user/cm-digdag/cm1/success-job.sh

  _check:
    sh>: echo "success!(1)"
  _error:
    sh>: echo "failure!(1)"

+failure-job:
  sh>: /home/ec2-user/cm-digdag/cm1/failure-job.sh

  _check:
    sh>: echo "success!(2)"
  _error:
    sh>: echo "failure!(2)"

処理の実行。何度か試しながらの実践でしたので、同じ処理結果を返すように実行時に--rerunオプションを付けています。実行内容についても上記で想定していた通りの結果となりました。_errorタスクには都合2つ処理が通っています。この辺りはどこで捕まえたかに拠ってメッセージの出し方や処理の分岐等を変えて行く、という対策が可能となるので実践する処理に応じてこの辺り上手い事使って行きたいところですね。ちなみにこの_errorタスク、異常発生時のエラーオブジェクト等は併せて表示等出来るのでしょうか?(単純に異常終了という点だけであれば、表示されているJavaスタックトレース位の情報しか得られない感じなのでしょうか...)SQLをスクリプト内で実行した際にそのエラー内容等も取れれば...とも思ったのですが、難しそうな感じですね。

$ digdag run check-and-error.dig --rerun
2016-11-13 xx:xx:22 +0900: Digdag v0.8.18
2016-11-13 xx:xx:23 +0900 [WARN] (main): Reusing the last session time 2016-11-12T00:00:00+09:00.
2016-11-13 xx:xx:23 +0900 [INFO] (main): Using session /home/ec2-user/cm-digdag/cm1/.digdag/status/20161112T000000+0900.
2016-11-13 xx:xx:24 +0900 [INFO] (main): Starting a new session project id=1 workflow name=check-and-error session_time=2016-11-12T00:00:00+09:00
2016-11-13 xx:xx:25 +0900 [INFO] (0016@+check-and-error+success-job): sh>: /home/ec2-user/cm-digdag/cm1/success-job.sh
this job is successful job.
2016-11-13 xx:xx:26 +0900 [INFO] (0016@+check-and-error+success-job^check): sh>: echo "success!(1)"
success!(1)
2016-11-13 xx:xx:27 +0900 [INFO] (0016@+check-and-error+failure-job): sh>: /home/ec2-user/cm-digdag/cm1/failure-job.sh
this job is failure job.
2016-11-13 xx:xx:27 +0900 [ERROR] (0016@+check-and-error+failure-job): Task failed with unexpected error: Command failed with code 1
java.lang.RuntimeException: Command failed with code 1
	at io.digdag.standards.operator.ShOperatorFactory$ShOperator.runTask(ShOperatorFactory.java:193)
	at io.digdag.util.BaseOperator.run(BaseOperator.java:51)
	at io.digdag.core.agent.OperatorManager.callExecutor(OperatorManager.java:313)
	at io.digdag.cli.Run$OperatorManagerWithSkip.callExecutor(Run.java:678)
	at io.digdag.core.agent.OperatorManager.runWithWorkspace(OperatorManager.java:258)
	at io.digdag.core.agent.OperatorManager.lambda$runWithHeartbeat$2(OperatorManager.java:141)
	at io.digdag.core.agent.LocalWorkspaceManager.withExtractedArchive(LocalWorkspaceManager.java:25)
	at io.digdag.core.agent.OperatorManager.runWithHeartbeat(OperatorManager.java:139)
	at io.digdag.core.agent.OperatorManager.run(OperatorManager.java:123)
	at io.digdag.cli.Run$OperatorManagerWithSkip.run(Run.java:660)
	at io.digdag.core.agent.MultiThreadAgent.lambda$run$0(MultiThreadAgent.java:95)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:745)
2016-11-13 xx:xx:27 +0900 [INFO] (0016@+check-and-error+failure-job^error): sh>: echo "failure!(2)"
failure!(2)
2016-11-13 xx:xx:28 +0900 [INFO] (0016@+check-and-error^failure-alert): type: notify
2016-11-13 xx:xx:28 +0900 [INFO] (0019@+check-and-error^error): sh>: echo "failure!!!"
failure!!!
error: 
  * +check-and-error+failure-job:
    Command failed with code 1

Task state is saved at /home/ec2-user/cm-digdag/cm1/.digdag/status/20161112T000000+0900 directory.
  * Use --session <daily | hourly | "yyyy-MM-dd[ HH:mm:ss]"> to not reuse the last session time.
  * Use --rerun, --start +NAME, or --goal +NAME argument to rerun skipped tasks.

まとめ

という訳で、タスクの正常終了・異常終了判定は『終了ステータスコード』の内容で判断していると見て良さそうです。Digdagで連携するスクリプトについては、処理の結果を最終的にステータスコードで返す設計にしておく事で正確な制御が可能となる事でしょう。初歩的な事ではありますが、ジョブ作成・設計の際にはこの点について留意しながら作成しておいた方が良さそうですね。こちらからは以上です。

参考情報