« ^ »

Pythonのログ出力を自分でJSON形式にする

所要時間: 約 3分

Pythonのログ出力は、デフォルトでは1つのログが複数行に渡って出力される。これはターミナル上で手動で実行する場合は見易いが、ログ収集のシステムと連携してしようとすると各行が1つのログとして扱われてしまう。これはログの集計の結果にも影響を与えてしまうし、なにより検索しにくくなってしまう。そのため、PythonのloggerのフォーマッターをJSON形式用のフォーマッターに差し替えて使う。structlogやpython-json-formatterは、そういったライブラリだ。

ただJSON形式のログを出力するだけの為に、何でサードパーティのライブラリに依存しないといけないのだろうか。Pythonにはjsonモジュールもloggingモジュールもあるのに、ログ変換処理のためだけに外部の何かに依存したくない。

そこで、この変換処理は自分で簡易なものを実装する事にした。

main.py

import json
import logging
import traceback


class JSONFormatter(logging.Formatter):
    def format(self, record):
        log_data = {
            "timestamp": self.formatTime(record, self.datefmt),
            "level": record.levelname,
            "message": record.getMessage(),
            "logger_name": record.name,
            "module": record.module,
            "function": record.funcName,
            "line": record.lineno,
            "thread": record.threadName,
            "process": record.process,
            "traceback": "".join(traceback.format_tb(record.exc_info[2]))
            if record.exc_info
            else None,
        }
        return json.dumps(log_data, ensure_ascii=False)


handler = logging.StreamHandler()
formatter = JSONFormatter()
handler.setFormatter(formatter)

logging.basicConfig(level=logging.INFO, handlers=[handler])


logger = logging.getLogger("custom-logger")
logger.info("Ok")


def testing():
    raise ValueError("日本語例外")


try:
    testing()
except:
    logger.exception("?Oops!!", exc_info=True)
python main.py 2>&1
{"timestamp": "2023-08-04 15:11:45,652", "level": "INFO", "message": "Ok", "logger_name": "custom-logger", "module": "main", "function": "<module>", "line": 33, "thread": "MainThread", "process": 55413, "traceback": null}
{"timestamp": "2023-08-04 15:11:45,652", "level": "ERROR", "message": "?Oops!!", "logger_name": "custom-logger", "module": "main", "function": "<module>", "line": 43, "thread": "MainThread", "process": 55413, "traceback": "  File \"/opt/ng/symdon/pages/posts/1691127585/main.py\", line 41, in <module>\n    testing()\n  File \"/opt/ng/symdon/pages/posts/1691127585/main.py\", line 37, in testing\n    raise ValueError(\"日本語例外\")\n"}

AWS CloudWatch Logs だとログのレコードを正しく認識できなくて、1つのレコードに複数のログが混在してしまう状態になる事があった。この処理では不十分だと思う。structlogではどのように実装しているのか、時間を見つけて調査してみたい。

LoggerAdapter

loggingモジュールはLoggerAdapterというクラスを定義している。これは、ログ出力に情報を追加するために使う。例えばその実行時のリクエストやコンテキストの情報であったり、その時にのみ取得でいる共通の情報だったりする。

ここでは extracustom_value の値として、 Hello world! を含める。

class CustomLoggingAdapter(logging.LoggerAdapter):
    def process(self, msg, kwargs):
        if "extra" not in kwargs:
            kwargs["extra"] = {}

        kwargs["extra"]["custom_value"] = "Hello world!"
        return msg, kwargs

このクラスはlogging.dictConfigや、Djangoのsettings.LOGGINGでは設定できない。そのためlogging.getLogger("")で取得したロガーを引数にして、CustomLoggingAdapterに渡す必要がある。

logger = logging.getLogger(__name__)
log_adapter = CustomLoggingAdapter(logger)