JP1で管理するジョブの異常終了をClojureを利用しSlack通知する

f:id:vasilyjp:20191206172308j:plain

こんにちは、開発部SREの田島です。私達のチームでは、JP1というツールをワークフローエンジンとして利用しています。JP1のジョブの監視は今まで外部にお願いしていましたが、異常が発生してからすぐ連絡してもらうことができない等の問題がありました。そこでJP1の機能とClojureで作成したスクリプトを組み合わせて異常検知の仕組みを作成しました。本記事ではJP1を使っている背景、並びに異常検知の仕組みをどのように実現したかについてご紹介します。

背景

JP1利用の背景

冒頭でも紹介しましたが私達のチームでは日立製作所が開発・発売しているJP1というツールをワークフローエンジンとして利用しています。多くのチームではDigdagやGCPのCloud Composerが主にワークフローエンジンとして採用されています。

実際私達のチームでもDigdagをフル活用しており、その運用の知見も得られているためワークフローエンジンはDigdagに集約するように動いています。そんな中JP1は約9年前に導入され様々なワークフローがその上で組まれています。そのため簡単にはDigdagに移行できません。

さらにJP1で稼働中のシステムは私達SREチームではなく別のチームが管理しているという状態でした。そこでまずはJP1の運用をSREチームで引き継ぎ、JP1自体の仕組み並びにJP1上で動いているシステムを理解することからはじめました。

JP1ジョブの異常検知

SREチームで運用を引き継ぐため、まずアラート対応に参加しました。そこで早速問題が発生しました。私達のチームでは基本的にSlackでのアラートをフックに当番がそのチャンネルにログを残しつつ対応するというフローをとっています。
しかしJP1のアラートは監視を外部にお願いしており、人間が異常かどうかを判断して電話またはメールで運用担当者に連絡してもらうというフローとなっていました。人間が異常かどうかを判断して連絡してもらうというフローのため異常が発生してから連絡まで最大で30分〜60分かかることがありました。

そこでまずは機械的にJP1の異常を検知し、Slackへ通知することにしました。

JP1について

まずSlack通知をする上でJP1がどのような状態になったら通知するかについて検討する必要があります。しかしJP1を触ったことがまったくなかったので、最初にJP1を使った「Hello World」に挑戦しました。

ジョブネット

まずはじめに、JP1にはジョブネットという概念があります。ジョブネットとは後ほど説明するジョブを集めたものです。GUI上でジョブをどのような順番で実行するかと言ったDagを作成できます。

f:id:vasilyjp:20191205185548p:plain

ジョブ

次にジョブです。JP1では1つ1つの処理がジョブと呼ばれています。ジョブは以下のような画面から設定でき、実際に実行するコマンドやログの出力先などを指定できます。

f:id:vasilyjp:20191205185604p:plain

以上は、hello.batを実行するような設定になっています。batファイルの中身は以下のとおりです。

@echo off
setlocal enabledelayedexpansion
cd %~dp0

echo "hello world!"

ジョブネットグループ

最後にジョブネットグループです、これはジョブネットをまとめてグループ化する概念となっています。よって階層的には「ジョブネットグループ ∋ ジョブネット ∋ ジョブ」となります。

ジョブネットの実行

最後に設定したジョブネットを実行してみます。実行するには「実行を登録」という機能を使って即時実行、またはスケジューリング実行することが可能です。今回は即時実行してみます。実行の結果以下のようなログが指定したファイルに吐き出されました。

hello world!

以上でJP1でのHello Worldが成功しました。

ここからJP1での異常を検知するには、ジョブネットが異常終了した時Slackに通知すればよいことがわかりました。またジョブネットが正常終了した場合にも別のSlackチャンネルに通知できれば便利かなと考えました。

ジョブネットの異常検知

次にジョブネットが失敗した場合にどのようにSlack通知をするかを考える必要があります。ジョブが失敗した場合に外部へ通知するという機能があればいいのですがそのような機能はありませんでした。
そこで、JP1のイベントをきっかけにジョブを実行する機能があるのでそれを利用することにしました。

JP1イベント

JP1はJP1上で起きたイベントをフックにしてジョブを起動する機能があります。イベントの一覧はこちらのリンクにまとめられています。
今回は以下のイベントが利用できそうです。

  • ジョブネット異常終了イベント
  • ジョブネット正常終了イベント
  • ジョブネット開始遅延イベント
  • ジョブネット終了遅延イベント

