awkでログ分析 #Bash

awkでログファイルを分析＆集計する際によくやる方法

環境・前提

awkが実行できる
awkの列概念（$1が1列目）くらいは知ってる

解析イメージ

ログファイルは処理ログ
関数単位のデバッグメッセージが出力されている
一つの関数ログは開始、件数、成功か失敗の3行が必ずまとまって出力される
成功した関数だけ件数を集計し関数名と共に出力する

ログファイル

funcXはerror終了なので集計しない
funcAは全てsuccessなので件数を全て集計(計30件)
funcBは一つerrorがある(計22件)

sample.log

debug funcX start
debug reccnt 100
debug funcX error
--
debug funcA start
debug reccnt 10
debug funcA success
--
debug funcA start
debug reccnt 8
debug funcA success
--
debug funcA start
debug reccnt 12
debug funcA success
--
debug funcB start
debug reccnt 10
debug funcB success
--
debug funcB start
debug reccnt 8
debug funcB error
--
debug funcB start
debug reccnt 12
debug funcB success

実装検討

仕様決め（ざっくり）

start, reccnt, successのキーワードが使えるな
startがあれば関数名取得
reccntがあれば取得済み関数名にカウントをセット
successがあれば取得済み関数名とカウントを出力用変数にセット
全行処理できたら出力する
先頭行にヘッダだけは出力しておこう
ヘッダは結果出力がなくても無条件に出力する

実装

start判定

startがあれば関数名を取得する処理

まずはstart行の取得を確認

$ awk '$3~/start/{ print $0}' sample.log
debug funcX start
debug funcA start
debug funcA start
debug funcA start
debug funcB start
debug funcB start
debug funcB start

判定中の関数がわかるようにtmpという変数に関数名($2)をセットしておこう

$ awk '$3~/start/{tmp=$2}' sample.log

reccnt判定

reccntがあれば取得済み関数名にカウントをセットする処理

まずはreccntの取得を確認

$ awk '$3~/start/{tmp=$2} $2~/reccnt/{print $3}' sample.log
100
10
8
12
10
8
12

件数を一時的に保持しておくためにcnt[関数名]という配列に件数($3)をセットしておこう

awk '$3~/start/{tmp=$2} $2~/reccnt/{cnt[tmp]=$3}' sample.log

success判定

successがあれば取得済み関数名とカウントを出力用変数にセットする処理

まずはsuccess行の取得を確認

$ awk '$3~/start/{tmp=$2} $2~/reccnt/{cnt[tmp]=$3} $3~/success/{print $0}' sample.log
debug funcA success
debug funcA success
debug funcA success
debug funcB success
debug funcB success

出力用のout[関数名]という配列に件数(cnt[$2])を加算する

$ awk '$3~/start/{tmp=$2} $2~/reccnt/{cnt[tmp]=$3} $3~/success/{out[$2]+=cnt[$2]}' sample.log

整形

END処理

全行処理後に出力を行う

まずは配列を展開しの関数名が正しくセットできているか確認

$ awk '$3~/start/{tmp=$2} $2~/reccnt/{cnt[tmp]=$3} $3~/success/{out[$2]+=cnt[$2]} END{for(f in out){print f}}' sample.log
funcA
funcB

件数も出力

$ awk '$3~/start/{tmp=$2} $2~/reccnt/{cnt[tmp]=$3} $3~/success/{out[$2]+=cnt[$2]} END{for(f in out){print f,out[f]}}' sample.log
funcA 30
funcB 22

BEGIN処理

先頭行にヘッダを出力しよう
csv形式にするのでOFS（Output Field Separator）にカンマをセットしcsvヘッダを出力すれば完成！

$ awk 'BEGIN{FS=" ";OFS=",";print "function,count"} $3~/start/{tmp=$2} $2~/reccnt/{cnt[tmp]=$3} $3~/success/{out[$2]+=cnt[$2]} END{for(f in out){print f,out[f]}}' sample.log
function,count
funcA,30
funcB,22

実際はファイルに出力するのでout.csvにリダイレクト

$ awk 'BEGIN{FS=" ";OFS=",";print "function,count"} $3~/start/{tmp=$2} $2~/reccnt/{cnt[tmp]=$3} $3~/success/{out[$2]+=cnt[$2]} END{for(f in out){print f,out[f]}}' sample.log > out.csv

結果ファイル

out.csv

function,count
funcA,30
funcB,22

おまけ

awkを使う時は今回のように簡単に処理する場合が多いのでワンライナーで書くことが多いですがせっかく書いたのでファイル化して保存しておこう。

処理をfile化

func_cnt.awk

BEGIN {
        FS=" "; /* 入力フィールドセパレータ */
        OFS=","; /* 出力フィールドセパレータ */
        print "function,count";
}

$3 ~ /start/ {
        tmp=$2;
}

$2 ~ /reccnt/ {
        cnt[tmp]=$3;
}

$3 ~ /success/ {
        out[$2] += cnt[$2];
}

END {
        for(f in out){
                print f,out[f];
        }
}

実行例

$ awk -f func_cnt.awk sample.log
function,count
funcA,30
funcB,22

あとがき

現在Talendを扱っているのですが実はその記事を書くための参照ネタとして今回のawkログ解析を書きました。
個人的感想ですがtJavaFlexというコンポーネントがawkの考え方にそっくりなんですよね。