Pythonのloggingに[ファイル名：行番号 メソッド名]を出力できるようにしたい

本タイトルの内容を調べてみて自前で実装したのですが、公式に同じ機能があり、役に立たなそうだから供養という体裁をとっていました。
実際に使ってみるとちょっと想定と違う挙動になったので書き直しています。

【追記】0.問題意識

awsのlambdaを使って開発をしています。
設計上のひとつの秩序として、処理系はClassでまとめて、メソッドはlambdaのエントリーポイントのみということにしてみました。
ログの出力処理もClassでまとめようと考えています。
その際に、loggingにある機能をつかって本タイトルの実装としようとしたところ、ログ出力用Class内で実行したログ出力処理を行番号・メソッド名として出力するという結果になりました。
これだと意味がないので、やっぱり使い物になるかも説

１．結論から言うloggingに機能はあるけどちょっと違った。

loggingにそういう機能がありました。
https://docs.python.org/ja/3/library/logging.html#logging.LogRecord

【追記】
似たような機能はありましたが、こちらはlog.debugなどのログ出力の実行場所が記録されるだけということがわかりました。

検証１

logger.py

import logging

def test_method():

    log = logging.getLogger()
    formatter = "[%(asctime)s] [%(process)d] [%(levelname)s] [%(filename)s:%(lineno)d %(funcName)s] %(message)s "
    logging.basicConfig(level=logging.DEBUG, format=formatter)
    log.debug('test')

test_method()

実行結果

[2021-04-01 11:49:39,995] [57865] [DEBUG] [logger.py:8 test_method] test 

便利〜

【追記】
便利じゃなかった。

検証２

logger.py

class Logger():
    """
    ログ出力用クラス
    """
    def __init__(self):
        self.logger = logging.getLogger()
        self.logger.setLevel(logging.DEBUG)
        formatter = logging.Formatter(
          '[%(levelname)s]\t%(asctime)s.%(msecs)dZ\t%(aws_request_id)s\t%(filename)s\t%(funcName)s\t%(lineno)d\t%(message)s\n',
          '%Y-%m-%dT%H:%M:%S'
        )
        for handler in self.logger.handlers:
            handler.setFormatter(formatter)

    def debug(self, log_message):
        self.logger.debug(log_message)

    def info(self, log_message):
        self.logger.info(log_message)

    def warning(self, log_message):
        self.logger.warning(log_message)

    def error(self, log_message):
        self.logger.error(log_message)


def test_method(event, context):
    log = Logger()
    log.debug('test debug')
    log.info('test info')
    log.warning('test warning')
    log.error('test error')

[DEBUG] 2021-04-01T04:20:35.437Z    87afa56f-bb0a-435e-8652-8dbc61c3be91 logger.py  debug   20  test debug
[INFO]  2021-04-01T04:20:35.437Z    87afa56f-bb0a-435e-8652-8dbc61c3be91    logger.py   info    23  test info
[WARNING]   2021-04-01T04:20:35.437Z    87afa56f-bb0a-435e-8652-8dbc61c3be91 logger.py  warning 26  test warning
[ERROR] 2021-04-01T04:20:35.437Z    87afa56f-bb0a-435e-8652-8dbc61c3be91    logger.py   error   29  test error

最初の検証と違う環境で実行しているので、「ファイル名　メソッド名　行番号」になっています。
メソッドがtest_methodになっておらず、また行番号もclass内の行番号になっています。
これではいかん。

２．【供養】最初無いもんだと思ってやったこと実はこれでよかった

logger.py

import logging
import inspect
import os

class Logger():
    """
    ログ出力用クラス
    """
    def __init__(self):
        self.logger = logging.basicConfig(level=logging.DEBUG, format="[%(asctime)s] [%(process)d] [%(name)s] [%(levelname)s] %(message)s")

    def debug(self, execution_location, log_message):
        self.logger = logging.getLogger(execution_location)
        self.logger.debug(log_message)

    def info(self, execution_location, log_message):
        self.logger = logging.getLogger(execution_location)
        self.logger.info(log_message)

    def warning(self, execution_location, log_message):
        self.logger = logging.getLogger(execution_location)
        self.logger.warning(log_message)

    def error(self, execution_location, log_message):
        self.logger = logging.getLogger(execution_location)
        self.logger.error(log_message)

class Trace():
    """
    ログ出力とセットで使う処理をまとめたクラス
    """
    @classmethod
    def execution_location(self):
        """
        処理の実行場所を出力する。[ファイル名: 行番号  メソッド名]
        """
        frame = inspect.currentframe().f_back
        return "{}:{} {}".format(os.path.basename(frame.f_code.co_filename), frame.f_lineno, frame.f_code.co_name)

def test_method():
    log = Logger()
    log.debug(Trace.execution_location(), 'debug test')

test_method()

実行結果

[2021-04-01 12:11:05,181] [62612] [logger.py:42 test_method] [DEBUG] debug test

inspectについて
https://docs.python.org/ja/3/library/inspect.html
ログ生成場所でTrace.execution_locationを実行しないとファイル名、行番号、メソッドがLoggerクラス内になってしまってうまくいかないなーなどと２時間くらい考えた結果、上記のような実装になりました。
あまりキレイじゃないなーと思っていたので、より良い解決方法が見つかったのは良かったです。
自前の実装でうまくいってました。できれば組み込みで処理したいんですけどね。ドキュメント残さなくていいし。

３．敗因勝因

知らない誰かが作ったLoggerクラスが先にあり、その挙動を調べるところからスタートして、ドキュメントを後回しにしたことです。
ある程度頭の中で見通しができるまではドキュメントを読んでも進まなかったとも思うので、まぁいいっちゃいいんですけど。
実は勝ってました。

４．本来の目的はaws lambdaのloggingだったりする

aws側でさらに便利な出力がされるようになっているようです。
Lambda (Python) からのログ出力Tips
https://qiita.com/ohtsuka1317/items/6d4f527e6a0ccf0903f7

５．感想

loggingの場所を知りたいという意味では組み込みのものをそのまま使えば良いと思います。
本件の私の解決法よりスマートな方法があればその方がなお良しですね。

【更に追記】
さらにもうちょっと調べてみたらスマートな解決策があったのでこっちを使うことになると思います。
aws-lambda-powertools
https://pypi.org/project/aws-lambda-powertools/

A．参考

Pythonでロギングを学ぼう
https://qiita.com/__init__/items/91e5841ed53d55a7895e
pythonで実行中のファイル、関数、行番号を取得する
https://qiita.com/ymko/items/b46d32b98f013f06d805