プログラムローカルで実行し動作を確認する時、そのプログラムの出力するログがJSONでフォーマットされたログを出力する事がある。ログの出力形式は設定で変更できる事が多いが、プログラム毎に異なる設定を毎度調べる事に疲れてしまった。賽の河原で石を積んでいる気分になる。まだ積み足りないのだろうか。もう疲れてしまった。だから、外側から出力されるJSONを整形するようにしようと思う。
そういった時に使えるのはjqコマンドだろう。jqコマンドは、標準入力からJSONを受け取り、そのデータを加工して標準出力に出力できる。連続してJSONが流れてくるようなデータもパイプを使用してjqに渡す事で1行ずつ解析と加工ができる。
例として取り上げるログは、JSONでフォーマットされたログであり、各行はmessage, level, timestampの3つの属性を常に持っている事とする。また3行目のmessageには改行文字が含まれている。
{"message": "test one!", "level": "info", "timestamp": "2023-03-17T03:14:52.224343Z"}
{"message": "test two!", "level": "warning", "timestamp": "2023-03-17T03:14:52.224343Z"}
{"message": "test three!\nok", "level": "error", "timestamp": "2023-03-17T03:14:52.224343Z"}
{"message": "test four!", "level": "critical", "timestamp": "2023-03-17T03:14:52.224343Z"}
この形式は実際に存在するプログラムとしても、細かくは違うだろうけれど似た形式のログを出力しているのを見る。やり方の雰囲気さえ理解できれば、動作をカスタマイズする事は、それほど難しくない。jqの記法についてはjqの公式ドキュメントを見ると良い。
今回はこのログを出力するテスト用のスクリプトを記述する。出力は上記のログを1行ずつ1秒おきに標準出力に出力する。
echo '{"message": "test one!", "level": "info", "timestamp": "2023-03-17T03:14:52.224343Z"}'
sleep 1
echo '{"message": "test two!", "level": "warning", "timestamp": "2023-03-17T03:14:52.224343Z"}'
sleep 1
echo "{\"message\": \"test three!\\nok\", \"level\": \"error\", \"timestamp\": \"2023-03-17T03:14:52.224343Z\"}"
sleep 1
echo '{"message": "test four!", "level": "critical", "timestamp": "2023-03-17T03:14:52.224343Z"}'outputlog.sh
では、このスクリプトの出力をjqにパイプで渡す。
bash outputlog.sh | jq
{
"message": "test one!",
"level": "info",
"timestamp": "2023-03-17T03:14:52.224343Z"
}
{
"message": "test two!",
"level": "warning",
"timestamp": "2023-03-17T03:14:52.224343Z"
}
{
"message": "test three!\nok",
"level": "error",
"timestamp": "2023-03-17T03:14:52.224343Z"
}
{
"message": "test four!",
"level": "critical",
"timestamp": "2023-03-17T03:14:52.224343Z"
}
JSONが少し整形されている。
次にmessage属性のみ標準出力に出力する。
bash outputlog.sh | jq -r '.message'test one! test two! test three! ok test four!
-r がないとダブルクォートで括られた文字列として表示されてしまい、例えば改行文字がエスケープされた状態で出力される。それではJSONをそのまま出力しているのとあまり違いがない。改行はエスケープされず改行されて欲しい。そのため -r を指定し、出力を生の文字列(raw string)として扱うようにしている。
これでログのメッセージを出力できた。ただし、ログレベルも同時に確認したい。jqでは()を使うことで、同じレベルに位置する属性も扱うことができる。そこでlevel属性とmessage属性を両方出力するようにし、ついでにタブ文字で区切るようにする。
bash outputlog.sh | jq -r '(.level) + "\t" + (.message) 'info test one! warning test two! error test three! ok critical test four!
() を使いlevel属性とmessage属性を両方取得し、 + を使い文字列結合している。ただし、なんだかlevelの文字列が8文字以上あるものがあり、少しだけ表示が崩れてしまう。ではlevelの文字列を半角空白で10文字分だけ左パディングする。
bash outputlog.sh | jq -r '(.level | (" " * (10 - length)) + .) + "\t" + (.message)'
info test one!
warning test two!
error test three!
ok
critical test four!
かなりログが見やすくなった。
毎回、この記述をコマンドの最後に付けるのは面倒なので、bashのエイリアスとして定義することにした。
alias prettylog="jq -r '(.level | (\" \" * (10 - length)) + .) + \"\t\" + (.message)'"
$ bash outputlog.sh | prettylog
info test one!
warning test two!
error test three!
ok
critical test four!
悪くはないけれど、もう少し複雑にしようとすると、エスケープシーケンスお化けが誕生して、1週間後には意味がわからない状態になってしまいそうな予感がする。エイリアスにはせず、スクリプトとして記述してしまう方が良さそうだ。execコマンドを使って、jqを呼び出すようにする。
#! /usr/bin/env bash
exec jq -r '(.level | (" " * (10 - length)) + .) + "\t" + (.message)'prettylog
実行する。
$ bash outputlog.sh | bash ./prettylog
info test one!
warning test two!
error test three!
ok
critical test four!
このprettylogに実行権限を与え、パスの通った場所に置いておけばよさそうだ。しばらくはこれを使おうと思う。
https://github.com/TakesxiSximada/emacs.d/blob/main/bin/prettylog に置いておく。