loguruを使ってロギングをしてみよう
https://gyazo.com/5fc730665c1e21e73c142efdc23cb0df
Loguru について
python 標準ライブラリ の logging はよくできていますが、ログ設定ではいくつかの手続きをしなければいけないため、すこし煩雑になりがちです。
これに対して、loguru は驚くほど簡単にロギングできる拡張モジュールで、
デバッグライトとして使用したいときにも適用することができます。
インストール
loguru は拡張モジュールなので次のようにインストールします。
code: bash pipの場合
$ pip install loguru
loguru の使い方
単純な使い方では次のように loguru をインポートするだけです。
code: python
from loguru import logger
logger.debug("That's it, beautiful and simple logging!")
デフォルトの状態ではログは標準出力にも表示されます。
これを抑制したいときは logger.remove() を呼び出しておきます。
code: python
from loguru import logger
logger.remove()
Pythonの標準ライブラリ logging にある Handler, Formatter, Filter のような設定についての個別の関数がなく、すべてをadd()で処理することができます。
code: Python
logger.add(sys.stderr,
format="{time} {level} {message}",
filter="my_module", level="INFO")
フォーマット
format = "{time} {message}" のように、時間フォーマット指定子が使用されていない場合、デフォルトではISO 8601が使用されます。
table: 時間フォーマット指定子
識別子 出力例
年 YYYY 2000, 2001, 2002 … 2012, 2013
YY 00, 01, 02 … 12, 13
クォーター Q 1, 2, 3, 4
月 MMMM January, February, March …
MMM Jan, Feb, Mar …
MM 01, 02, 03 … 11, 12
M 1, 2, 3 … 11, 12
年内の日 DDDD 001, 002, 003 … 364, 365
DDD 1, 2, 3 … 364, 365
月内の日 DD 01, 02, 03 … 30, 31
D 1, 2, 3 … 30, 31
週内の日 dddd Monday, Tuesday, Wednesday …
ddd Mon, Tue, Wed …
d 0, 1, 2 … 6
週内の日（ISO) E 1, 2, 3 … 7
時 HH 00, 01, 02 … 23, 24
H 0, 1, 2 … 23, 24
hh 01, 02, 03 … 11, 12
h 1, 2, 3 … 11, 12
分 mm 00, 01, 02 … 58, 59
m 0, 1, 2 … 58, 59
秒 ss 00, 01, 02 … 58, 59
s 0, 1, 2 … 58, 59
秒の小数部 S 0 1 … 8 9
SS 00, 01, 02 … 98, 99
SSS 000 001 … 998 999
SSSSSS 000000 000001 … 999998 999999
AM / PM A AM, PM
Timezone Z -07:00, -06:00 … +06:00, +07:00
ZZ -0700, -0600 … +0600, +0700
zz EST CST … MST PST
タイムスタンプ（秒） X 1381685817, 1234567890.123
タイムスタンプ（マイクロ秒) x 1234567890123
ログローテーション
ログファイルのローテーションもadd() で簡単に設定できます。
code: pyton
logger.add(filepath, rotation="500MB")
add() のローテーション関連の引数の指定例
filepath： file_{time}.log のように指定すると日時がファイル名に使われます。
rotation="500MB"：500MB ごとに新しいファイルを作成
rotation="12:00"：毎日12:00に新しいファイルを作成
rotation="1 week"： １週間ごとにローテーションを行う
rotation="10 days"： 10日ごとにローテーションを行う
compression="zip"：ログファイルの圧縮を行う
"gz", "bz2", "xz", "lzma", "tar", "tar.gz", "tar.bz2", "tar.xz", "zip" が指定可能
カラー表示
コンソールにログ出力するとき、カラーを指定することができます。
code: python
logger.add(sys.stdout,
colorize=True,
format="<green>{time}</green> <level>{message}</level>")
table: カラーとスタイル
カラー (短縮形) スタイル (短縮形)
Black (k) Bold (b)
Blue (e) Dim (d)
Cyan (c) Normal (n)
Green (g) Italic (i)
Magenta (m) Underline (u)
Red (r) Strike (s)
White (w) Reverse (v)
Yellow (y) Blink (l)
Hide (h)
カラーは小文字で指定すると前景色（文字の色）、大文字で指定すると背景色になります。
他にも次の書式で色指定ができます。
table: 色指定
タイプ 前景色 背景色
基本色 <red> <RED>
<r> <R>
淡色 <light-blue> <LIGHT_BLUE>
<lb> <LB>
8ビット指定 <fg 86> <bg 42>
<fg 255> <bg 9>
RGB指定 <fg 0,95,0> <bg 72,119,65>
環境変数の参照
add()の引数のデフォルト値は、環境変数LOGURU_引数名 を設定することで変更できます。
Linuxでの設定例：
code: bash
export LOGURU_FORMAT="{time}-{message}"
ログレベルのデフォルトは、環境変数 LOGURU_レベル_アトリビュート を設定して変更することもできます。
Windowsでの設定例：
code: powershell
setx LOGURU_DEBUG_COLOR "<blue>"
Windowsでアイコンを設定する例：
code: powershe;l
setx LOGURU_TRACE_ICON "🚀"。
setコマンドを使用するときは、引用符を含めずに特殊記号をエスケープします。
code: powershell
LOGURU_DEBUG_COLOR = ^ <blue ^>
例外の捕獲
プログラムで例外が発生するとログファイルに何も表示されずに異常終了することがあります。loguru はエラーがロガーに正しく伝搬されることを保証するデコレータcatch() が提供されています。
code: python
@logger.catch
def my_function(x, y, z):
return 1 / (x + y + z)
loguruは、変数の値を含むスタックトレース全体をログできるので、デバッグ時に便利です。
code: test.py
logger.add("output.log", backtrace=True, diagnose=True)
def func(a, b):
return a / b
def nested(c):
try:
func(5, c)
except ZeroDivisionError:
logger.exception("What?!")
nested(0)
このコードは次のようなログを記録します。
code: output.log
2018-07-17 01:38:43.975 | ERROR | __main__:nested:10 - What?!
Traceback (most recent call last):
File "test.py", line 12, in <module>
nested(0)
└ <function nested at 0x7f5c755322f0>
File "test.py", line 8, in nested
func(5, c)
│ └ 0
└ <function func at 0x7f5c79fc2e18>
File "test.py", line 4, in func
return a / b
│ └ 0
└ 5
ZeroDivisionError: division by zero
ログ出力の分離
ログを出力するとき、状況によっては特定のメッセージを特定のハンドラーに記録すると便利な場合があります。たとえば、ログを任意の識別子に基づいて2つのファイルに分割したい場合、bind() とフィルターを組み合わせることでそれを実現できます。
code: python
from loguru import logger
def do_something():
pass
def do_something_else():
pass
def task_A():
logger_a = logger.bind(task="A")
logger_a.info("Starting task A")
do_something()
logger_a.success("End of task A")
def task_B():
logger_b = logger.bind(task="B")
logger_b.info("Starting task B")
do_something_else()
logger_b.success("End of task B")
logger.add("file_A.log",
logger.add("file_B.log",
task_A()
task_B()
code: bash
$ python loguru_separate.py
2020-04-26 15:07:12.003 | INFO | __main__:task_A:10 - Starting task A
2020-04-26 15:07:12.003 | SUCCESS | __main__:task_A:12 - End of task A
2020-04-26 15:07:12.003 | INFO | __main__:task_B:16 - Starting task B
2020-04-26 15:07:12.004 | SUCCESS | __main__:task_B:18 - End of task B
file_A.logには関数task_A() のログとfile_B.log には、関数task_B()のログのみが含まれます。
こうした分離されたログを多数設定してしまうと、それぞれのハンドラーのフィルターによってログをチェックされるため、アプリケーションのパフォーマンスが低下する可能性があります。
こうしたときは、copy モジュールの deepcopy() を使って、独立した loggerオブジェクトを作成するようにします。
code: python
import copy
from loguru import logger
def do_something(id):
pass
def task(task_id, logger):
logger.info("Starting task {}", task_id)
do_something(task_id)
logger.success("End of task {}", task_id)
logger.remove()
logger_ = copy.deepcopy(logger)
logger_.add("file_%s.log" % task_id)
task(task_id, logger_)
tqdm と連携したプログレスバー
tqdmライブラリーによってラップされた反復処理の中で loguruの loggerを使用しようとすると、表示されるプログレスバーが乱れる場合があります。
回避策として、sys.stderr に直接ログを書き込む代わりに、tqdm.write()関数を使用できます。
code: python
import time
from loguru import logger
from tqdm import tqdm
logger.remove()
logger.add(tqdm.write)
logger.info("Initializing")
for x in tqdm(range(100)):
logger.info("Iterating #{}", x) time.sleep(1)
JSON形式でのログ出力
loguru は serialize引数を使用すると、ログメッセージはJSONフォーマットに変換されます。
code: loguru_serialize.py
rom loguru import logger
logger.add('/tmp/test.log', serialize=True)
logger.info("This is first log")
logger.info("This is second log")
code: bash
$ cat /tmp/test.log
{"text": "2020-11-19 11:03:21.775 | INFO | __main__:<module>:5 - This is first log\n", "record": {"elapsed": {"repr": "0:00:00.007473", "seconds": 0.007473}, "exception": null, "extra": {}, "file": {"name": "kk", "path": "kk"}, "function": "<module>", "level": {"icon": "\u2139\ufe0f", "name": "INFO", "no": 20}, "line": 5, "message": "This is first log", "module": "kk", "name": "__main__", "process": {"id": 57021, "name": "MainProcess"}, "thread": {"id": 4638453184, "name": "MainThread"}, "time": {"repr": "2020-11-19 11:03:21.775184+09:00", "timestamp": 1605751401.775184}}}
{"text": "2020-11-19 11:03:21.776 | INFO | __main__:<module>:6 - This is second log\n", "record": {"elapsed": {"repr": "0:00:00.009084", "seconds": 0.009084}, "exception": null, "extra": {}, "file": {"name": "kk", "path": "kk"}, "function": "<module>", "level": {"icon": "\u2139\ufe0f", "name": "INFO", "no": 20}, "line": 6, "message": "This is second log", "module": "kk", "name": "__main__", "process": {"id": 57021, "name": "MainProcess"}, "thread": {"id": 4638453184, "name": "MainThread"}, "time": {"repr": "2020-11-19 11:03:21.776795+09:00", "timestamp": 1605751401.776795}}}
JSON形式なのでログをパースするときは、json や pandas を使うことで簡単に処理することができます。また、 jq というJSONパーサーを使うと、特定のフィールドの値を簡単に取り出すことができます。 このjqコマンドは、Linux, Mac, Windows で使用することができます。
code: bash
% cat /tmp/test.log| jq ".record.message, .record.time"
"This is first log"
{
"repr": "2020-11-19 11:03:21.775184+09:00",
"timestamp": 1605751401.775184
}
"This is second log"
{
"repr": "2020-11-19 11:03:21.776795+09:00",
"timestamp": 1605751401.776795
}
まとめ
loguru はPythonの標準ライブラリ logging とは使用方法が異なりますが、add()でほとんどのことが設定できるため利用しやすく、学習コストが低いくなります。
参考: