1. いきさつ
ログ出力のための print と import logging はやめてほしい - Qiita
私も「うーん、なるほどなぁ」と思いながら読んでいました。
しかし、同時にこう思いました。
じゃあ、loggingってどうやって書けばいいんだろう？
タダでさえPythonのlogging苦手で時間かかるのにloggerとか無理!!
ということで、この記事を書くことにしました。
目的としては以下の通りです。
- 必死になってloggerと向き合った結果見つけた自分なりの理解を共有したい
- みんながPythonでアプリ作るときにloggingに悩んで時間を無駄にしないでほしい
2. 結局、なんでloggingを使っちゃいけないの！？
公式ドキュメントと上のQiitaの記事を読んだ見解です。
loggingは階層構造になっています。
└── rootLogger
├── scanLogger
│ ├── scanLogger.txt
│ ├── scanLogger.html
│ └── scanLogger.pdf
└── anotherLogger
rootLoggerというloggerを親として、子のloggerを複数持っている（もしくは作られる）わけです。
たとえば...
-
urllibというmoduleはurllibというloggerを利用 -
apscheduler.schedulerというmoduleはapscheduler.schedulerというloggerを利用
これらのパッケージやアプリごとのloggerの元締めが rootLogger です。
import logging
logging.info("Taking log...")
とすることは、 rootLogger を直接いじることと同義なのでやめましょうということです。
class をいじるのではなく、 instanceをいじりましょうという概念と似ていますね。
3. loggingのサンプル
公式ドキュメントを見ても、サンプルを見ても書き方がイマイチわからないんですよね...汗
どこまで固定文言で、どこまで自分で変えていいのか。（自分で命名できる範囲）
というわけで、動作確認をしている構成を提示してしまいます。
困った時はコピペして使ってみてください。
なるべく、皆さんがカスタマイズしやすいようにコメントで解説も入れておきます。
3-1. (Pattern.1) Configファイルを利用
3-1-1. 実行環境
loggingのconfigファイルをtomlで書いています。
pip install tomlでtomlパッケージ参考になります。
yamlでの表記方法はこちら。
$ tree
.
├── app
│ ├── logger
│ │ ├── __init__.py
│ │ └── logger.py
│ ├── logging.config.toml
│ └── main.py
└── log
├── application.log
└── error.log
$ cd app/
$ python app.py # app/ディレクトリでこのコマンドを実行することが前提でサンプルを書いています
3-1-2. ファイル
Github サンプルコードも置いておきます。
# 前のloggerはディレクトリ。後ろのloggerはファイル。
from logger.logger import get_logger
logger = get_logger()
def main():
logger.info("start = main()")
# do something
logger.error("oops! something wrong!!")
# do something
logger.info("end = main()")
if __name__ == "__main__":
main()
logging.config.toml はconsole画面とfileにログを出力するように設定しています。
version = 1
disable_existing_loggers = false # 他のmoduleのloggerを無効にしないようにする
[formatters]
[formatters.basic]
# logのフォーマットを設定。書き方の詳細は後述
format = "%(asctime)s [%(name)s][%(levelname)s] %(message)s (%(filename)s:%(module)s:%(funcName)s:%(lineno)d)"
datefmt = "%Y-%m-%d %H:%M:%S"
[handlers]
[handlers.console]
# ここでconsole出力の設定
class = "logging.StreamHandler" # 固定文言
level = "DEBUG" # log level はお好みで
formatter = "basic" # formattersに記載しているlogフォーマットを選択
stream = "ext://sys.stdout" # 固定文言
[handlers.file]
class = "logging.handlers.TimedRotatingFileHandler" # 固定文言。TimeRotatingFileHandlerの詳細は後述。注意点あり
formatter = "basic"
filename = "../log/application.log" # 相対pathで指定するなら $ python を実行するディレクトリから書く
when = 'D' # logファイルを切り替えるタイミングの単位。D = day。
interval = 1 # 上でdayを選択しているので1日ごとに新規ファイル。
backupCount = 31 # 上でdayを選択しているので31日分のlogファイルを保持
[handlers.error]
class = "logging.handlers.TimedRotatingFileHandler"
level = "ERROR"
formatter = "basic"
filename = "../log/error.log"
when = 'D'
interval = 1
backupCount = 31
[loggers]
[loggers.app_name] # app_nameはpythonから呼び出すloggerの名称。任意で命名
level = "INFO"
handlers = [
"console",
"file",
"error",
] # 上で設定したhandlerのどれを使うかを設定
propagate = false
[root]
level = "INFO"
handlers = [
"console",
"file",
"error"
] # loggerの親玉rootLoggerの設定。rootLoggerもconsoleとfileに残したい
from . import logger
logger.init_logger('logging.config.toml', 'app_name')
# 第一引数: configfile = configファイルの名称。pythonコマンドで実行するディレクトリの相対path or 絶対path
# 第二引数: loggername = configファイルで設定したloggerの名称
import os
import toml
from logging import getLogger
from logging.config import dictConfig
CONFIGFILE = "logging.config.toml" # global変数として扱う。デフォルト値を左のようにしている。任意
LOGGERNAME = "root" # global変数として扱う。デフォルト値をrootにしている。任意
def init_logger(configfile, loggername):
global CONFIGFILE
global LOGGERNAME
CONFIGFILE = configfile
LOGGERNAME = loggername
dictConfig(toml.load(CONFIGFILE))
def get_logger():
return getLogger(LOGGERNAME)
3-2. (Pattern.2) Pythonのdictを利用
Configファイルでのloggingと比べて、これちは柔軟性が高いです。
Configファイルでは親ディレクトリを ../ としていてOS依存が強くなります。
pythonのdictで設定すれば、 os.path.pardir で指定できます。
3-2-1. 実行環境
$ tree
.
├── app
│ ├── logger
│ │ ├── __init__.py
│ │ └── logger.py
│ └── main.py
└── log
├── application.log
└── error.log
$ cd app/
$ python main.py
3-2-2. ファイル
Github サンプルコードも置いておきます。
main.py は上のmain.pyと同じです。
また、CONFIG の内容も上記の logging.config.toml と同じ内容です。
from . import logger
logger.init_logger()
import os
from logging import getLogger
from logging.config import dictConfig
APP_NAME = os.getenv('APP_NAME', default='app_name')
CONFIG = {
'version': 1,
'disable_existing_loggers': False,
'formatters': {
'basic': {
'format': '%(asctime)s [%(name)s][%(levelname)s] %(message)s (%(module)s:%(filename)s:%(funcName)s:%(lineno)d)',
'datefmt': '%Y-%m-%d %H:%M:%S'
}
},
'handlers': {
'console': {
'class': 'logging.StreamHandler',
'level': 'DEBUG',
'formatter': 'basic',
'stream': 'ext://sys.stdout'
},
'file': {
'class': 'logging.handlers.TimedRotatingFileHandler',
'formatter': 'basic',
'filename': os.path.join(os.path.pardir, 'log', 'application.log'),
'when': 'D',
'interval': 1,
'backupCount': 31
},
'error': {
'class': 'logging.handlers.TimedRotatingFileHandler',
'level': 'ERROR',
'formatter': 'basic',
'filename': os.path.join(os.path.pardir, 'log', 'error.log'),
'when': 'D',
'interval': 1,
'backupCount': 31
}
},
'loggers': {
APP_NAME: {
'level': 'INFO',
'handlers': [
'console',
'file',
'error'
],
'propagate': False
}
},
'root': {
'level': 'INFO',
'handlers': [
'console',
'file',
'error'
]
}
}
def init_logger():
dictConfig(CONFIG)
def get_logger():
return getLogger(APP_NAME)
3-3. 実行結果
Pattern 1. でも Pattern 2. でも出力のフォーマットは同じです。
[app_name] はlogger名。
$ cd app/
$ python main.py
2019-12-21 15:43:28 [app_name][INFO] start = main() (main:main.py:main:8)
2019-12-21 15:43:28 [app_name][ERROR] oops! something wrong!! (main:main.py:main:10)
2019-12-21 15:43:28 [app_name][INFO] end = main() (main:main.py:main:12)
$ cat ../log/application.log
2019-12-21 15:43:28 [app_name][INFO] start = main() (main:main.py:main:8)
2019-12-21 15:43:28 [app_name][ERROR] oops! something wrong!! (main:main.py:main:10)
2019-12-21 15:43:28 [app_name][INFO] end = main() (main:main.py:main:12)
$ cat ../log/error.log
2019-12-21 15:43:28 [app_name][ERROR] oops! something wrong!! (main:main.py:main:10)
3-4. ちょっと解説
3-4-1. TimedRotatingFileHandler
公式ドキュメントのTimedRotatingFileHandlerに「interval や when に何が設定できるか？」が書かれています！
設定した時間で新しいファイルにlogを出力します。
上記の例では 'D' つまり日毎にファイルを書き換えます。
過去のログファイルはファイル名に application.log.2019-12-21 のように日付のsurfixがつきます。
注意！
app.py が1日中起動しないようなアプリケーションでは TimedRotatingFileHandler は機能しません。
DjangoやFlaskのようなWebアプリでは有効ですが、cronなどでは正常に動作しない場合があります。
3-4-2. Format
公式ドキュメントのLogRecord 属性 に各フォーマットの一覧があります。
自分なりに必要な項目をアレンジしてみましょう！
4. まとめ (Takeaways)
loggingの作り方を2種類紹介しました！それぞれを振り返りましょう！
（もう完璧という方は読み飛ばしてOK!!）
ちなみに、Takeawaysは「ポイント、要点」という意味です。
take away = 持ち帰る → 今日のプレゼンでこれだけは持ち帰ってくれ！ といったニュアンスですね。
4-1. import logging がダメな理由
logger は rootLogger を親として、いくつも生成されている。
rootLogger → Class、 logger → instance のようなイメージ。
logging.info() はrootLoggerを直接いじることになるので、独自にloggerを作成してあげましょう。
4-2. サンプルファイル
じゃあ、具体的にどうやって作るの？
4-3. 注意点
-
disable_existing_loggers = Falseにしなければgunicornのloggerが壊れる - Configファイルを作る場合
- 相対パスのOS依存性に注意
- logフォルダの相対パスは
$ pythonを実行するディレクトリから
-
TimedRotatingFileHandler- intervalに対してプログラムの実行時間が短いと意味がない
- Django や Flask などのWebアプリ向け
5. さいごに
loggingの書き方は一概にこれが正しいというのは無いと思います。
pythonファイルに addHandler でhandlerを追加する方法もあります。
みなさんのオススメのloggingの設定方法をご教示いただけるとありがたい限りです。