先日、cronで回しているとあるバッチジョブがたまに妙に時間がかかっているようだったので、その所要時間をZabbixで監視してみました。

time(1)

コマンドの所要時間を計測するにはtime(1)コマンドが便利です。bash組み込みのtimeも便利ですが、time(1)はさらにいろんなオプションが使えます。

$ /usr/bin/time -o result.time -f 'time:%e exit:%x' --quiet -- COMMAND

-oオプションは計測結果を指定ファイルに出力します。
-fオプションは結果の出力フォーマットを指定します。%eはいわゆるreal時間(単位は秒)、%xはCOMMANDのexit statusです。他にもいろいろな計測ができます。
デフォルトではCOMMANDのexit statusが非ゼロの場合にエラーメッセージを出力します。それを抑制するには--quietを指定します。

time(1)コマンドを使ってファイルに所要時間を出力しておけば、あとは適当な方法でそれをZabbixへアップロードすればOKです(後述)。

ただし、time(1)コマンドは実行開始時点で出力先ファイルを書き込みオープンするため、バッチジョブの実行中は出力先ファイルの中身が空になってしまいます。なので出力先ファイルは一時ファイルとし、コマンド実行完了後にmvするとよいと思います。

また、やや余談ですが時間のかかるバッチジョブでもう一つ大事なのが多重起動の防止です。これを実現するにはflock(1)が便利です。

ということで、以上をまとめたrun_job.shを書いておきます。

run_job.sh

# !/bin/bash

basename="$1"
shift
(
  flock -n 9 || { echo "$basename is already running." >&2 ; exit 1 ; }
  /usr/bin/time -o "/tmp/$basename.time.tmp" -f 'time:%e exit:%x' --quiet -- "$@"
  mv -f "/tmp/$basename.time.tmp" "/tmp/$basename.time"
) 9> "/tmp/$basename.lock"

crontabでは以下のように使います。

10 23 * * * root  run_job.sh JOB_NAME COMMAND 2>&1 | logger

Zabbixのアイテムの設定

次に、計測したジョブの所要時間をZabbixにアップロードします。これはzabbix-agentでポーリングする方法と、zabbix-senderでプッシュする方法のどちらでもできます。

zabbix-agentを使う場合はvfs.file.regexpキーで所要時間ファイルの中身を切り出せばいいでしょう。

ただ、残念ながら筆者の使っているZabbixはバージョンが古すぎてregexpキーが使えなかったので、system.runで以下のように設定しました。

ジョブ所要時間
- Key: system.run[perl -ne '/time:(\S+)/ and print $1' /tmp/result.time]
- Type: Numeric(float)
- Units: s
ジョブ実行結果

もちろん、system.runを使わずにUserParameterを使うこともできます。(そっちの方がよかったかな・・・)

ついでにジョブの実行完了時刻も取得します。これは所要時間ファイルのタイムスタンプから分かります。

ジョブ実行完了時刻
- Key: vfs.file.time[/tmp/result.time]
- Type: Numeric(unsigned)
- Units: unixtime

Zabbixのトリガーの設定

作成したアイテムに対してトリガーを設定し、異常時にアラートが上がるようにします。

所要時間が1時間を超えた場合にアラート

  {host:system.run[perl -ne '/time:(\S+)/ and print $1' /tmp/result.time].last(0)}>3600}

所要時間の変動が激しくてトリガーが暴れるようならmax関数などを使ってフィルタリングするとよいです。

実行結果が非ゼロの場合にアラート

  {host:system.run[perl -ne '/exit:(\S+)/ and print $1' /tmp/result.time].last(0)}#0

実行完了時刻が3日以上古い(あるいは新しい)場合にアラート
```
  {host:vfs.file.time[/tmp/result.time].fuzzytime(3d)}=0
```