アプリログをQlikViewでリアルタイムに可視化してみた。

お疲れ様です。高橋です。

タイトルは本当だと「アプリが送るログをhttpdが受け取ってaccess_logに追記し、そこをfluentdがtailし続けて必要なものだけgrepしてparseしてMySQLにinsertしたものをSSH Proxyを経由してODBCしたものをQlikViewでリアルタイムに可視化してみた。」が正確ですが、これだと長過ぎるのでシンプルにしてみました。

先日からの宿題は、ほぼ完了しました。

出力ログについて

アプリからは、

http://curious4dev.mydns.jp/appLog?app_id=<app_id>&adid=<adid>&act=<act>

という形でサーバ(curious4dev.mydns.jp)に対して送っています。

これを見ると一見、「appLogというログ蓄積用のアプリがあり、そいつが受け取ったapp_idとadidとactを処理しているんだな」と思われるかもしれませんが、実はappLogなんていうイカした物は実装していません。httpdをただのaccess_logへのログ出力アプリとしてしか使っていません。access_logには

111.104.142.201 - - [07/Dec/2014:18:41:03 +0900] "GET /appLog?app_id=jp.curious4dev.nishinokanakana&adid=&act=re_create HTTP/1.1" 200 0 "-" "Apache-HttpClient/UNAVAILABLE (java 1.4)"

こんな感じで吐き出されます。

adidが吐き出されていないのはアプリ側のバグです。原因はわからないので明日デバッグです。で、一応0byteの「appLog」というファイルを作って、404ではなく200を返すようにしています。でないと、勝手に404用のファイルを出力しようとし、おそらくこのサーバの負荷が若干上がるのではないか、と思ったからです。

とりあえず、解析前のログがaccess_logに書き込まれるようになりましたので、次はfluentdでの分解・格納です。

fluentdについて

fluentdとは、公式ページにも書いてありますが、いろんなデータソースをいろんなデータソースに格納してくれる、素敵なロギングツールです。

今回私がやりたい事は「access_logに格納された適当なパラメータ群をイイ感じに分解して、MySQLにinsertする」事です。いい感じに分解するには、正規表現が必要です。

その前にfluentdの設定ファイルの構造は

<source>
  type tail
  format ～～
  path /var/log/httpd/access_log
  tag apache.appLog
</source>
<match>
  type file
  path /tmp/hoge.flu
</match>

な感じです。sourceで受け取って、matchで出力する感じです。

下記はaccess_logですが、

111.104.142.201 - - [07/Dec/2014:18:41:03 +0900] "GET /appLog?app_id=jp.curious4dev.nishinokanakana&adid=&act=re_create HTTP/1.1" 200 0 "-" "Apache-HttpClient/UNAVAILABLE (java 1.4)"

この部分の

/appLog?app_id=jp.curious4dev.nishinokanakana&adid=&act=re_create

を、「app_id」「adid」「act」に分解する必要があります。

ので、正規表現としては下記のような記載になります。

format /^(?<remote_addr>[^ ]*) [^ ]* (?<user>[^ ]*) \[(?<time>[^\]]*)\] "(?<method>\S+)(?: +(?<path>[^\?]*)\?[^\=]*\=(?<app_id>[^\&]*)\&[^\=]*\=(?<adid>[^\&]*)\&[^\=]*\=(?<action>[^ ]*) +\S*)?" (?<code>[^ ]*) (?<size>[^ ]*)(?: "(?<referer>[^\"]*)" "(?<user_agent>[^\"]*)")?$/

これで、access_logに記載される全てのパラメータを取得する事が出来ます。正規表現って何度も書いていますが、相変わらず分かりにくいです。

また、curious4dev.mydns.jpは、wordpressサーバも兼ねていますので、当然上記以外のログも沢山吐き出されています。その邪魔なログを捨てるために、fluent-plugin-grepを導入し、「pathというkeyにappLogという物がある行のみ取得して下さい」と設定してやる必要があります。こんな感じに。

<match apache.appLog>
 type grep
 input_key path
 regexp appLog
 add_tag_prefix greped
</match>

あとは、fluent-plugin-mysqlを導入し、下記のように、パースした変数をそのままinsertする感じに記載すればOKです。事前にtableを作っておくのは言うまでもありません。(fluent-plugin-mysqlは、gem mysql2に依存しており、mysql2はmysql-develに依存しているので、事前にyumったりgemったりする必要があります。)

