[PYTHON] It is convenient to use stac_info and exc_info when you want to display traceback in log output by logging.

Introduction

When you want to output the location information together with the location information when you output the log using the logger of logging There is. To put it tangibly, I want a traceback. Talk about what to do when including this traceback in the log.

Stupid way

Of course, there is a story that you can add traceback to the log by yourself. As below.

import logging
import traceback
logger = logging.getLogger("sample")


def foo():
    bar()


def bar():
    logger.info("bar")
    logger.info("tb: %s", "".join(traceback.format_stack()))


if __name__ == "__main__":
    logging.basicConfig(level=logging.INFO)
    foo()

Traceback is displayed for the time being.

INFO:sample:bar
INFO:sample:tb:   File "qr_64852sBQ.py", line 18, in <module>
    foo()
  File "qr_64852sBQ.py", line 8, in foo
    bar()
  File "qr_64852sBQ.py", line 13, in bar
    logger.info("tb: %s", "".join(traceback.format_stack()))

However, it is troublesome to bother to fetch the traceback by yourself. It is strange to require knowledge of python (ʻimport traceback`) just for log output in the first place.

stack_info

In fact, you don't have to add traceback yourself as above, just add stack_info = True when logging with logger.

--- 00sample.py	2017-07-13 08:06:10.000000000 +0900
+++ 01sample.py	2017-07-13 08:09:06.000000000 +0900
@@ -1,6 +1,5 @@
 # -*- coding:utf-8 -*-
 import logging
-import traceback
 logger = logging.getLogger("sample")
 
 
@@ -9,8 +8,7 @@
 
 
 def bar():
-    logger.info("bar")
-    logger.info("tb: %s", "".join(traceback.format_stack()))
+    logger.info("bar", stack_info=True)

When I run it, traceback is displayed after Stack (most recent call last).

INFO:sample:bar
Stack (most recent call last):
  File "qr_64852GWc.py", line 16, in <module>
    foo()
  File "qr_64852GWc.py", line 7, in foo
    bar()
  File "qr_64852GWc.py", line 11, in bar
    logger.info("bar", stack_info=True)

exc_info

You may want to display the traceback of the exception occurrence position instead of the log output position. For example, the same format as when using logger.exceptipn (). You can do this by passing ʻexc_info instead of stack_info`.

import logging
logger = logging.getLogger("sample")


def foo():
    bar()


def bar():
    logger.info("bar")
    1 / 0


if __name__ == "__main__":
    logging.basicConfig(level=logging.INFO)
    try:
        foo()
    except:
        logger.info("hmm", exc_info=True)

The traceback of the position where the zero division error occurs is extracted from the exception object and automatically written together.

INFO:sample:bar
INFO:sample:hmm
Traceback (most recent call last):
  File "qr_64852t0u.py", line 18, in <module>
    foo()
  File "qr_64852t0u.py", line 7, in foo
    bar()
  File "qr_64852t0u.py", line 12, in bar
    1 / 0
ZeroDivisionError: division by zero