LoginSignup
4

More than 5 years have passed since last update.

awkでログ解析〜レスポンス時間を添えて〜

Last updated at Posted at 2019-02-03

まず

ログの解析で、時間ごとの集計(例えば○月☓日の△時〜◇時までのアクセス数)とかは割と簡単にできた(というよりQiitaとかにたくさんやり方が載っている)が、アクセスに対してどれくらいレスポンスに時間がかかったとか、24時間でアクセスが0件だったものも表示する、というお題が出されて苦戦しました。しかも一行で。

実行環境

  • Linux
  • Apache
  • bash

実際にやってみる

例えばこんな感じのログがあったとする
Apacheのログはhttpd.confカスタマイズ可能なので、今回は最後にレスポンス時間(ミリ秒)を表示させています。

access_log.2019-02-03.txt
xxx.x.x.x - - [03/Feb/2019:04:03:00 +0900] “POST /test/a HTTP/1.1” 200 213
xxx.x.x.x - - [03/Feb/2019:10:26:20 +0900] “POST /test/b HTTP/1.1" 200 213
xxx.x.x.x - - [03/Feb/2019:10:26:21 +0900] “POST /test/b HTTP/1.1” 200 244
xxx.x.x.x - - [03/Feb/2019:10:26:21 +0900] “POST /test/c HTTP/1.1" 200 77
xxx.x.x.x - - [03/Feb/2019:10:26:23 +0900] “POST /test/c HTTP/1.1” 200 285
xxx.x.x.x - - [03/Feb/2019:10:26:23 +0900] “POST /test/c HTTP/1.1" 200 77
xxx.x.x.x - - [03/Feb/2019:10:26:26 +0900] “POST /test/d HTTP/1.1” 200 77
xxx.x.x.x - - [03/Feb/2019:10:26:26 +0900] “POST /test/e HTTP/1.1" 200 14531
xxx.x.x.x - - [03/Feb/2019:10:26:36 +0900] “POST /test/f HTTP/1.1” 200 11526
(以下省略)

一時間ごとで集計する

ここからいらない情報を削って、一時間ごとで集計する

awk '{print $4}' access_log.2019-02-03.txt | cut -b 2-15 | sort | uniq -c | sed "s/03\/Feb\/2019:/2019\/02\/03 /g" | awk '{print $2,$3":00","#",$1}'

以下、出力結果

2019/02/03 04:00 # 1
2019/02/03 10:00 # 28
2019/02/03 12:00 # 4
2019/02/03 13:00 # 18
2019/02/03 14:00 # 216
2019/02/03 15:00 # 1
2019/02/03 16:00 # 2
2019/02/03 17:00 # 218
2019/02/03 18:00 # 5109
2019/02/03 19:00 # 4502
2019/02/03 20:00 # 4941
2019/02/03 21:00 # 1037
コマンドの解説

awk '{print $4}' access_log.2019-02-03.txt
ファイルから各行の4列目を取得してprintする。日付と時間を取得する。