JP1のイベントをきっかけにジョブを実行する

JP1では通常のジョブとは別にイベントジョブといった特殊なジョブをdagの中に組み込むことができます。以下がそのジョブと設定できる項目です。

f:id:vasilyjp:20191205185644p:plain

紹介したリンクのイベントIDを指定することで、IDに紐づくイベントが発生したタイミングでジョブが実行されます。後続に通常のジョブを設定しておくことで、特定のスクリプトをあるイベントが発生したタイミングで実行が可能となります。ただしこのやり方だとジョブネットが実行中のタイミングでしかイベントを検知できません。そのためイベントを1回だけしか検知ができません。

JP1イベントのたびにジョブネットを実行する

以上の問題を解決するために、イベント受信監視という機能を利用します。イベント受信監視を利用するには「起動条件の設定」を利用します。

f:id:vasilyjp:20191205185654p:plain

「起動条件の設定」を作成すると以下のようなジョブネットの条件フィールドが通常のジョブネットと並列に作成されます。フィールドにイベントジョブを並べてやることで、イベントが発生する毎に並列のジョブネットが実行されます。
条件フィールドの中のイベントはOR条件またはAND条件を指定することが可能です。下記ではOR条件となっているため、指定したイベントの中の1つでも当てはまればジョブが起動します。

f:id:vasilyjp:20191205185706p:plain

実行登録時に、登録方法を「即時実行」起動条件を「設定されていれば使用する」に指定することで監視が開始されます。ジョブネットの状態が監視中となっていればイベントが監視されている状態となっています。

f:id:vasilyjp:20191205185720p:plain

最終的なJP1の監視設定

それでは実際に監視ジョブを作成してみます。まず以下のように監視用のジョブネットを作成し、イベント監視を含むジョブを作成しました。

f:id:vasilyjp:20191205185729p:plain

また、発火するイベントは以下のように設定しました。同じ条件が2つあることについては後ほど説明します。

f:id:vasilyjp:20191205185745p:plain

環境変数の受け渡し

イベントから発火されたジョブではこちらのリンクに記載されているパラメータを利用できます。
しかし、このパラメータはJP1上でのマクロ変数として渡されます。マクロ変数を環境変数に変換することで起動されるスクリプトの中で利用できます。
「最終的なJP1の監視設定」の中の環境変数という項目でマクロ変数を環境変数に変換しています。以下のようなフォーマットで環境変数に指定することで、マクロ変数の値を環境変数に指定できます。

環境変数名=?AJS2マクロ変数?

無限イベント検知問題

JP1では発生したイベントに対して、イベントメッセージを正規表現のマッチングにより絞り込むことができます。絞り込みを利用しないと、イベントからキックされたジョブ自体も監視の対象となるため無限に正常終了の通知がSlackに流れてしまうという問題が発生しました。メッセージを確認すると、必ずジョブネットグループの名前が含まれていることがわかりました。そこで、監視用のジョブネットグループ「MONITORING」を作成し、イベントの文言に「MONITORING」が含まれていないという条件にすればいいと考えました。しかし、否定がJP1の正規表現では使えませんでした。
そこで最終的に、監視したいジョブネットグループの名前が含まれている場合にのみイベント発火を行うことで無限イベント検知を回避しました。また、JP1の正規表現ではOR条件も利用できないためイベント毎にジョブネットの数だけイベントジョブを用意してやる必要があります。 先程の例で2つずつイベントジョブが定義されていたのもこれが理由です。
実際の設定ではイベントジョブのメッセージの部分に正規表現で条件を書きます。以下はメッセージにTEST_WORKが含まれている場合にイベントを発火することを表しています。

f:id:vasilyjp:20191205185812p:plain

Slackへの通知スクリプト

言語選定

