Proxyサーバー(Privoxy)のログをMySQLでDB化してMetabaseで可視化してみる
[technology] PrivoxyのログをMYSQLでDB化、Metabaseで可視化
ちょっと以前からMetabaseというオープンソースのBIツール（というカテゴリで良いのだろうか？)を試してみたいと思っていて、COZMOの自律走行遊びが一段落したので、試してみました。
Metabaseで何が出来るか？というと色々なログから情報を判りやすく可視化、つまり色んな視点で整理したグラフを簡単に作って見せてくれるダッシュボード作成ツールです。
巷で流行っているELK(Elastic Search,Logstash,Kibana)やGrafana的な奴。
ELKが使えるならELK使ってしまえば良いのですが、家のPCで個人の勉強がてら動かすのはPCのスペック的に荷が重いなと。環境構築自体は最近はDocker Image引っ張ってくればさほど苦労はなさ気なんですけど。
そこで、Metabaseです。MetabaseはJavaで書かれていて、Java8以上のJava実行環境があれば、jarファイルをjavaに食わせるだけとインストール、起動が超簡単。
最近のOSSらしく公式でDockerイメージも準備されているので、Java環境作るのすら面倒なら、そっちを使う手もあります。
Jarファイルからの起動は下記の様なブログ、色々紹介記事が見つかります。
www.yutorism.jp
baystream.jp
なので、本エントリではMetabaseのインストール方法とかは紹介しません。
どちらかというと問題なのはデータ。
MetabaseはMySQLとか、MongoDBとか、既存のデータベース上に蓄積されたデータを可視化するツールなのでデータが無いと試せません。(あ、一応Metabaseにはお試し用テストデータが付いていますが..)
会社とかなら、既に何か日々蓄積されたデータが有り、なんらかのデータベースに記録されているところからスタートですが個人の勉強なので、ディープラーニングの勉強同様にお試し様の素材データをどうやって集めるか？が結構ハードルだったりします。
で、やっと本題で、Metabaseを試すために家で稼働しているProxyサーバー:Privoxyのログを使う事にしました。
と言っても普段Privoxyではエラー以外ログを吐かせていないので、まず、Privoxyの設定を変更します。
Privoxyの公式サイトに説明によると、ログレベルの定義は下記。
The Main Configuration File
debug 1 # Log the destination for each request Privoxy let through. See also debug 1024. debug 2 # show each connection status debug 4 # show I/O status debug 8 # show header parsing debug 16 # log all data written to the network debug 32 # debug force feature debug 64 # debug regular expression filters debug 128 # debug redirects debug 256 # debug GIF de-animation debug 512 # Common Log Format debug 1024 # Log the destination for requests Privoxy didn't let through, and the reason why. debug 2048 # CGI user interface debug 4096 # Startup banner and warnings. debug 8192 # Non-fatal errors debug 32768 # log all data read from the network debug 65536 # Log the applying actions
この中で、debug 1とdebug 1024を有効化する様にPrivoxyを稼働させているOpenWrtマシン上でコンフィグファイル(/etc/config/privoxy)を編集します。
option debug_1 '1' # 0を1に変更 option debug_512 '0' option debug_1024 '1' # 0を1に変更 option debug_4096 '0' option debug_8192 '0'
これで/etc/init.d/privoxy restartと実行して、1日待ちます。
自分の使い方で1日で約8万行のログが取れました。
ログの中身は下記の様な感じです。
2019-09-03 22:36:32.906 76f17d40 Request: mtalk.google.com:443/ 〜中略〜 2019-09-03 22:41:05.329 76e93d40 Crunch: Blocked: ads.rubiconproject.com:443 〜中略〜 2019-09-03 22:41:17.367 76e93d40 Crunch: DNS failure: http://apple-mobile.query.yahooapis.com/うんたらかんたら....(本当はかなり長い)
「Request」というのが、Privoxyが正常に中継した接続。「Crunch: Blocked：」がPrivoxyのフィルターに引っかかったブロックされたもの。基本的に広告系のものです。
「Crunch: DNS failure:」はそのまんまDNS検索失敗と思われます。(これなんでDNS引けないのか？良く判らないけど)
1日稼働させて出てきたログは基本この3種類。
ちなみにPrivoxyのソースを見ると、ログの種類(特にエラーの種類)はもっとたくさんありますが、Metabaseのサンプルに使うのが目的なので、とりあえずこの3種類だけを考慮してDBに格納することを考えます。
で、DBのスキーマを考えるわけですが、ログを見ると＜日付時刻＞＜謎の16進数値＞＜ログの種類＞＜URL＞という基本形式に見えます。ただし単純に空白をデリミタとしてログをパースすると、ログの種類によって異なるフィールド数に分解されてちょっと面倒です。まあ、この辺はpythonのscript書いてごにょごにょ対処することに。また謎の１６進数値が何なのか？最初はユニークなIDとか、URL部分のchecksumとかかと思ったのですが、Privoxyのドキュメントには言及されておらず、ソースコードで確認したところ、Privoxy内のスレッドIDを出力している様でした。
後、URL部分はログの種類によってスキーマ(http:)を含んでいたり、居なかったりでここもちょっとパース処理がめんどくさそうです。
とりあえずDB(MySQLを使いました。postgresとかSQLiteとかでも良いです)のスキーマは下記に決定。
mysql> desc privoxylog; +-----------+--------------+------+-----+---------+----------------+ | Field | Type | Null | Key | Default | Extra | +-----------+--------------+------+-----+---------+----------------+ | seqno | int(11) | NO | PRI | NULL | auto_increment | | time | datetime | YES | | NULL | | | operation | varchar(9) | YES | | NULL | | | netloc | varchar(128) | YES | | NULL | | +-----------+--------------+------+-----+---------+----------------+ 4 rows in set (0.01 sec)
seqnoはDBに登録する時に自動でインクリメントする整数のID。timeはログに記録された日付時刻から秒未満の部分を削除した値。
operationはログの種類で、「request」「block」「dns_error」という3種類の文字列を上記のログの種類に応じて入れる事にしました。
netlocはURL。http:等のスキーマは削除。またサイト内の相対パスも削除です。
で、このスキーマに合わせて先ほどのログをMySQLに書き込むpythonスクリプトがこちら。
#!/usr/bin/env python
# -*- coding: utf-8 -*-
import signal
import sys
from urllib.parse import urlparse
import mysql.connector
PRIV_LOG = 'privoxy.log' # 解析するログファイル名
DB_HOST = 'localhost'
DB_USER = 'metabase' # MySQLに接続する際のユーザー名
DB_PW = 'PASSWORD' # MySQLに接続する際のパスワード(左記はダミーです)
DB_NAME = 'metabasedb' # MySQL上のDB名
#def do_exit(sig, stack):
# print('You pressed Ctrl+C.')
# print('Stop running the job.')
# sys.exit(0)
if __name__ == '__main__':
# signal.signal(signal.SIGINT, do_exit)
with open(PRIV_LOG, mode='r') as file:
config = { 'user':DB_USER,'password':DB_PW,'host':DB_HOST,'database':DB_NAME }
cnx = mysql.connector.connect(**config)
cursor = cnx.cursor()
seq = 0
for line in file:
args = line[:-1].split()
if len(args) != 0:
op = 'unknown'
urlsrc = ''
dt = args[0]
tm = args[1][:-4]
id = args[2]
if args[3] == 'Request:':
op = 'request'
urlsrc = args[4]
o = urlparse('http://'+urlsrc)
url = o.netloc
elif args[3] == 'Crunch:':
if args[4] == 'DNS':
op = 'dns_error'
urlsrc = args[6]
o = urlparse(urlsrc)
url = o.netloc
elif args[4] == 'Blocked:':
op = 'block'
urlsrc = args[5]
if urlsrc.startswith('http:'):
o = urlparse(urlsrc)
url = o.netloc
else:
url = urlsrc
print(seq,dt,tm,op,url)
if len(url) > 128:
url = url[0:128]
stmt = "INSERT INTO privoxylog (seqno,time,operation,netloc) VALUES (null,%s,%s,%s)"
cursor.execute(stmt,(dt+' '+tm,op,url))
seq += 1
cursor.execute('COMMIT') # MySQL側をautocommitに設定していても必要みたい(深く検証していない)
cursor.close()
cnx.close()
これでMySQLに書き込んだ後、Metabaseを起動してDBを読み込ませたら、Privoxyのログの可視化が出来ました。
時系列でのアクセス頻度や、request/block/dns_errorの割合とか、アクセス先URLの頻度順の円グラフとか色々作れます。
とりあえず、Metabaseで上記のDBを読んだ直後の表示がこんな感じです。
以前に仕事でExcelデータからこの手のグラフ作った時はピボット駆使して集計して、それをグラフ化してとか大変でしたが、DBにデータを放り込む仕組みだけ作っておけば統計情報可視化はとっても楽そうです。
まあ、運用監視とかだとZabbixとか、それ用に特化したものがあるので、そちらを使えば良いのですが。IoTのPoCとかで簡易にやりたいならMetabase良いかも。
