背景
現在、私はある会社でソーシャルゲームを運用している。
ユーザーから「ローディングが遅くてなかなかゲームが始まらないぞ！」「ある特定の動作が
遅くてゲームが進まない！」という声が増えてきた。
Apacheのログからボトルネック(レスポンス時間が極めて遅いところの調査)を調査することになりました。しかし、何万行もあるログを上から見ていくのは至難の技です。
なんとか効率化できないものか考えたところ、数分間隔毎に、リクエストURLごとに平均レスポンス時間、最大レスポンス時間を纏めるものを作ってみた。
このような処理を実装した結果、どこのリクエストがボトルネックになっているのかわかるようになりました。
ボトルネックになっているURLがわかると、不具合等の調査もしやすくなります。
※厳密に言うと、「ここがボトルネックになっているだろう」と仮説を立てることができるが、数字化できなかったため検証・立証が困難だった。
作ったものの紹介
開発環境
■Webサーバ
Linux
apache
■プログラミング言語
python (v2.7)
作成したもの
作成したものは、Githubに公開しています。
もし使ってみたいと思ったら、以下のURLから
https://github.com/jshirius/python_tools
「apache_log_ana.py 」をダウンロードしてください。
■使い方
コンソールやターミナル画面で以下のように入力して実行します。
python2.7 apache_log_ana.py <計測対象のログファイル1つめ> <計測対象のログファイル2つめ> …
実際に入力した例
python2.7 apache_log_ana.py apache_access.log apache_access_2.log
使用上の注意
Apacheのログは、httpd.confのLogFormatによって、出力する形式が違うため。
実際に使う場合はLogFormatを確認した上で、本プログラムを修正して使うようにしてください。
このプログラムを使った結果、不具合等の問題が起きても当方は責任は持ちません。
使用例
以下のようなApacheログファイルを用意します。
apache_access.logの中身
2018-12-22T04:18:58+00:00 apacheaccess {"APACHEACCESS":"101.2.193.222 - - [22/Dec/2018:04:18:57 +0000] \"GET /sampleApi/Controller/function1 HTTP/1.1\" 200 43 16799 10.0.2.255
2018-12-22T04:18:58+00:00 apacheaccess {"APACHEACCESS":"101.2.193.222 - - [22/Dec/2018:04:18:57 +0000] \"GET /sampleApi/Controller/function1 HTTP/1.1\" 200 43 26799 10.0.2.255
2018-12-22T04:21:00+00:00 apacheaccess {"APACHEACCESS":"101.2.193.222 - - [22/Dec/2018:04:18:57 +0000] \"GET /sampleApi/Controller/function1 HTTP/1.1\" 200 43 36799 10.0.2.255
2018-12-22T04:22:58+00:00 apacheaccess {"APACHEACCESS":"101.2.193.222 - - [22/Dec/2018:04:18:57 +0000] \"GET /sampleApi/Controller/function2 HTTP/1.1\" 200 43 46799 10.0.2.255
2018-12-22T04:22:58+00:00 apacheaccess {"APACHEACCESS":"101.2.193.222 - - [22/Dec/2018:04:18:57 +0000] \"GET /sampleApi/Controller/function3 HTTP/1.1\" 200 43 56799 10.0.2.255
ターミナルなどのコマンドプロンプトからapache_log_ana.pyを実行します。
python2.7 apache_log_ana.py apache_access.log
上記の実行後、以下のようなCSVファイルが出力されます。
以下の例は5分毎のリクエスト回数、最大レスポンス時間(ms) 、平均レスポンス時間(ms) を出力しています。
時間帯(5分毎),リクエストURL,リクエスト回数,最大レスポンス時間(ms) ,合計レスポンス時間(ms),平均レスポンス時間(ms)
20181222_0415,function1,2,26,42,21
20181222_0420,function1,1,36,36,36
20181222_0420,function2,1,46,46,46
20181222_0420,function3,1,56,56,56
エクセルに出力したイメージ
まとめ
ソーシャルゲームを運用開始すると様々な問題が勃発します。
ただ、ログを出力するだけでなく、加工することも考慮して設計するべきであることが、運用を通してわかったのである。
