アクセスログの直近数分の平均レスポンス秒数を取るためのワンライナー

#概要
nginxやapacheでアクセスログから直近数分間の平均レスポンス秒数を取るためのワンライナーです。ちゃんとした分析基盤があれば不要なのですが、サクッと出したり定点観測したいときに活用ください。

#注意事項
簡単な解析スクリプトのため、ログを全部走査します。ログファイルが巨大な場合は適宜分割するか、catしている部分をtail -nXXXで行指定して出す等してください。ログのサイズによっては重くなる可能性があるので、負荷をかけても大丈夫な環境で試してください。

#ワンライナー本体と集計ログ

• nginxのアクセスログから現在から5分以内の平均アクセス秒数を取得

checkdate=`date -d '5 minutes ago' '+%d %b %Y %H:%M:%S +0900'`; cat /var/log/nginx/access.log | sed -r "s/^.*\[(.*)\](.*)$/\1\2/" | sed -e 's#/# #g' -e 's/:/ /' |awk -F - '"'"$checkdate"'" < $1 ' | awk '{sum += $NF; count++}; END{print (sum/count)}'

• ログフォーマット

log_format  main  '$remote_addr - $remote_user [$time_local] "$request" '
                  '$status $body_bytes_sent "$http_referer" '
                  '"$http_user_agent" "$http_x_forwarded_for" $request_time';

• 実際のログのサンプル

111.222.333.444 - - [06/Sep/2017:18:19:08 +0900] "GET /test/testApi HTTP/1.1" 200 3942 "Something referrer" "Something user agent" "-" 0.025
111.222.333.444 - - [06/Sep/2017:18:19:08 +0900] "GET /test/testApi HTTP/1.1" 200 3942 "Something referrer" "Something user agent" "-" 0.035
111.222.333.444 - - [06/Sep/2017:18:19:08 +0900] "GET /test/testApi HTTP/1.1" 200 3942 "Something referrer" "Something user agent" "-" 0.045

#解説

checkdate=`date -d '5 minutes ago' '+%d %b %Y %H:%M:%S +0900'`;

• あとで利用するため、フォーマット済みの日時を変数に入れておきます。

cat /var/log/nginx/access.log

• ログを出力します。全内容読み取るので保険をかけるなら tail /var/log/nginx/access.log -n10000（nのあとは適度に大きい数）でも可

| sed -r "s/^.*\[(.*)\](.*)$/\1\2/"

• []をなくして、[]以降の文字列に変換

| sed -e 's#/# #g' -e 's/:/ /'

• 日付をawkで扱えるようにフォーマット変換 "06/Sep/2017:18:19:08 +0900"が"6 Sep 2017 18:19:08 +0900"になる。

| awk -F - '"'"$checkdate"'" < $1 ' 

• 指定日時以降のものを取得。今回はやってませんが、期間指定もできます。

| awk '{sum += $NF; count++}; END{print (sum/count)}'

• 合計値と件数を取得集計、計算して出力。apacheの場合はマイクロ秒なので、1000000で割ってあげるとわかりやすくなります。

#【応用】シェルにして、zabbixで観測する。

間に合わせですが、以下のようにファイルと取得する分数を指定して取得するシェルを組めば、定点観測できます。1分、5分、15分の値をとってロードアベレージのように遷移をみるとかできます。

##シェル作成

mkdir -p /etc/zabbix/script/
touch /etc/zabbix/script/get_nginx_average_response.sh 
chmod 755 /etc/zabbix/script/get_nginx_average_response.sh 
vim /etc/zabbix/script/get_nginx_average_response.sh 

/etc/zabbix/script/get_nginx_average_response.sh

#!/bin/sh

checkdate=`date -d $1' minutes ago' '+%d %b %Y %H:%M:%S +0900'`;
cat $2 | sed -r "s/^.*\[(.*)\](.*)$/\1\2/" | sed -e 's#/# #g' -e 's/:/ /' |awk -F - '"'"$checkdate"'" < $1 ' | awk '{sum += $NF; count++}; END{print (sum/count)}'

##agent設定追加、再起動

vim /etc/zabbix/zabbix_agentd.conf

以下を最後尾に追記

/etc/zabbix/zabbix_agentd.conf

UserParameter=nginxresponseavg[*],bash /etc/zabbix/script/get_nginx_average_response.sh \$1 \$2

エージェント再起動

service zabbix-agent restart

##zabbixの設定
上記が正しく設定されていれば、以下のキーでデータが取れるはずです。

nginxresponseavg[5, /var/log/nginx/access.log]