はじめに
現在、業務にて毎日実行しているバッチの実行時間を監視するため、バッチログをExcelでグラフに成形しています。この手順をオープンソースプロダクトを利用して自動化できないか試みました。
結果として、日々のバッチログを業務利用に耐えうるレベルで自動整形する環境を得ることができました。
実際に触れてみた感想は次の通りです。
- ログの出力からKibanaのグラフ表示までを自動化できた。手動で定期的にグラフを作成するのに比べ、リアルタイムで自動生成できると手間の減少・危険な兆候に早く気づけるというメリットは大きい。
- グラフ自体の使い勝手はExcelの方が良い。シンプルな使い方で良ければKibanaの自動生成に利がある。
本記事では自動グラフ化構成の簡単な紹介と、各グラフをどのような目的で・どう作ったかの説明をしたいと思います。
Kibanaへのデータ登録まで
バッチが出力したログが自動的にKibanaに登録されるようになるまでの道筋を簡単に説明します。
※具体的な構築手順については既に多数の有用な記事が投稿されているためここでは触れません。
構成
プロダクト名称(インストールした順) | 説明 |
---|---|
CentOS Linux release 7.5 | OS |
Java 1.8.0_131 | Elasticsearchの動作に必要 |
Kibana 5.4.0 | ログデータ可視化する画面 |
Elasticsearch 5.4.3 | ログデータを格納するDB |
Logstash 5.4.3 | CSV形式のログデータをElasticsearchに登録する為に使用 |
構成図(Kibana導入前)
構成図(Kibana導入後)
データ投入設定
バッチ実行ログの仕様
すべてのバッチが同一のファイルに対して、1回実行するごとに1行追記するようにしています。
形式は次の通り共通としています。
項目名 | 説明 |
---|---|
実行日付 |
YYYY-MM-DD 形式 |
開始時刻 |
HH:mm:SS 形式 |
終了時刻 |
HH:mm:SS 形式 |
実行時間(秒) | 整数。開始・終了時刻から算出できますが、集計するツールによっては登録時に計算が出来なかったり、グラフ表示の度に計算したりすることもあるのでこの時点で計算しておきます |
バッチ名 | 文字列。 |
バッチカテゴリ名 | 集計用項目として記録。 ・INPUT…他システムからの取込 ・PROCESS…内部処理 ・OUTPUT…他システムへの出力 ・SEND_MAIL…メール送信処理 |
出力例
2018-07-17,05:37:48,05:39:19,91,INPUT_A08,INPUT
2018-07-17,05:39:21,05:44:43,322,PROCESS_E,PROCESS
2018-07-17,05:44:33,05:45:40,67,OUTPUT_A10_2,OUTPUT
Elasticsearchの設定
Elasticsearchに格納されるINDEX形式を定義します。
INDEX名は「joblog」とします。
ターミナル上で実行します。
# curl -XDELETE 'http://localhost:9200/joblog'
# curl -H 'Content-Type: application/json' -XPUT http://localhost:9200/joblog -d '
{
"mappings" : {
"_default_" : {
"properties" : {
"start_date" : {"type": "date", "format": "yyyy-MM-dd"},
"start_time" : {"type": "date", "format": "HH:mm:ss"},
"end_time" : {"type": "date", "format": "HH:mm:ss"},
"processing_time" : { "type" : "integer" },
"job_name" : {"type": "string", "index" : "not_analyzed" },
"job_category" : {"type": "string", "index" : "not_analyzed" }
}
}
}
}
';
Logstashの設定
Elasticsearchは標準でCSV形式を取り込むことが出来ないため、Logstash経由で取り込みます。
入力元のファイルパス、CSVの解釈方法、Elasticsearch側へ登録するINDEXを指定します。
テキストファイルを編集します。
# vi /etc/logstash/conf.d/joblog.conf
input {
file {
path => "/root/kibana_sampledata/joblog-dummy.csv"
start_position => "beginning"
}
}
filter {
csv {
columns => ["start_date", "start_time", "end_time", "processing_time", "job_name", "job_category"]
convert => {
"processing_time" => "integer"
}
}
grok {
remove_tag => ["_geoip_lookup_failure"]
}
date {
match => ["start_date", "YYYY-MM-DD"]
}
date {
match => ["start_time", "HH:mm:ss"]
}
date {
match => ["end_time", "HH:mm:ss"]
}
geoip {
source => ["clientip"]
}
}
output {
elasticsearch {
hosts => "localhost:9200"
index => "joblog"
document_id => "%{job_name}_%{start_date}_%{start_time}"
}
stdout {}
}
この設定により、業務サーバ側でCSV形式のログが追記される度に自動でElasticsearchにデータが蓄積されます。
Kibanaの設定
INDEX「joblog」を定義し、Elasticsearchに格納されているデータを読み込みます。
Kibanaの画面上で操作します。
- Configure an index pattern画面にて次のように入力
- Index name or pattern :joblog
- Index contains time-based events:チェック無し
- Createボタンを押下
今回は実行日付と時刻が別の項目になっているため、タイムスタンプ系の定義は使いませんでした。
ここまでの手順でKibanaにデータが自動で蓄積されるようになりました。
Kibanaでの目的別グラフ設定・使用例
Kibana上からデータが見えるようになったデータをグラフ化します。ここからはグラフごとの目的・設定方法・実際に使った感想を紹介していきます。
後続システム向けバッチの遅延監視(※Include条件の活用)
若干細かいグラフですが、最もやりたいことなので最初に書きます。
毎朝5:30からバッチを順次実行し、6:30(3600秒後)までに完了させる必要があります。
バッチの内訳はINPUT(他システムからの取込)、PROCESS(内部処理)、OUTPUT(他システムへの出力)の順です。
そこで、次の内容でグラフを作成することにしました。
- すべてのバッチのうち、朝5:30から6:30までに実行するバッチが対象(バッチ名で指定する)
- バッチの実行時間の合計が3600秒を超えたら遅延とみなす
KibanaでVisualize新規画面を選択し、「Area」を選択します。
グラフの設定は次の通りです。
- Data
- Y-Axis(グラフのY軸)
- Aggregation:Sum(合計)
- Field:processing_time(バッチ実行時間)
- X-Axis(グラフのX軸)
- Aggregation:Date Histogram(時間軸)
- Field:start_date(バッチ実行日付)
- interval:Daily(日単位)
- Split Series(グラフの系列)
- Sub Aggregation:Terms(種別ごと)
- Field:job_name(バッチ名)
- Order:Ascending 50(すべて表示したいので総数より大きい値)
-
(Advanced Options) Include
:INPUT_A(02|04|06|08|14|26)|PROCESS_(E)|OUTPUT_(A01|A07|A08|A10_2|A11_2|A16|B01|B02|B08|B09|B10|B11|B12_2|Z01_2|Z02_2)(※)
- Y-Axis(グラフのY軸)
- Metrics & Axes
- Metrics
- Chart Type:area
- Mode:stacked(積み上げグラフ)
- Value Axis:LeftAxis-1
- Line Mode:stepped(てっぺんを平らに)
- Y-Axes
- Show:チェックあり
- Position:left
- Mode:normal
- Scale Type:linear
- (Advanced Options) Max:3600(グラフの一番上をボーダーラインとする)
- X-Axis
- Show:チェックあり
- Position:bottom
- Metrics
- Panel Settings
- Settings
- Legend Position:right
- Grid
- X-Axis Lines:チェックあり
- Y-Axis Lines:LeftAxis-1
- Settings
※Data/Split Series/Include欄にて集計対象となるバッチ名を指定していますが、この欄に文字数制限があるため、正規表現でなるべく文字数を減らしておくのが良さそうです。
ここまで設定すると、このグラフが描画されます。(※先と同じ画面です)
ボーダーラインとしてY軸の3600秒に赤線を引きたかったのですが、プラグインを入れ、かつダミーデータを入力しないと出来ないようです。この点が冒頭で「グラフ自体の使い勝手はExcelの方が良い」と書いた理由です。このグラフではY軸の一番上を3600とすることで目的を果たすことにしました。
本来の目的であったグラフ自体に対する所見も書いておきます。
まず前提として一番下の緑色、INPUT_A02は月末にだけ処理があります。3月と9月は繁忙期で月の後半の間ずっと処理があります。
INPUT_A02の処理が無い時は総実行時間が下がるはずが、7月から全体的に底上げされています。これは一番上の緑色であるPROCESS_Eの処理対象データが増えたためです。9月末の繁忙期に合計実行時間が3200秒付近まで上がりました。このまま次の繁忙期を迎えるのは若干危険と判断し、PROCESS_Eを2つのバッチに分割し、この時間帯でなくても処理できる内容を別の時間帯に移すことにしました。
朝バッチ遅延監視と同じ方式です。
毎晩20:00からバッチを順次実行し、22:00(7200秒後)までに完了させる必要があります。
バッチの内訳はINPUT(他システムからの取込)、PROCESS(内部処理)、OUTPUT(他システムへの出力)に加えてSEND_MAIL(メール送信処理)があります。
作成するグラフは次の通りです。
- すべてのバッチのうち、朝20:00から22:00までに実行するバッチが対象(バッチ名で指定する)
- バッチの実行時間の合計が7200秒を超えたら遅延とみなす
KibanaでVisualize新規画面を選択し、「Area」を選択します。
グラフの設定は次の通りです。
- Data
- Y-Axis(グラフのY軸)
- Aggregation:Sum(合計)
- Field:processing_time(バッチ実行時間)
- X-Axis(グラフのX軸)
- Aggregation:Date Histogram(時間軸)
- Field:start_date(バッチ実行日付)
- interval:Daily(日単位)
- Split Series(グラフの系列)
- Sub Aggregation:Terms(種別ごと)
- Field:job_name(バッチ名)
- Order:Ascending 50(すべて表示したいので総数より大きい値)
- (Advanced Options) Include
:PROCESS_(D|C|O1|O2|J|P|T|Z0006|Z0007)|OUTPUT_(A01|A06|A07|A08|A10|A11|B01|B02|B08|B09|B10|B11|B12|Z01|Z02)|SEND_MAIL(04|06|08|09|10|11|13|15|16)
- Y-Axis(グラフのY軸)
- Metrics & Axes
- Metrics
- Chart Type:area
- Mode:stacked(積み上げグラフ)
- Value Axis:LeftAxis-1
- Line Mode:stepped(てっぺんを平らに)
- Y-Axes
- Show:チェックあり
- Position:left
- Mode:normal
- Scale Type:linear
- (Advanced Options) Max:7200(グラフの一番上をボーダーラインとする)
- X-Axis
- Show:チェックあり
- Position:bottom
- Metrics
- Panel Settings
- Settings
- Legend Position:right
- Grid
- X-Axis Lines:チェックあり
- Y-Axis Lines:LeftAxis-1
- Settings
ここまで設定すると、このグラフが描画されます。(※先と同じ画面です)
ボーダーラインとしてこのグラフではY軸の一番上を7200としています。
グラフに対する所見としてはほぼ安全域と見て良いと思います。
こちらには月末の繁忙期に増える処理がありません。ですが、朝バッチと同様に7月以降に処理の対象となるデータが増えているため、処理時間が急増したり、右肩上がりが長く続かないかという観点での注意は必要です。
バッチ別実行時間ランキング
システム全体で処理時間が長いバッチのランキングベスト(ワースト)5です。
実行時間の累計に応じて上位5つまでが自動で入れ替わります。
KibanaでVisualize新規画面を選択し、「Vertical Bar」を選択します。
グラフの設定は次の通りです。
- Data
- Y-Axis(グラフのY軸)
- Aggregation:Sum(合計)
- Field:processing_time(バッチ実行時間)
- Custom Label:総実行時間(秒)
- X-Axis(グラフのX軸)
- Aggregation:Terms(種別)
- Field:job_name(バッチ名)
- Order By:metric:総実行時間(秒)
- Order/Size:Decentding/5(上位5件)
- Y-Axis(グラフのY軸)
- Metrics & Axes
- Metrics
- Chart Type:bar
- Mode:normal
- Value Axis:LeftAxis-1
- Y-Axes
- Show:チェックあり
- Position:left
- Mode:normal
- Scale Type:linear
- X-Axis
- Show:チェックあり
- Position:bottom
- Metrics
- Panel Settings
- Settings
- Legend Position:right
- Grid
- X-Axis Lines:チェックなし
- Y-Axis Lines:LeftAxis-1
- Settings
ここまで設定すると、このグラフが描画されます。(※先と同じ画面です)
単純なグラフですが、担当者が認識している順位と違う結果になったり、入れ替わったりした際に気づくことができそうです。
バッチカテゴリに分けた上での総実行時間比率と、カテゴリ内ランキングです。
赤枠内がバッチカテゴリ(グラフ内周)で、それより下の項目はバッチ名(外周)になります。
KibanaでVisualize新規画面を選択し、「Pie」を選択します。
グラフの設定は次の通りです。
- Data
- Slice Size
- Aggregation:Sum(合計)
- Field:processing_time(バッチ実行時間)
- Custom Label:総実行時間(秒)
- Split Slices(内周の分割)
- Aggregation:Terms(種別)
- Field:job_category(バッチ種別)
- Order By:metric:総実行時間(秒)
- Order/Size:Decentding/5(すべて表示したいので総数より大きい値)
- Split Slices(外周の分割)
- Aggregation:Terms(種別)
- Field:job_name(バッチ名)
- Order By:metric:総実行時間(秒)
- Order/Size:Decentding/50(すべて表示したいので総数より大きい値)
- Slice Size
ここまで設定すると、このグラフが描画されます。(※先と同じ画面です)
バッチの種別としてはINPUT(青色)、PROCESS(赤色)がほぼ同じで、次いでOUTPUT(緑色)があり、SEND_MAIL(紫色)はわずかということが分かります。
また、INPUT系、OUTPUT系は本数が多く実行時間が分散しているのに対し、PROCESS系は上位3バッチが実行時間をほぼ占めていることが分かります。
バッチの総実行時間の傾向監視(※Exclude条件の活用)
「バッチの総実行時間の傾向監視(カテゴリ別)」
次は、バッチの実行時間が右肩上がりになっているものがないかを監視します。
まずは全体の総実行時間の推移を大まかに把握するグラフを作ります。
集計単位はバッチカテゴリごととします。
KibanaでVisualize新規画面を選択し、「Area」を選択します。
グラフの設定は次の通りです。
- Data
- Y-Axis(グラフのY軸)
- Aggregation:Sum(合計)
- Field:processing_time(バッチ実行時間)
- X-Axis(グラフのX軸)
- Aggregation:Date Histogram(時間軸)
- Field:start_date(バッチ実行日付)
- interval:Daily(日単位)
- Split Series(グラフの系列)
- Sub Aggregation:Terms(種別ごと)
- Field:job_categoryy(バッチカテゴリ)
- Order:Ascending 5(すべて表示したいので総数より大きい値)
- Y-Axis(グラフのY軸)
- Metrics & Axes
- Metrics
- Chart Type:area
- Mode:stacked(積み上げグラフ)
- Value Axis:LeftAxis-1
- Line Mode:straight(推移を見たいので普通の線グラフ)
- Y-Axes
- Show:チェックあり
- Position:left
- Mode:normal
- Scale Type:linear
- X-Axis
- Show:チェックあり
- Position:bottom
- Metrics
- Panel Settings
- Settings
- Legend Position:right
- Grid
- X-Axis Lines:チェックあり
- Y-Axis Lines:LeftAxis-1
- Settings
ここまで設定すると、このグラフが描画されます。(※先と同じ画面です)
カテゴリの色は先のものと同じでINPUT(青色)、PROCESS(赤色)、OUTPUT(緑色)、SEND_MAIL(紫色)としています。
SEND_MAILは合計値が小さすぎてほぼ見えませんが、今後増える可能性を考慮して監視対象としておきます。
PROCESSの実行時間が上下しているのは3日に1回だけ、旧いデータを削除するバッチが含まれているためです。
それを除いてもINPUT、OUTPUT共に右肩上がりになっているように見受けられます。
次に集計単位を細かくしたバッチ別集計グラフも作成して分析してみたいと思います。
「バッチの総実行時間の傾向監視(バッチ別)」
先の「バッチの総実行時間の傾向監視(カテゴリ別)」と同じ方式です。
グラフ条件で差異のある部分だけを記載します。
- Data
- Split Series(グラフの系列)
- Sub Aggregation:Terms(種別ごと)
- Field:job_name(バッチ名)
- Order:Ascending 50(すべて表示したいので総数より大きい値)
- Split Series(グラフの系列)
やはり、カテゴリ別のグラフと同様に3日に1回だけデータ削除を行うバッチPROCESS_Z0010(一番上の赤色)が個々のバッチの傾向を見るのに邪魔です。この他にも月末だけ処理をするもの(一番下の青灰色など)がその日だけ全体を底上げしています。
日によって処理時間が大きく上下するバッチは別にグラフを作成することにし、このグラフからは除外します。
この条件に当てはまるバッチはPROCESS_Z0010の他、INPUT_A02、OUTPUT_A08、OUTPUT_B10、OUTPUT_B11です。
グラフ設定の以下を変更します。
- Data
- Split Series(グラフの系列)
- Sub Aggregation:Terms(種別ごと)
- Field:job_name(バッチ名)
- Order:Ascending 50(すべて表示したいので総数より大きい値)
- (Advanced Options) Exclude
:INPUT_A02|PROCESS_Z0010|OUTPUT_(A08|B10|B11)
- Split Series(グラフの系列)
こうして見ると、全体的に右肩上がりになっているというよりは、全体のデータ量が増えた7月を境に処理時間が増えたあとは横ばいになっているということが分かります。※とはいえ10月の結果が上り調子なまま終わっているので、12月くらいまでのデータを確認したいところですが。
Kibanaダッシュボードの作成
ダッシュボードを使えば複数のグラフを表示できるため、監視が便利になります。
KibanaのDashboardページより、「+」マークを押下します。
画面上部のAddをクリックするとグラフの一覧が出るので、表示したいグラフをドラッグ&ドロップで並べていきます。
完成です。このダッシュボードを保存しておけばいつでも表示できます。
まとめ
最初にバッチ側で開始・終了日時が読み取りやすいログファイルを出力する必要はありますが、それさえ出来れば集計からグラフ表示までを自動化出来ました。ここで紹介したグラフはほんの一例で、観点を変えれば他にもさまざまなグラフを生成出来ます。例えば、別の年度で集計するグラフを並べることで次の繁忙期の実行時間が予測出来ます。
冒頭でKibanaのグラフに赤線を入れたいと書きましたが、業務で監視する際はこのグラフに所見を添えたドキュメントを定期的に作成するのでその時に手動で足せばよいことに気が付きました。グラフの自動生成はその手間を補って余りあるものと思います。
長い記事となりましたが、ここまでお読みいただきありがとうございました。
参考情報
いずれも構築段階での参考資料です。
(公式)Kibanaのインストール
https://www.elastic.co/guide/jp/kibana/5.4/install.html
(公式)Kibana - サンプルデータの読み込み
https://www.elastic.co/guide/jp/kibana/5.4/tutorial-load-dataset.html
logstashの設定ファイルが正しいかを調べる
https://asahima.hatenablog.jp/entry/2017/09/04/210000
→Logstashの設定を細かく変えながら何度も動作させている間、助かりました。
Logstashでハマった - Kibanaを立ててみた:番外編
http://atsuizo.hatenadiary.jp/entry/2017/09/13/093018
→こちらもLogstash構築時。ファイルのアクセス権設定でミスがあると動作しない・ログも出ないという状況になります。ご注意ください。