イベントから発火されたジョブではこちらのリンクにあるパラメータを環境変数に渡すことで利用できると紹介しました。それらの情報を利用して文言を組み立てSlackに通知します。
上記を実現するためにはスクリプトを作成する必要があります。 P1はWindows上で動作しているため、VBScriptやPowerShell・Windowバッチしかデフォルトでは利用できません。しかし、これらの言語は使い慣れていないかつ、複雑になりそうだったため採用しませんでした。
調べてみると、JP1から呼ばれているジョブはJavaで作成されていることがわかりました。よってJVM言語であれば追加でライブラリをインストールせずに利用できます。そこでJVMで動く言語を利用してスクリプトを作成することにしました。

Clojureの採用

JVMで動作する言語の中で以下の理由からClojureを採用しました。

  • 独立した小さなスクリプトである
  • 普段業務で使っていない言語である
  • 普段使っている言語とパラダイムがぜんぜん違う
  • 筆者がClojure好き

まず今回作成するスクリプトは独立した小さなものなので、新しい技術スタックを試すには絶好のチャンスと考えました。

チームの中には新しい言語に触れるという事に抵抗がある人もいます。そこで、普段業務で使っていない言語を利用することでチームメンバーへの刺激になると考えました。 またClojureはS式や関数型といった特徴を持っています。このような普段使っている言語とはパラダイムがぜんぜん違う言語を使うことでチームメンバーへの新たな発見につながるのではと考えました。 そして何よりも筆者がClojure好きというのも採用に大きく影響しています。

Clojureを採用するデメリットとしては他の人が運用できず負債になるかもしれないというものが挙げられました。しかし、小さなスクリプトなので最悪まるっと別言語で書き換えられる、いつかはDigdagにワークフローエンジンを移行したいという理由から新しい技術スタックに挑戦することを優先しました。

ソースコード

以下がJP1からキックされるbatファイルと、batファイルから実行されるClojureスクリプトになります。 ClojureはLeiningenというツールで管理しています。

notification.bat

@echo off
setlocal enabledelayedexpansion
cd %~dp0

echo "event"
java -jar F:\JP1Notification\jp1-notification\target\uberjar\jp1-notification-0.1.0-SNAPSHOT-standalone.jar

project.clj

(defproject jp1-notification "0.1.0-SNAPSHOT"
  :dependencies [[org.clojure/clojure "1.10.0"]
                 [clj-http "3.10.0"]
                 [org.clojure/data.json "0.2.6"]]
  :main ^:skip-aot jp1-notification.core
  :target-path "target/%s"
  :profiles {:uberjar {:aot :all}}
  :plugins [[lein-shell "0.5.0"]]
  :shell {:env {"EVMSG" "KAVS0262-E ジョブネット(STK-MGR:/TEST_WORK/TAJIMA_TEST_HELLO:@P2944)が正常終了しました"
                "EVID" "4102:0"
                "EVDATE" "2019/10/23"
                "EVTIME" "15:32:29"
                "EVHOST" "hostname"
                "EVIPADDR" "192.168.111.111"}})

core.clj

(ns jp1-notification.core
  (:gen-class)
  (:require [jp1-notification.slack :refer [send-to-slack]]
            [jp1-notification.event :refer [event]]))

(defn -main
  [& args]
  (send-to-slack (event)))

event.clj

(ns jp1-notification.event)

; event: http://itdoc.hitachi.co.jp/manuals/3020/30203S0733/AJSJ0164.HTM
(def error-event-list ["4107:0" "4123:0" "4127:0"])
(def jobnet-group-production ["Application"])

(defn get-jobnet-group [message]
  (second (re-find (re-pattern "STK-MGR:/(.+?)/") message)))

(defn get-event-level [event-id]
  (if (.contains error-event-list event-id)
      :error
      :info))

(defn production? [jobnet-group]
  (.contains jobnet-group-production jobnet-group))

; env: http://itdoc.hitachi.co.jp/manuals/3020/30203K2143/AJSF0177.HTM
(defn event []
  (let [message  (System/getenv "EVMSG")
        event-id (System/getenv "EVID")
        jobnet-group (get-jobnet-group message)]
    {:event-id     event-id
     :message      message
     :date-time    (str (System/getenv "EVDATE") " " (System/getenv "EVTIME"))
     :host         (System/getenv "EVHOST")
     :ip           (System/getenv "EVIPADDR")
     :jobnet-group jobnet-group
     :event-level  (get-event-level event-id)
     :production?  (production? jobnet-group)}))

slack.clj

(ns jp1-notification.slack
  (:require [clj-http.client :as client]
            [clojure.data.json :as json]))

