2019/08/02 – Cheerfull days

Pythonを使っているときに、ログを取るのを怠ってエラーが見つからずに苦労したので、ちゃんとログを取りましょう、という話です。(Pythonに慣れている方には、おそらく常識レベルの話だと思います)

普通に処理をしている場合は、予期しない例外が発生すると標準エラー出力に例外のスタックトレースが出力されます。しかし、標準エラー出力を潰した後はスタックトレースが出力されません。

以下のような場合に問題になります。

daemon化する場合
スレッドを実行する場合

順に説明します。

daemon化する場合

double forkによるdaemon化については、Pythonでは以下のページの例のように行います。

Double forkによるプロセスのデーモン化と、ファイル変更時の自動サーバーリロードの実装 (Python)

この場合、標準エラー出力が潰されているので、 daemon化した後に例外が発生しても、例外のスタックトレースはどこにも出力されません。

以下のようにすると、例外のログがloggerで出力できます。

def main():
    logger = getLogger()
    handler = FileHandler("./test.log")
    logger.addHandler(handler)

    daemonize() # double forkした後に標準エラー出力を潰す

    try:
        do_process() #ここで例外が発生したら、下のexceptでキャッチする
    except Exception as e:
        logger.exception("Exception {0} occured".format(e))

スレッドを実行する場合

さらに、daemon化してからスレッドを実行する場合、親スレッドのtry-exceptではスレッド内での例外は捕捉されず、例外のスタックトレースはどこにも出力されません。スレッドのrun()で、例外を捕捉してログを出力する必要があります。

class TestThread(threading.Thread):
    _logger = getLogger(__name__)

    def run(self):
        try:
            self._do_process() #ここで例外が発生したら、下のexceptでキャッチする
        except Exception as e:
            self._logger.exception("Exception {0} occured".format(e))

def main():
    logger = getLogger()
    handler = FileHandler("./test.log")
    logger.addHandler(handler)

    daemonize() # double forkした後に標準エラー出力を潰す

    try:
        thread = TestThread()
        thread.start() # thread.run()で例外が発生しても、このtry-exceptでは捕捉できない
    except Exception as e:
        logger.exception("Exception {0} occured".format(e))

そんなこんなでうじゃうじゃ。