正規表現を使ってログをカジュアルに構造化ログ/データに変換するツールlrepを作った

tl;dr

Fluentdのregexp parser pluginCLI版っぽいツールを作りました(個人的に一番伝わりやすい言い方だと思っている)。

構造化されていないログを分析するとき面倒問題

最近のログは最初からJSONやLTSVなどの構造化ログになっていたり、Fluentdなどで構造化データに変換されたうえでRDBやElasticsearch、BigQueryなどに収集されていたりすることが多くなってきていると思います。

ログの分析をしたいとき、RDBに保存されているのであればSQLが便利です。

また、構造化ログにさえなっていればtrdsqlgo-jsqliteなど、構造化ログに対してSQLクエリを実行する手段はあります。保存先がS3なのであればS3 Selectを利用することもできます。

じゃあ、構造化されていない、いわゆる生ログの分析はどうすればいいかというと、

  1. (簡単な分析であれば)UNIXコマンドなど(awkとかsedとかsortとかwcとか)を駆使するか
  2. 分析したいことに合わせて生ログを必要最低限の構造化データに変換するか

だと思います。

世の中のログを触る人々は、どちらもやった経験がありそうな気がしてなりません。

そしてどちらもちょっと面倒です*1

なので今回、私は「2. 分析したいことに合わせて生ログを必要最低限の構造化データに変換する」を簡単にするためにlrepというツールを作りました。

github.com

lrep

lrepは、正規表現のキャプチャグループ(( ) で囲まれた部分正規表現にマッチした値を参照できる機能 )でマッチした値を構造化データのフィールドとして、ログを構造化ログ/データに変換するツールです。

例えば Common Log FormatApacheアクセスログの場合、以下のような正規表現で構造化ログに変換できます。

$ tail -F /var/log/access.log | lrep '^(\S*) \S* \S* \[(.*)\] "(.*)" (\S*) (\S*)'
{"_raw":"100.21.169.226 - - [25/Jul/2020:16:25:05 +0900] \"GET /category/electronics HTTP/1.1\" 200 114","m0":"100.21.169.226 - - [25/Jul/2020:16:25:05 +0900] \"GET /category/electronics HTTP/1.1\" 200 1\
14","m1":"100.21.169.226","m2":"25/Jul/2020:16:25:05 +0900","m3":"GET /category/electronics HTTP/1.1","m4":"200","m5":"114"}
{"_raw":"104.141.81.229 - - [25/Jul/2020:16:25:05 +0900] \"GET /item/office/1680 HTTP/1.1\" 200 49","m0":"104.141.81.229 - - [25/Jul/2020:16:25:05 +0900] \"GET /item/office/1680 HTTP/1.1\" 200 49","m1":"\
104.141.81.229","m2":"25/Jul/2020:16:25:05 +0900","m3":"GET /item/office/1680 HTTP/1.1","m4":"200","m5":"49"}
{"_raw":"132.189.225.189 - - [25/Jul/2020:16:25:05 +0900] \"GET /category/office HTTP/1.1\" 200 97","m0":"132.189.225.189 - - [25/Jul/2020:16:25:05 +0900] \"GET /category/office HTTP/1.1\" 200 97","m1":"\
132.189.225.189","m2":"25/Jul/2020:16:25:05 +0900","m3":"GET /category/office HTTP/1.1","m4":"200","m5":"97"}
[...]

部分正規表現を含めそれぞれ一致した箇所が、自動でそれぞれ以下のようなフィールド名になります。

フィールド名 説明
m0 一致全体
m1 部分一致1番目
m2 部分一致2番目
... ...
_raw (デフォルト) 元の生ログ

また、名前付きキャプチャグループも利用してフィールド名を明示的に指定することも可能ですし、利用側として意図的ではない m0 (一致全体)や _raw (元の生ログ)のフィールドを除外することもできます。

$ tail -f /var/log/access.log | lrep --no-m0 --no-raw '^(?P<host>\S*) \S* \S* \[(?P<time>.*)\] "(?P<request>.*)" (?P<status>\S*) (?P<bytes>\S*)'
{"bytes":"118","host":"100.39.167.131","request":"GET /category/toys HTTP/1.1","status":"200","time":"25/Jul/2020:17:46:26 +0900"}
{"bytes":"70","host":"36.30.101.105","request":"GET /item/electronics/1293 HTTP/1.1","status":"200","time":"25/Jul/2020:17:46:26 +0900"}
{"bytes":"123","host":"212.87.25.78","request":"GET /category/software HTTP/1.1","status":"200","time":"25/Jul/2020:17:46:26 +0900"}
{"bytes":"76","host":"84.189.195.199","request":"GET /category/office HTTP/1.1","status":"200","time":"25/Jul/2020:17:46:27 +0900"}
{"bytes":"103","host":"164.78.219.152","request":"GET /item/electronics/1175 HTTP/1.1","status":"200","time":"25/Jul/2020:17:46:28 +0900"}
[...]

サポートしているフォーマット

JSON、LTSVといった一般的な構造化ログフォーマットに加えてSQLite用のクエリがあります(これが一番作りたかった)。

-t sqlite を指定するとDDLも含めたSQLite用クエリに変換できます。

