python loggingでトレースバックを出力する

pythonのloggingモジュールで単にerrorログを吐いてもトレースバックまで出力してくれない。

サンプルコード

# lowermodule.py
import traceback
import logging

logging.basicConfig(
    level=logging.DEBUG, format="%(asctime)s %(name)s %(levelname)s:%(message)s"
)
logger = logging.getLogger(__name__)

def word_count(myfile):
    try:
        with open(myfile, "r") as f:
            file_data = f.read()
            words = file_data.split(" ")
            final_word_count = len(words)
            logger.info("this file has %d words", final_word_count)
            return final_word_count
    except OSError as e:
        logger.error(e)

# uppermodule.py
import logging
import lowermodule

logging.basicConfig(
    level=logging.DEBUG, format="%(asctime)s %(name)s %(levelname)s:%(message)s"
)
logger = logging.getLogger(__name__)

def record_word_count(myfile):
    logger.info("starting the function")
    try:
        word_count = lowermodule.word_count(myfile)
        with open("wordcountarchive.csv", "a") as file:
            row = str(myfile) + "," + str(word_count)
            file.write(row + "\n")
    except:
        logger.warning("could not write file %s to destination", myfile)
    finally:
        logger.debug("the function is done for the file %s", myfile)
record_word_count("test.txt")

test.txtがない状態でuppermodule.pyを実行すると以下のようなログが吐かれる。
errorログが出ているのが確認できるが、トレースバックまでは出力されていない。

2023-02-02 13:30:23,165 __main__ INFO:starting the function
2023-02-02 13:30:23,165 lowermodule ERROR:[Errno 2] No such file or directory: 'test.txt'
2023-02-02 13:30:23,171 __main__ DEBUG:the function is done for the file test.txt

トレースバックまで出力したい場合、errorメソッドのexc_infoをTrue にしてあげる必要がある。

def word_count(myfile):
    try:
        with open(myfile, "r") as f:
            file_data = f.read()
            words = file_data.split(" ")
            final_word_count = len(words)
            logger.info("this file has %d words", final_word_count)
            return final_word_count
    except OSError as e:
        logger.error(e)
        logger.error(e, exc_info=True)

上記のように修正して実行すると以下のようにトレースバックまで出力されていることが確認できる。

2023-02-02 13:37:19,495 __main__ INFO:starting the function
2023-02-02 13:37:19,495 lowermodule ERROR:[Errno 2] No such file or directory: 'test.txt'
2023-02-02 13:37:19,495 lowermodule ERROR:[Errno 2] No such file or directory: 'test.txt'
Traceback (most recent call last):
  File "/home/hoge/lowermodule.py", line 13, in word_count
    with open(myfile, "r") as f:
FileNotFoundError: [Errno 2] No such file or directory: 'test.txt'
2023-02-02 13:37:19,504 __main__ DEBUG:the function is done for the file test.txt

logging.exception()を使っても同様のことが可能。

グローバルなException, unexpectedなExceptionのトレースバックを出力したい場合は以下のようにtracebackモジュールを使用する必要がある。

def word_count(myfile):
    try:
        with open(myfile, "r") as f:
            file_data = f.read()
            words = file_data.split(" ")
            final_word_count = len(words)
            logger.info("this file has %d words", final_word_count)
            return final_word_count
    except OSError as e:
        logger.error(e)
        logger.error(e, exc_info=True)
    except Exception as e:
        logger.error("uncaught exception: %s", traceback.format_exc())  #

参考：

How to collect, customize, and centralize Python logs