Cloud Logging向け構造化ログ Python編

Cloud Loggingでは構造化ログがサポートされており、JSON形式のログを出力する事で構造化データとして読み取ってくれる。
構造化ログを出力すると、Cloud Loggingのクエリでのフィルタリングが簡単になるため、
GCP上で実行されるアプリケーションのログはCloud Loggingフレンドリーにしておきたい。

要件

Cloud Loggingのログエントリ形式に合わせる
- 特にseverity, message, timestampを合わせると、Cloud Logging Viewer上の表示がいい感じになる
標準出力/標準エラー出力からログを出力する
- Cloud Logging API等を使うと、ローカル環境のテストがやりづらくなる。
任意のkey-valueを追加できる
- message だけでなく任意の変数を埋め込めると、ログ分析をする際に文字列パースをしなくて済む

実装

Python標準のLoggingモジュールに、Cloud Logging用のFormatterを設定する。
python-json-logger を使う事で、JSON形式のFormatterを簡単に作ることができる。

""" cloud logging logger """

from datetime import datetime
from datetime import timezone
import sys
import logging

from pythonjsonlogger import jsonlogger


class CloudLoggingFormatter(jsonlogger.JsonFormatter):
    def parse(self):
        return ["name", "message", "stack_info"]

    def add_fields(self, log_record, record, message_dict):
        super().add_fields(log_record, record, message_dict)

        if not log_record.get("timestamp"):
            # RFC3339形式にフォーマットする
            log_record["time"] = datetime.now(timezone.utc).strftime("%Y-%m-%dT%H:%S.%fZ")

        if log_record.get("level"):
            # Pythonのログレベルのアッパーケースを流用
            log_record["severity"] = log_record["level"].upper()
        else:
            log_record["severity"] = record.levelname
            

formatter = CloudLoggingFormatter()

stream = logging.StreamHandler(stream=sys.stdout)
stream.setFormatter(formatter)

logger = logging.getLogger("app-name")
logger.setLevel(logging.INFO)
logger.addHandler(stream)

使い方

$ cat main.py
from logger import logger

logger.info("info log", extra={"extra-key1": "fuga", "extra-key2": "fuga"})
logger.error("error log", extra={"extra-key2": "fuga"})
$ python main.py | jq
{
  "name": "app-name",
  "message": "info log",
  "stack_info": null,
  "extra-key1": "fuga",
  "extra-key2": "fuga",
  "time": "2020-12-28T13:54.096049Z",
  "severity": "INFO"
}
{
  "name": "app-name",
  "message": "error log",
  "stack_info": null,
  "extra-key2": "fuga",
  "time": "2020-12-28T13:54.096245Z",
  "severity": "ERROR"
}

Cloud Logging Viewerだと以下のようになる。
severityに合わせて左側のアイコンが変化するため、見やすくなる。 f:id:acata:20201228232657p:plain f:id:acata:20201228232700p:plain