<match greped.apache.appLog>
 type mysql
 host localhost
 database ********
 key_names remote_addr, user, method, path, app_id, adid, action, code, size, referer, user_agent
 sql INSERT INTO appLog (remote_addr, user, method, path, app_id, adid, action, code, size, referer, agent) values(?,?,?,?,?,?,?,?,?,?,?)
 username ********
 password ********
 flush_interval 10s
</match>

fluentd.confの全体像は下記のような感じです。

<source>
 type tail
 format /^(?<remote_addr>[^ ]*) [^ ]* (?<user>[^ ]*) \[(?<time>[^\]]*)\] "(?<method>\S+)(?: +(?<path>[^\?]*)\?[^\=]*\=(?<app_id>[^\&]*)\&[^\=]*\=(?<adid>[^\&]*)\&[^\=]*\=(?<action>[^ ]*) +\S*)?" (?<code>[^ ]*) (?<size>[^ ]*)(?: "(?<referer>[^\"]*)" "(?<user_agent>[^\"]*)")?$/
 time_format %d/%b/%Y:%H:%M:%S %z
 path /var/log/httpd/access_log
 pos_file /opt/fluent/fluent.pos
 tag apache.appLog
</source>
<match apache.appLog>
 type grep
 input_key path
 regexp appLog
 add_tag_prefix greped
</match>
<match greped.apache.appLog>
 type mysql
 host localhost
 database ********
 key_names remote_addr, user, method, path, app_id, adid, action, code, size, referer, user_agent
 sql INSERT INTO appLog (remote_addr, user, method, path, app_id, adid, action, code, size, referer, agent) values(?,?,?,?,?,?,?,?,?,?,?)
 username ********
 password ********
 flush_interval 10s
</match>

fluentを動かしておくと、↓のようにMySQLにログがドンドコ蓄積されていきます。

mysql> select seq, remote_addr, user, method, path, app_id, adid, action, code, size, referer from appLog;
+-----+----------------+------+--------+---------+----------+-----------+--------+------+-------+---------+
| seq | remote_addr | user | method | path | app_id | adid | action | code | size | referer |
+-----+----------------+------+--------+---------+----------+-----------+--------+------+-------+---------+
| 1 | 106.153.33.120 | - | GET | /appLog | test | test2 | boot | 404 | 18830 | - |
| 2 | 106.153.33.120 | - | GET | /appLog | test | test2 | boot | 404 | 18830 | - |
| 3 | 106.153.33.120 | - | GET | /appLog | test | test2 | boot | 200 | - | - |
| 4 | 106.153.33.120 | - | GET | /appLog | test | test2 | boot | 304 | - | - |
| 5 | 106.153.33.120 | - | GET | /appLog | test | test2 | boot | 200 | - | - |
| 6 | 106.153.33.120 | - | GET | /appLog | test | test2 | boot | 304 | - | - |
| 7 | 106.153.33.120 | - | GET | /appLog | test | test2 | boot | 304 | - | - |
| 8 | 106.153.33.120 | - | GET | /appLog | test | test2 | boot | 304 | - | - |
| 9 | 106.153.33.120 | - | GET | /appLog | test | test3 | boot | 200 | - | - |
| 10 | 106.153.33.120 | - | GET | /appLog | test2 | test3 | boot | 200 | - | - |
| 11 | 106.153.33.120 | - | GET | /appLog | testaaa2 | test3 | boot | 200 | - | - |
| 12 | 106.153.33.120 | - | GET | /appLog | testaaa2 | test12313 | boot | 200 | - | - |
+-----+----------------+------+--------+---------+----------+-----------+--------+------+-------+---------+
12 rows in set (0.00 sec)

QlikViewからODBCする

curious4dev.mydns.jpで動いているMySQLにODBCする必要があります。まずはSSH proxyで、自分のPCの3306を叩くと、curious4dev.mydns.jpの3306につなげる感じの設定をします。私はPuTTYという素敵なterminalを使っていますが、普通のコマンドだと、おそらく

ssh -L 3306:localhost:3306

な感じになると思います。

で、MySQLのODBCドライバを公式からダウンロードし、インストールします。んで、普通に自分の3306を叩く感じでODBCを下記のように設定します。

一応、「Test」を押して↓が出てくる事を確認します。

QlikViewから繋げる

QlikViewのLoadScriptで、先ほど作ったODBC設定を読み込み、後はお好みで見たい観点でチャートを作っていけば完了です。下記は、サンプルとしてapp_id毎のadidの数や、action毎のadidの数をリアルタイムに表示している所です。

サーバ周りの事ばかりやっていたので、アプリ側の実装をすっかり放置していました。

以上、よろしくお願い致します。