【Python】ルートロガーでログを記録するコード例【logging】

loggingロギングモジュールの root loggerルートロガーを使用してロギングする Python コード例です。

新しく Python プログラムを書き始めるときのルートロガーの使い方です。

ルートロガーのロギングレベルを下げます。
ルートロガーにハンドラを追加します。
名前付きロガーやルートロガーにログを書きます。

これで、ログを「画面」や「ファイル」に出力することができました。

Python コード例です。

import logging, pathlib
logger = logging.getLogger(__name__)

def main():
    root_logger = logging.getLogger()
    root_logger.setLevel(logging.DEBUG)

    sh = logging.StreamHandler()
    # sh.setLevel(logging.NOTSET)
    sh.setFormatter(logging.Formatter('%(name)s %(levelname)s %(funcName)s: %(message)s'))
    root_logger.addHandler(sh)

    log_txt = pathlib.Path(r'F:\apps\data\log.txt')
    fh = logging.FileHandler(log_txt, encoding='utf-8', mode='a')
    fh.setLevel(logging.INFO)
    fh.setFormatter(logging.Formatter('%(name)s %(levelname)s %(funcName)s: %(message)s'))
    root_logger.addHandler(fh)

    root_logger.debug('start')
    root_logger.info('%(name)s %(levelname)s %(funcName)s: %(message)s')
    logger.debug('jisaku.jisaku_func() start')
    jisaku_func()
    logger.debug('jisaku.jisaku_func() end')
    root_logger.debug('end')
    return

def jisaku_func():
    logger.debug('logger.debug() デバッグログ')
    logger.info('logger.info() インフォログ')
    logger.warning('logger.warning() ウォーニングログ ')
    logger.error('logger.error() エラーログ')
    logger.critical('logger.critical() クリティカルログ')
    return

if __name__ == '__main__':
    main()

実行結果の画面表示です。

root DEBUG main: start
root INFO main: %(name)s %(levelname)s %(funcName)s: %(message)s 
__main__ DEBUG main: jisaku.jisaku_func() start
__main__ DEBUG jisaku_func: logger.debug() デバッグログ
__main__ INFO jisaku_func: logger.info() インフォログ
__main__ WARNING jisaku_func: logger.warning() ウォーニングログ  
__main__ ERROR jisaku_func: logger.error() エラーログ
__main__ CRITICAL jisaku_func: logger.critical() クリティカルログ
__main__ DEBUG main: jisaku.jisaku_func() end
root DEBUG main: end

ログファイル (log.txt) の内容です。

root INFO main: %(name)s %(levelname)s %(funcName)s: %(message)s
__main__ INFO jisaku_func: logger.info() インフォログ
__main__ WARNING jisaku_func: logger.warning() ウォーニングログ 
__main__ ERROR jisaku_func: logger.error() エラーログ
__main__ CRITICAL jisaku_func: logger.critical() クリティカルログ

以上です。

Python マニュアルによると、まずは「ルートロガーだけにハンドラを取り付けてログを記録する」というのが、ロガーの使い方の「一般的なシナリオ」とのことでした。

一般的に、ハンドラを複数のロガーに接続する必要はありません。propagate 設定が True のままになっていれば、ロガーの階層において最上位にある適切なロガーにハンドラを接続するだけで、そのハンドラは全ての子孫ロガーが記録する全てのイベントを確認することができます。一般的なシナリオでは、ハンドラをルートロガーに対してのみ接続し、残りは propagate にすべて委ねます。
(Python) logging.Logger.propagate 属性（注釈:）

子ロガーはメッセージを親ロガーのハンドラに伝えます。このため、アプリケーションが使っているすべてのロガーのためのハンドラを定義して設定する必要はありません。トップレベルのロガーのためのハンドラだけ設定しておいて必要に応じて子ロガーを作成すれば十分です。(しかし、ロガーの propagate 属性を False に設定することで、伝播を抑制できます。)
(Python) ロガー（上級ロギングチュートリアル）

デフォルトのロギングレベルは、ルートロガーだけが WARNING (30) でした。ほかの名前付きロガーや各種ハンドラは、すべて NOTSET (0) でした。

⇒ ロガーとハンドラのデフォルトのロギングレベル（ロガーでロギングするコード例）

ログはどのロガーに書くべきか？

ログを書くときは名前付きロガーに書けば十分でした。

ルートロガーは「ハンドラを追加するとき」にだけ使用すれば十分でした。

名前付きロガーに書いたログは、ルートロガーに取り付けたハンドラで記録されました。

ルートロガーへのログの伝搬でんぱん（伝播でんぱ）を止とめたいときは、logger.propagete 属性を False に設定したらできました。

ルートロガーに書いたログは、もちろん、ルートロガーに取り付けたハンドラで記録されました。

