Pythonで新しくプロジェクトを作ろうとした際、そういえばLoggerの設定や取り扱いってどうすればいいんだっけ？と思って調べてみたところ QiitaやZennだと様々な流儀のLoggingのやり方が書いてあって、結局どうすればいいのかがわからず調べたのでまとめました。
長い説明を読むのも大変だと思うのでまずは結論だけ書きます。
PythonのPackageを作成している場合はログを送出したい各モジュールの先頭部分で getLogger を呼んでLoggerオブジェクトをうけとり、
ログを送出したい部分で debug, info, warning, criticalなどの重要度を使い分けてログを出力しましょう。
from logging import getLogger
_logger = getLogger(__name__)
def greate_function():
_logger.info("Someting greate start!")
"""
すごい処理
"""
_logger.debug("this is debug message")
class GreateClass():
def __init__(self):
_logger.debug("Initializing GreateClass...")_loggerの先頭に_をつけているのはこのモジュールを外からimportしたときに_loggerオブジェクトは外から使用するものではないということを意味しています。
細かいことは考えず最初の 2 行だけ各ファイルに書いてログを出しましょう!
Python Packageのプロジェクトであればこれだけで十分です。
上の設定だけだと、Loggerに渡したメッセージをどのログレベルまで、どのような形で出力するかが定義されていないので ログの内容を出力して確認することができません。
サービスを作る場合やPython Interprinterから直接実行するスクリプト、cliツールを書いたりする場合は ログの出力方法の設定を行なってあげる必要があります。
特定のログレベル以上のログを標準エラー出力に出力するだけであればエントリーポイントに以下の設定を加えればよいです。
(ここでいうエントリーポイントとは直接実行するpythonスクリプトのことを指します。例えばflaskだとapp.pyやmain.pyという名前にすることが多いです)
from logging import DEBUG, basicConfig
# RootLoggerの出力設定
basicConfig(level=DEBUG, format='%(asctime)s - %(name)s - %(levelname)s - %(message)s')formatを指定しているのは時刻、モジュール名、ログレベルは表示しておいた方がトラブルシューティングの際便利だからです。
ここはプロジェクトの事情や好みの問題もあるので、便利なように設定しましょう。
直接実行しない、エントリーポイントに import して使うモジュールについては Package の時と同じくgetLoggerで_loggerを作ってログを送出しましょう。
Pythonのloggingを便利に使うための情報はほとんど上級ロギングチュートリアル で説明されています。
ここで説明されている流儀に従ってloggingを使用するのがPythonでLoggingをする際は最も楽な方法の一つだと思うのですが、なぜか一度読んだくらいでは結局どうすればいいのかが分かりません。
(少なくとも私はわからなかったです)
結論ではログの出し方はエントリーポイントに一度だけ書いて、他のモジュールではgetLoggerで_loggerオブジェクトを作ってその method を使えば多くの場合では十分だと書きました。
なぜこれで十分なのかを理解するには
を知っている必要があります。
名前空間階層構造について覚えておく必要があるのは以下の3点です。
rootを頂点とした名前空間階層構造を持つ.区切りの名前で表現される例えば次のような名前空間階層構造があったとして
root
├── aaa
│ ├── bbb
│ └── ccc
│ └── ddd
└── eeeaaa.ccc.dddやaaa.ccc、aaa.bbbはaaaの子であり、
そしてすべての名前はrootロガーの子になります。
getLoggerを使って
name = "aaa"
_logger = getLogger(name)_loggerを作ると毎回新しいオブジェクトを作っているような気がしますが同じ名前のLoggerは一つしかインスタンス化されません。
重要なのはloggingのコードのこの辺です。
root = RootLogger(WARNING)
Logger.root = root
Logger.manager = Manager(Logger.root)loggingモジュールはimportされた際にManagerクラスをインスタンスしてLoggerクラスのアトリビュートに追加しています。
getLogger(name)のように関数を呼び出すとManagerが持っている辞書オブジェクトを参照しnameのLoggerを持っていればそれを返し、
まだ辞書に存在しなければ新しくLoggerをインスタンス化して返すという仕組みになっています。
Loggerはpropagateというアトリビュートを持っているのですがこれがTrueの場合、Loggerに渡されたメッセージは親Loggerに伝搬します。
propagateはデフォルトでTrueになっているので
各モジュールで
from logging import getLogger
_logger = getLogger(__name__)で_loggerを作って使用すると、すべてのメッセージはRootLoggerに伝搬することになります。
これがログの出力の設定はエントリーポイントで一度やれば十分だった理由です。
下手にモジュール内部でpropagateをFalseにしたり、_logger.setLevel()でログレベルを設定してしまうとメッセージの親Loggerへの伝搬
が妨げられてしまいます。
どんなログをどのような形で出力するかはエントリーポイントかエントリーポイント付近で制御した方が柔軟にログを出力することができます。
ログの出力の方法はHandlerオブジェクトで指定します。 HandlerオブジェクトはLoggerにaddすることができ、 例えば以下のように StreamHandlerをLoggerにaddするとLoggerに流れてきたメッセージで条件にマッチするものが標準エラー出力に出力されます。
_logger = getLogger(__name__)
stream_handler = logging.StreamHandler()
_logger.addHandler(stream_handler)logging.handersが提供しているHandlerはここで確認できますが、
代表的なHandlerとしてはStreamHandlerがあります。
APIサーバーをクラウドでホスティングする場合は、APIサーバーのログはとりあえず標準出力に出しておいて、
外側でログを管理するサービスに送るという構成をとることが多いのでPython側ではStreamHandlerだけ設定しておけば十分なことが多いです。
オンプレでAPIサーバーを運用していてログをファイルに書き出したい場合はFileHandlerなどの使用を検討すればよいと思います。
Log Levelの使い分けについてはドキュメントを参考にしてください。
loggingではLog LevelをLoggerとHandlerに設定することができます。
例えば以下ようにするとaaa.bbbのLoggerにLog Levelを設定することができます。
logging.getLogger("aaa.bbb").setLevel(logging.INFO)こうするとINFOより重要度が低いメッセージはこのLoggerに到達した段階で捨てられるようになります。
この場合はDEBUGメッセージはaaaやroot Loggerには伝搬しなくなります。
HandlerにLog Levelをセットすることもできます。 例えば以下のように設定します。
_logger = getLogger("aaa")
stream_handler = logging.StreamHandler()
stream_handler.setLevel(logging.WARNING)
_logger.addHandler(stream_handler)この場合はstream_hanlderが標準エラー出力に出力するメッセージはWARNINGより重要度の高いメッセージのみとなります。
ログを出力する際はメッセージ内容だけでなく時刻やメッセージを送出したモジュール名も記録しておいたほうがデバッグをする上で便利です。
ログのフォーマットを指定するのがFormatterオブジェクトでHandlerにセットすることができます。
例えば以下のようにしてStreamHandlerの出力形式を指定できます。
_logger = getLogger("aaa")
stream_handler = logging.StreamHandler()
stream_handler.setLevel(logging.WARNING)
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
stream_handler.setFormatter(formatter)
_logger.addHandler(stream_handler)結論ではログ出力の設定をする際にlogging.basicConfigを呼び出すことしかしませんでした。
実はbasicConfigは 指定したキーワード引数に従ってRootLoggerの出力設定を行っています。
引数なしで
from logging import basicConfig
basicConfig()のように呼び出すとデフォルトのFormatterをもつStreamHandlerがRootLoggerにaddされます。
各子Loggerが送出したメッセージはRootLoggerまでpropagateするため、RootLoggerにさえ出力設定を行えば一通りを出力することができるわけです。
ちなみにpythonの実行環境によっては最初からHandlerがRootLoggerにaddされていることもあります。 例えばAWS LambdaでPythonを実行する場合はDocumentに記述があるようにリクエストIDを含むログを出力するHandlerがあらかじめRootLoaggerにaddされています。 この場合、デフォルトの出力内容で問題ない場合は出力設定は不要です。
loggingについて調べているとpythonnのPackageを開発する際はloggerにはNullHandlerだけを追加しましょうという記事をしばしば見かけると思います。
これはLoggerにHandlerが一つも登録されていない時に出るNo handlers could be found for loggerというエラーメッセージが出ないようにするためとなっています。
これは古いバージョンの Python の話で
公式ドキュメント Logging HOWTO の環境設定が与えられないとどうなるかによると
Python 3.2以降ではHandlerが設定されていとエラーメッセージが出るという振る舞いがそもそもなくなっています。
よってPython 3.2より前のバージョンのPythonに対応したPackageを開発するという特殊な場合を除いてPackage開発の際はLogger
にNullHandlerを追加しておくというお作法は不要です。
何もHandlerを追加しなければOKです。
loggingについて調べるとたまに以下のようなログレベルとHandlerを設定済みのLoggerを返す関数を用意して、
プロジェクト内でLoggerを使いたいときはこのget_logger関数からloggerを受け取って使用するという記事をしばしば目にします。
import logging
def get_logger(name, level=logging.DEBUG):
logger = logging.getLogger(name)
logger.setLevel(level)
stream_handler = logging.StreamHandler()
stream_handler.setLevel(level)
formatter = logging.Formatter('%(name)s - %(levelname)s - %(message)s')
stream_handler.setFormatter(formatter)
logger.addHandler(stream_handler)
logger.propagete = False
return loggerプロジェクトにおけるログの出力方法を統一したくてこうしているのだと思いますが、
ログの出力方法の統一は親Loggerでログの出力設定を行うことで実現できるのでこのやり方はあまりうまみがないと思います。
loggingモジュールはメッセージはRootLoggerに集めて、RootLoggerにHandlerをaddして出力方法を決めるという思想で設計されています。
特別な理由がない限りは設計思想に合わせて実装したほうが面倒が少ないです。
面倒な例を上げると、これが一つのプロジェクト内で閉じた話ならまだどうにかなるのですが、途中でコードをほかのプロジェクトで使うために
packageとして切り出したくなった時、get_loggerでLog LevelとHandlerを設定しているとpackageを使用するプロジェクト側でログ出力を制御しようとするとかなりワークアラウンド的な処理が必要になってきます。
get_loggerをClassの初期化の際に呼ぶと悲惨なことになります。
例えば次のようにするとget_loggerはClassをインスタンス化するたびに実行されるわけですが、
上で説明した通り同じnameのLoggerは一つしか作成されず、getLogger(name)を呼ぶと同じLoggerが使いまわされます。
それにもかかわらずStreamHandlerはLoggerに追加されていくため、Classの初期化を行った回数だけ多重にメッセージが標準エラー出力に出力されてしまいます。
import logging
def get_logger(name, level=logging.DEBUG):
logger = logging.getLogger(name)
logger.setLevel(level)
stream_handler = logging.StreamHandler()
stream_handler.setLevel(level)
formatter = logging.Formatter('%(name)s - %(levelname)s - %(message)s')
stream_handler.setFormatter(formatter)
logger.addHandler(stream_handler)
return logger
class MyClass:
def __init__(self):
self.logger = get_logger(self.__class__.__name__)
def show(self):
self.logger.debug("This is a debug message")
if __name__ == "__main__":
c1 = MyClass()
c2 = MyClass()
c3 = MyClass()
c2.show()これを回避するためのワークアラウンドを解説する記事も存在しますが、 以下のようにして、Handlerの設定はエントリーポイントで行ったほうが簡単です。
from logging import getLogger, basicConfig, DEBUG
_logger = getLogger(__name__)
class MyClass:
def __init__(self):
pass
def show(self):
_logger.debug("This is a debug message")
if __name__ == "__main__":
basicConfig(level=DEBUG)
c1 = MyClass()
c2 = MyClass()
c3 = MyClass()
c2.show()Pythonのloggingモジュールは様々な設定方法がありますが、プロジェクトを開始した初期段階では結論で解説した方法でロギングしておけば多くの場合で問題ないです。
もちろんプロジェクトが大きくなってくると個別の事情が出てきてさらなる設定が必要になると思います。
その場合もLogging HowToで解説されているloggingの設計思想にのっとって拡張していけば柔軟にログを出力することができるはずです。
ロギングをしっかり行っておくと開発時のデバッグや本番運用時のトラブルシューティングの際に作業がはかどります。
みなさんloggingを使いこなして快適に開発や運用を行いましょう！