(def slack-url "https://hooks.slack.com/services/xxxxxxxxxxxxxxxxxxxxxxxxxxxxx")

(def production-channel-alert  "#alert_cahannel")
(def production-channel-notice "#notice_channel")
(def test-channel              "#test_channel")

(def info-slack-title  "[INFO] From JP1")
(def error-slack-title "<!channel>\n[ERROR] From JP1")

(defn channel [jobnet-group event-level production?]
  (if-not production?
    test-channel
    (if (= event-level :error)
      production-channel-alert
      production-channel-notice)))

(defn title [event-level]
  (if (= event-level :error)
    error-slack-title
    info-slack-title))

(defn color [event-level]
  (if (= event-level :error)
    "danger"
    "good"))

(defn payload [{:keys [event-id message date-time host ip jobnet-group event-level production?]}]
  {:channel (channel jobnet-group event-level production?)
   :username "JP1 Event"
   :attachments [{:color (color event-level)
                  :title (title event-level)
                  :text (str "```" message "```")
                  :fields [{:title "DateTime"
                            :value date-time
                            :short true}
                            {:title "Host"
                            :value (str host " (" ip ")")
                            :short true}]}]})

(defn send-to-slack
  [eve]
  (client/post slack-url {:form-params {:payload (json/write-str (payload eve))}}))

開発時の環境変数

Clojureのスクリプト開発の際にも今回1つ工夫をしています。開発時でもJP1から渡される環境変数を擬似的にClojureに渡してやる必要があります。そこで、今回は lein-shell というライブラリを使うことでそれを実現しています。
まずproject.cljの pluginslein-shellを追加します。そして以下の行を追加し、実行コマンドの前にlein shellを付与してやることで環境変数がセットされます。

  :shell {:env {"EVMSG" "KAVS0262-E ジョブネット(STK-MGR:/TEST_WORK/TAJIMA_TEST_HELLO:@P2944)が正常終了しました"
                "EVID" "4102:0"
                "EVDATE" "2019/10/23"
                "EVTIME" "15:32:29"
                "EVHOST" "hostname"
                "EVIPADDR" "192.168.111.111"}}

通知結果

実際の通知は以下のようになりました。上が異常終了時、下が正常終了時の通知です。期待通り通知されていることがわかります。

f:id:vasilyjp:20191205185837p:plain

異常検知を自動化してどうなったか

最後に異常検知を自動化しSlack通知にすることで以下のようなメリットが見られたので紹介します。

  • 異常の発生にすぐに気づくことができるようになった
  • 今どのようなアラートが発生していて誰が対応しているのかがわかりやすくなった
  • 過去のアラートが検索できるようになった
  • JP1自体に詳しくなった
  • アラート対応についての現状の見直し・改善のきっかけとなった

まずJP1のジョブの異常が発生してから連絡が来るまでに時間がかかるという問題がありました。この問題は自動検知の仕組み導入により、リアルタイムで異常に気づくことができるようになりました。また、Slackにすべてのアラートが集約されるようになったため、対応のログがすべてSlack残ります。これにより今誰がアラート対応をしているのか、過去にどんなアラートが起こったのかを追うのが簡単になりました。
またこれは副作用ですが、JP1に異常の自動検知の仕組みを入れるためにはJP1自体を詳しく知る必要がありました。これによりシステム改善の第一歩としての現状把握に大きな貢献となりました。
そして何よりも、これをきっかけにチームでのアラート対応についての見直し・改善のきっかけに繋がりました。

今後の展望

アラートの異常検知を自動化することで様々なメリットが得られました。しかしまだまだ問題はあります。今問題となっているのは、夜中の大きなアラートに気づけないというものです。それを解決するための1つとしてPagerDutyの導入を検討してます。
またアラート対応者が誰かに偏っている、知見が誰かに偏っているといった問題があります。これについては、当番制度の見直しなどをチームで日々話し合い改善を行っています。

まとめ

以上で見たように、弊社には改善すべきことがたくさん眠っています。自分の技術スタックとはぜんぜん違う領域に対しても、積極的に挑戦し改善していけるようなエンジニアを募集しています。

tech.zozo.com

あと、Clojureのコードレビューもお待ちしております。

カテゴリー