pythonのloggingにて、想定した値が取得できない。

Question

サンプルコード

# これがmain.pyです
import logging
from logging import getLogger, StreamHandler, FileHandler, Formatter

# --------------------------------------------------
# log関連の宣言
# --------------------------------------------------
# loggerオブジェクトの宣言
logger = logging.getLogger(__name__)
# loggerのログレベル設定(ハンドラに渡すエラーメッセージのレベル)
logger.setLevel(logging.INFO)
# logのフォーマット
handler_format = Formatter('%(asctime)s %(levelname)-8s [%(module)s#%(funcName)s %(lineno)d] %(message)s')

# ---- 標準出力のhandler ----
# コンソール用のhandlerの生成
stream_handler = StreamHandler()
# handlerのログレベル設定(ハンドラが出力するエラーメッセージのレベル)
stream_handler.setLevel(logging.INFO)
# ログ出力フォーマット設定
stream_handler.setFormatter(handler_format)

# ---- ログファイル出力のhandler ----
# ログファイル用のhandlerの生成
file_handler = FileHandler('error.log', encoding='utf-8')
# handlerのログレベル設定(ハンドラが出力するエラーメッセージのレベル)
file_handler.setLevel(logging.WARNING)
# ログ出力フォーマット設定
file_handler.setFormatter(handler_format)

# ---loggerにhandlerをセット---
# 標準出力のhandlerをセット
logger.addHandler(stream_handler)
# ログファイル出力のhandlerをセット
logger.addHandler(file_handler)

# mainの開始ログをコンソールに表示
logger.info("開始")
logger.error("エラー")

# こちらがtest.pyです
import logging

class Test():
    def __init__(self):
        # ロガーを取得する
        self.logger = logging.getLogger(__name__)

    def log_write():
    # ログ出力
        self.logger.debug('DEBUGレベルのメッセージです')
        self.logger.info('INFOレベルのメッセージです')
        self.logger.warning('WARNINGレベルのメッセージです')
        self.logger.error('ERRORレベルのメッセージです')
        self.logger.critical('CRITICALレベルのメッセージです')

2021-11-17 18:08:57,448 INFO     [main#<module> 47] 開始
2021-11-17 18:08:57,448 ERROR    [main#<module> 48] エラー
WARNINGレベルのメッセージです
ERRORレベルのメッセージです
CRITICALレベルのメッセージです
2021-11-17 18:09:23,046 INFO     [main#<module> 105] 終了

（これがerror.logです)
2021-11-17 18:08:57,448 ERROR    [main#<module> 48] エラー

実現したいこと

・test.pyで記入したlogがターミナルに表示されましたが、フォーマットが適用されません。

2021-11-17 18:08:57,448 INFO     [main#<module> 47] 開始
2021-11-17 18:08:57,448 ERROR    [main#<module> 48] エラー
2021-11-17 18:08:57,448 WARNING     [test#<module> 47] WARNINGレベルのメッセージです
2021-11-17 18:08:57,448 ERROR    [test#<module> 48] ERRORレベルのメッセージです
2021-11-17 18:08:57,448 CRITICAL    [test#<module> 49] CRITICALレベルのメッセージです
2021-11-17 18:09:23,046 INFO     [main#<module> 105] 終了

上記のようにターミナルに表示されることが理想です。

・error.logにもフォーマットが適用された状態でtest.pyでのlogを表示させたいです。

2021-11-17 18:08:57,448 ERROR    [main#<module> 48] エラー
2021-11-17 18:08:57,448 WARNING     [test#<module> 47] WARNINGレベルのメッセージです
2021-11-17 18:08:57,448 ERROR    [test#<module> 48] ERRORレベルのメッセージです
2021-11-17 18:08:57,448 CRITICAL    [test#<module> 49] CRITICALレベルのメッセージです

上記のようにerror.logに表示されることが理想です。

最後に

初歩的な質問で申し訳ありません。
しかし、自分なりに調べても出てこなかったため、お力を貸して頂けると幸いです。
何か不足している情報があれば遠慮なくお申し付けください。
よろしくお願い致します。

Comments

[quickquip]

Pythonは3.7以前のものですか?

[takuyatakkyu]

バージョンは3.9を使用しております！！

Answer 1

pythonのloggingモジュールでは、1つのプログラムの中で複数のロガーオブジェクトを持つことができます。親子関係にもできるし、別々のオブジェクトにすることもできます。
logging.getLogger("one") と logging.getLogger("two") は別のロガーオブジェクトです。
logging.getLogger("p") と logging.getLogger("p.c1") は親子関係のあるロガーオブジェクトです。

__name__ は、pythonの特殊変数で、モジュールのファイル名か、直接起動された時には、"main"という値を持ちます。

ということで、おわかりと思いますが、
質問の状況は、別のコードで「logging.getLogger(name)」と書いているので、それらは別のロガーオブジェクトになり、設定は片方にしか反映されません。
同じロガーにするには、__name__を使わず、何も設定しない(ルートロガーと呼ばれるロギーオブジェクトが取得できます)か、固定の文字列にするのが簡単でしょう。

ちゃんと親子関係にする方法もありますので、ドキュメントを参照してみてください。

Comments

[takuyatakkyu]

回答ありがとうございます。
親子関係にするという記事も調べる中で見かけたのですが、例えば
logger = getLogger("main").getChild("test")として親子関係にした場合、
モジュールの表示で
2021-11-06 20:30:30,681 - main.test - DEBUG - Hi!
のように、ドットで階層のような表記になってしまうのではと思い採用を見送っておりました。
親子関係にしてもモジュール名だけをコンソールで表示させるといった方法はあるのでしょうか？

[TakaiY]

出力にモジュール名を表示したいのであれば、フォーマッタの文字列に モジュール名(${module}s)を入れればいいでしょう。

main.testと表示されるのは、 %{name}s のように、ロガーの名前をログに入れているからですが、表示しなければならないわけではないので、不要であれば入れなければOKです。

ちなみに、ロガーの名前にモジュール名を入れる必要はありません。(入れることが多いでしょうけど。)

ご存知とは思いますが、フォーマッタに使える変数はここで確認できます。
https://docs.python.org/ja/3/library/logging.html#logrecord-attributes

[takuyatakkyu]

ご回答ありがとうございます。
全て解決いたしました！！