解説付きのコード例は、以下の記事に書きました。

⇒ 基本的なロギング（ロガーでロギングするコード例）

⇒ 自作ライブラリのロギング（ロガーでロギングするコード例）

必要なところだけ拾ってください。

以下、補足です。

「ルートロガー」か？「名前付きロガー」か？
プログラムの開始地点でのロギング
名前付きロガーにハンドラを追加する場合
logger の変数はグローバル変数に置きました

「ルートロガー」か？「名前付きロガー」か？

結論ですが、どちらも使用しました。

通常は、ルートロガーにハンドラを追加して、名前付きロガーにログを書いたら、目的が果たせました。

# ルートロガー
logging.getLogger()
logging.getLogger(None)

# 名前付きロガー
logging.getLogger(__name__)
logging.getLogger('__main__')
logging.getLogger('jisaku')

もちろん「ルートロガー」にログを書いても OK でした。

たいていは「名前付きロガー」に書けば十分でした（意図したロギングができました）。

ルートロガーにハンドラを追加して、名前付きロガーにログを書く。

これが、Python でプログラムを書き始めるときに、一番無難で便利なロギング方法でした。

そして「ルートロガー」にログを書いても OK です。

ログが出ない原因を探すときに、「ルートロガーでログが出るかを試す」とか、便利な場面がありました。

デバッグの目的や開発の進み具合によって、便利なやり方は変わりました。

プログラムの開始地点でのロギング

プログラムの開始地点かいしちてん（起点きてん、エントリーポイント、メインモジュール）となる Python ファイルでは、全部ルートロガーで済ませる、というのも便利でした。

コードがほんの少しだけ減りました（微々たる差でしたが）。

ルートロガーを取得したついでに、それでログを書いていく感じですね。

「ルートロガー」にハンドラを追加して、「ルートロガー」にログを書いていきました。

ちょっとしたプログラムで「画面表示＆ログファイル」を使いたいときに、よくそうしています。

この場合でも、自作ライブラリの中については、「名前付きロガー」にログを書いていきました。

まあ、開始地点だけルートロガーで済ませたところで、削減できたコードは数行でした。

なので、基本的には

ルートロガーにハンドラを追加して、名前付きロガーにログを書く。

というスタイルが、一番無難で、便利でした。

名前付きロガーにハンドラを追加する場合

ルートロガーとは別に、名前付きロガーにハンドラを取り付けて使用したことも、もちろんありました。

たとえば、ログに応じて「ログの出力先」を変えたいときです。

ログファイルを複数使いたいとか、特定のログだけをローテートしながら記録したいとか。

そういったときに、名前付きロガーにハンドラを追加して、使用する場面がありました。

⇒ ローテート専用のロガーを作って使用するコード例（ログファイルを『ファイルサイズでローテーション』するコード例）

ほかにも、ルートロガーのようなものを複数作るために、ログを「名前付きロガーの子こロガーたち」に書いていく方法も考えられます。

発展的なロギング方法はいろいろありましたが、とりあえず「書き始めの段階」では、いつもの方法で良いと思います。

ルートロガーにハンドラを追加して、名前付きロガーにログを書く。

最初に紹介した Python マニュアルにもあった通り、まずはルートロガーにだけハンドラを追加して使用するのが、実際に便利でした。

logger の変数はグローバル変数に置きました

使用頻度の高いロガーは、グローバル変数でいいと思います。

ロガーなんて、いつでも便利に使えてこそだと思います。

変数名も logger から log とか lg とか、どんどん短くしてきました。

logger.debug() みたいに、ただでさえ print() 関数よりも長くなったので、自分用のプログラムでは短く済ませています。

自分はこれまで、ロガーを「グローバル変数に置くアプローチ」と「ローカル変数に置くアプローチ」の 2 通りを試してきました。

結論ですが、グローバル変数に置いたほうが、たいてい便利でした。

特に、「最初にとりあえず用意しておくようなロガー」は、グローバル変数に入れて使っています。

一方で、局所的なロギングで、そこだけロガーを使い分けたい場合には、ロガーをローカル変数に入れて使ったり、logging.getLogger().debug() のように書いて使うのが便利でした。

logging モジュールさえインポートしていれば、いつでもどこでも、指定したロガーを呼び出すことができました。

与えられた名前に対して、この関数はどの呼び出しでも同じロガーインスタンスを返します。したがって、ロガーインスタンスをアプリケーションの各部でやりとりする必要はありません。
(Python) logging.getLogger(name=None)

まあ、特別なロギング設定用の関数を自作して使うときは、あえて明示的めいじてきに引数ひきすうでロガーを持ち回るほうが、見た目にも分かりやすくて便利だったりもしました。お好みで。

以上です。