【Splunk】1つのイベントで複数の時刻情報を持つ場合の時間差分取得方法

以前Splunkを使っていて困ったことがあったので、備忘投稿。

SplunkはHTTPアクセスログなどの1データに1つの時刻情報を持つデータを分析することには長けていますが、
処理の開始時刻と終了時刻が1つのデータにまとまった場合はちょっと工夫する必要があります。

ちょっと具体的にしますと、次のようなデータの場合は結構簡単に時間差分を出すことができます。

処理ID, 時刻, 処理内容
1001, 2017/04/01 12:00:00, 開始
1002, 2017/04/01 13:00:00, 開始
1002, 2017/04/02 10:00:00, 終了
1003, 2017/04/02 11:00:00, 開始
1001, 2017/04/02 13:00:00, 終了
1003, 2017/04/03 15:00:00, 終了

こんな感じのデータを「sample_data_1」というインデックスでSplunkに放り込んで、
次のようなサーチ文で処理することで、処理ID毎の時間を出力することができます。
※ 「duration」は秒(sec)表示なので、3600で割って時間(hour)表示にしときます

index="sample_data_1"
| transaction 処理ID
| eval dhour=duration/3600
| table 処理ID, dhour

ですが、冒頭で触れたような次のデータだとこの手法が使えません。(インデックスを「sample_data_2」とします)

処理ID, 開始時刻, 終了時刻
1001, 2017/04/01 12:00:00, 2017/04/02 13:00:00
1002, 2017/04/01 13:00:00, 2017/04/02 10:00:00
1003, 2017/04/02 11:00:00, 2017/04/03 15:00:00

durationはtransactionでまとめた２つ以上のイベントの差分時間を抽出したものであるため、
上記データでそれをやると「0」時間が抽出されます。(そもそもイベントが１つで差分を出せないため)

そんなときは次みたいにやるとうまいこと差分時間を出すことができます。
※ 「開始時刻」「終了時刻」とフォーマットで記号（「'」と「"」）が違うので注意

index="sample_data_2"
| eval _time=strptime('開始時刻', "%Y/%m/%d %H:%M:%S"), t_data="start"
| append [ search index="sample_data_2"
| eval _time=strptime('終了時刻', "%Y/%m/%d %H:%M:%S"), t_data="end"]
| transaction 処理ID
| eval dhour=duration/3600
| table 処理ID, dhour

何をやってるかというと、１つのイベントの中の時刻情報ごとに「_time」を再定義し、
１つのイベントを複数のイベントに分割してます。
これによりtransactionでイベント間の時間差分を抽出することができます。

Splunkはメジャーなデータ書式には予め対応していますが、
ローカルなデータになると利用者側で色々と定義する必要があります。
そんなときはサーチリファレンスとかSplunk Answerとかで調べてみるといいと思います。