$ tail -f /var/log/access.log | lrep -t sqlite --no-m0 '^(?P<host>\S*) \S* \S* \[(?P<time>.*)\] "(?P<request>.*)" (?P<status>\S*) (?P<bytes>\S*)'
CREATE TABLE IF NOT EXISTS lines (
  id INTEGER PRIMARY KEY AUTOINCREMENT,
  host TEXT,
  time TEXT,
  request TEXT,
  status TEXT,
  bytes TEXT,
  _raw TEXT,
  created NUMERIC NOT NULL
);
INSERT INTO lines(host, time, request, status, bytes, _raw, created) VALUES ('224.51.78.136', '25/Jul/2020:17:51:24 +0900', 'GET /category/books HTTP/1.1', '200', '130', '224.51.78.136 - - [25/Jul/2020:1\
7:51:24 +0900] "GET /category/books HTTP/1.1" 200 130', datetime('now'));
INSERT INTO lines(host, time, request, status, bytes, _raw, created) VALUES ('152.114.184.75', '25/Jul/2020:17:51:25 +0900', 'GET /category/finance HTTP/1.1', '200', '56', '152.114.184.75 - - [25/Jul/202\
0:17:51:25 +0900] "GET /category/finance HTTP/1.1" 200 56', datetime('now'));
INSERT INTO lines(host, time, request, status, bytes, _raw, created) VALUES ('168.57.224.190', '25/Jul/2020:17:51:25 +0900', 'GET /category/games?from=10 HTTP/1.1', '200', '60', '168.57.224.190 - - [25/J\
ul/2020:17:51:25 +0900] "GET /category/games?from=10 HTTP/1.1" 200 60', datetime('now'));
[...]

この形式の一番良いところろはパイプでダイレクトに sqlite3 コマンドに渡してSQLiteファイルを作成できることです。

$ cat /var/log/access.log | lrep -t sqlite --common | sqlite3 lines.db
$ sqlite3 lines.db
SQLite version 3.32.3 2020-06-18 14:00:33
Enter ".help" for usage hints.
sqlite> .tables
lines
sqlite> SELECT * FROM lines LIMIT 5;
1|200.159.42.212|27/Jul/2020:06:56:18 +0900|GET /item/music/1294 HTTP/1.1|200|112|200.159.42.212 - - [27/Jul/2020:06:56:18 +0900] "GET /item/music/1294 HTTP/1.1" 200 112|2020-07-26 21:56:18
2|68.54.151.135|27/Jul/2020:06:56:18 +0900|GET /item/electronics/3894 HTTP/1.1|200|96|68.54.151.135 - - [27/Jul/2020:06:56:18 +0900] "GET /item/electronics/3894 HTTP/1.1" 200 96|2020-07-26 21:56:18
3|84.93.121.21|27/Jul/2020:06:56:18 +0900|GET /category/software HTTP/1.1|200|126|84.93.121.21 - - [27/Jul/2020:06:56:18 +0900] "GET /category/software HTTP/1.1" 200 126|2020-07-26 21:56:18
4|176.36.75.163|27/Jul/2020:06:56:18 +0900|GET /category/garden HTTP/1.1|200|113|176.36.75.163 - - [27/Jul/2020:06:56:18 +0900] "GET /category/garden HTTP/1.1" 200 113|2020-07-26 21:56:18
5|40.60.150.212|27/Jul/2020:06:56:18 +0900|GET /category/games HTTP/1.1|200|75|40.60.150.212 - - [27/Jul/2020:06:56:18 +0900] "GET /category/games HTTP/1.1" 200 75|2020-07-26 21:56:18
sqlite>

ログにSQLで分析が捗ります。

ビルトイン正規表現

上記コマンドで使った --common はビルトインの正規表現です。

ビルトインの正規表現lrep builtin で確認できます。

$ lrep builtin
common       Common Log Format
combined     Combined Log Format
postgresql   PostgreSQL log
$ lrep builtin common
NAME
       common -- Common Log Format

REGEXP
       ^(?P<host>\S*) (?P<ident>\S*) (?P<user>\S*) \[(?P<time>.*)\] "(?P<method>\S+)(?: +(?P<resource>\S*) +(?P<proto>\S*?))?" (?P<status>\S*) (?P<bytes>\S*)

SAMPLE
       152.120.218.99 - - [25/Jul/2020:12:25:54 +0900] "GET /category/books HTTP/1.1" 200 67

現在はたったの3つだけですが、MySQLのログフォーマットなどを追加するなど継続して整備したいです。

今後など

今後実装していきたいこととして

  • ビルトイン正規表現をいざという時に備えて増やしておきたい
  • 時刻表現だけ特別扱いしたい(時刻としてパースしたい)

などを考えています。

是非使ってみてください。また、(特にビルトイン正規表現の)Pull Requestお待ちしています。

ところで、lrep、どこかでみたことのあるツールな気がしているんですよね。。

*1:「じゃあ最初から構造化データにしとけ」となるのですが対象のミドルウェアにはその機能がなかったり、Fluentdで捌くにもそれはそれでコンピューティングリソースを消費するし、毎回分析するようなログじゃない場合いろいろ億劫になりますよね...。そしてまた分析が必要な場面が訪れるというループ...