cut -b 2-15
先ほど取得したのが[03/Feb/2019:04:03:00となっているので、03/Feb/2019:04に変更する。

sort | uniq -c
uniqコマンドにオプション-cを指定すると重複したものを一行にまとめて、件数を一列目に表示してくれる。ただその前にデータが整列されている必要があるのでsortをする(実際ログデータは時間順に整列されているので必要ないのですがw)

sed "s/03\/Feb\/2019:/2019\/02\/03 /g"
これも実は必要なくて、個人的に年/月/日で表示したかったのと、日付と時間の区切りをスペースにしたかったので書いていますw

awk '{print $2,$3":00","#",$1}'
最後に時間表示がたとえば04:00とかになるようにするのと、件数をわかりやすく(?)するために#をつけて、最後尾に表示するために並び替えて表示する。

問題点

上記コマンドだとログ0件の時間が取得できていないのと、レスポンス時間で分けられていない。
順を追って実現していきましょう。

0件を表示させる

uniq -cで重複をまとめて件数を表示しているので、0件のものはそもそもカウントできない。ので、各時間に1件ずつダミーを表示して、最後に1を引く、というパワープレイをします。

(awk '{print $4}' access_log.2019-02-03.txt | cut -b 2-15 | sed "s/03\/Feb\/2019:/2019\/02\/03 /g" ; for i in 00 01 02 03 04 05 06 07 08 09 10 11 12 13 14 15 16 17 18 19 20 21 22 23; do echo "2019/02/03 $i"; done ) | sort -k 2 -n | uniq -c | awk '{print $2, $3":00", "#", $1-1}'

先程のものに0件が追加で表示された

2019/02/03 00:00 # 0
2019/02/03 01:00 # 0
2019/02/03 02:00 # 0
2019/02/03 03:00 # 0
2019/02/03 04:00 # 1
2019/02/03 05:00 # 0
2019/02/03 06:00 # 0
2019/02/03 07:00 # 0
2019/02/03 08:00 # 0
2019/02/03 09:00 # 0
2019/02/03 10:00 # 28
2019/02/03 11:00 # 0
2019/02/03 12:00 # 4
2019/02/03 13:00 # 18
2019/02/03 14:00 # 216
2019/02/03 15:00 # 1
2019/02/03 16:00 # 2
2019/02/03 17:00 # 218
2019/02/03 18:00 # 5109
2019/02/03 19:00 # 4502
2019/02/03 20:00 # 4941
2019/02/03 21:00 # 1037
2019/02/03 22:00 # 0
2019/02/03 23:00 # 0
コマンドの解説

for i in 00 01 02 03 04 05 06 07 08 09 10 11 12 13 14 15 16 17 18 19 20 21 22 23; do echo "2019/02/03 $i"; done
for文で00時から23時まで気合いで表示。

sort -k 2 -n | uniq -c
最初のawkからこのコマンドの前まで( )がついているのは、括弧がないと、おそらくfor文の中の;をbashが勘違いして処理をわけてしまって正しくsortできなかったから。
-nで数字として、-kオプションで2つ目の値を基準に並び替えています。

awk '{print $2, $3":00", "#", $1-1}'
最後にここで1を引くことで辻褄を合わせるw

レスポンス時間で分ける

今回はとりあえずレスポンスに3秒かからなかったもの、3秒以上10秒未満、10秒以上のものに分類。各時間で3行ずつ表示、それを最後に形を整えて表示させる戦法でいきます。

(awk '{print substr($0, index($0, "03"))}' access_log.2019-02-03.txt | sed -e "s/ /:/g" -e "s/03\/Feb\/2019/2019\/02\/03/g" | awk -F : '{print $1,$2,$10}'| awk '{if($3<3000){print $1,$2,"03"} else if($3>=3000&&$3<10000){print $1,$2,"05"} else {print $1,$2,10}}'; for i in 00 01 02 03 04 05 06 07 08 09 10 11 12 13 14 15 16 17 18 19 20 21 22 23; do for j in 03 05 10; do echo "2019/01/09 $i $j"; done; done) | sort -k 2,2 -k 3n | uniq -c | awk '{print $2,$3":00", $1-1" "}' | awk 'NR % 3 != 0 {printf $0;} NR % 3 ==0 {print $0}' | awk 'BEGIN{print "date", "hour", "0-3s", "3-10s", "10s-"}{print $1,$2,$3,$6,$9}'

レスポンス時間で分けられた。

date hour 0-3s 3-10s 10s-
2019/02/03 00:00 0 0 0
2019/02/03 01:00 0 0 0
2019/02/03 02:00 0 0 0
2019/02/03 03:00 0 0 0
2019/02/03 04:00 1 0 0
2019/02/03 05:00 0 0 0
2019/02/03 06:00 0 0 0
2019/02/03 07:00 0 0 0
2019/02/03 08:00 0 0 0
2019/02/03 09:00 0 0 0
2019/02/03 10:00 20 3 5
2019/02/03 11:00 0 0 0
2019/02/03 12:00 4 0 0
2019/02/03 13:00 13 1 4
2019/02/03 14:00 215 0 1
2019/02/03 15:00 0 0 1
2019/02/03 16:00 2 0 0
2019/02/03 17:00 217 0 1
2019/02/03 18:00 5109 0 0
2019/02/03 19:00 4501 0 1
2019/02/03 20:00 4941 0 0
2019/02/03 21:00 1037 0 0
2019/02/03 22:00 0 0 0
2019/02/03 23:00 0 0 0
コマンドの解説

awk '{print substr($0, index($0, "03"))}' access_log.2019-02-03.txt | sed -e "s/ /:/g" -e "s/03\/Feb\/2019/2019\/02\/03/g" | awk -F : '{print $1,$2,$10}'
今回は日時以外にレスポンス時間も取得しなくてはいけない。やり方はなんでも良いので、とりあえず今回はまずは日付までの部分を削除。それからスペースを:に置換して、それを区切り文字として指定して日時とレスポンスを取得。
(取得できればやり方はなんでもいいと思います。)

awk '{if($3<3000){print $1,$2,"03"} else if($3>=3000&&$3<10000){print $1,$2,"05"} else {print $1,$2,10}}';
レスポンス時間が3秒未満、3秒以上10秒未満、10秒以上のものにそれぞれ03,05,10と印を付ける。3つに分類できれば何でもいいのだけど、あとでsortしたときに順番がこの順番になるように気をつけてください。

for i in 00 01 02 03 04 05 06 07 08 09 10 11 12 13 14 15 16 17 18 19 20 21 22 23; do for j in 03 05 10; do echo "2019/01/09 $i $j"; done; done
for文の中でfor文を記述します。先程の0件表示と同じように各時間、各レスポンスでダミーを1件ずつ追加します。

sort -k 2,2 -k 3n | uniq -c | awk '{print $2,$3":00", $1-1" "}'
ここでのsortはまず時間で並び替えたあと、その中で03→05→10となるように並び替えます。最後にスペースを付け足しているのは、次のコマンドで改行せずに表示したときに区切りがわからなくなってしまわないためです。

awk 'NR % 3 != 0 {printf $0;} NR % 3 ==0 {print $0}'
print f は明示的に改行を指定しない限り改行されません。それを利用して、3の倍数行のときのみ改行して表示させ、それ以外のときに改行しないで表示させることができます。
レスポンス時間を4区切りで表示するなら、4の倍数行に変えてあげればオッケー。
ちなみに、この段階でこういう風に表示されるはずです。

2019/02/03 00:00 0 2019/02/03 00:00 0 2019/02/03 00:00 0 
2019/02/03 01:00 0 2019/02/03 01:00 0 2019/02/03 01:00 0
(省略)

awk 'BEGIN{print "date", "hour", "0-3s", "3-10s", "10s-"}{print $1,$2,$3,$6,$9}'
最後に一行目に分類をprintして、必要な列のみ表示させます。

おわりに

webエンジニア初心者なりに力づくでやってしまいましたが、より良い書き方があればコメントいただけると嬉しいです。。。

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
4