Skip to content
tenginePublic

About

No description, website, or topics provided.

Resources

Stars

0 stars

Watchers

0 watching

Forks

Latest commit

 

History

172 Commits

Folders and files

Repository files navigation

py-gn-log

py-gn-log は Cloud Run 環境とローカルの開発環境を考慮した Groovenauts 社内標準(にしようとしている) の Python ロギング設定ライブラリです。Cloud Run 環境では JSON 形式の構造化されたログを出力することで Cloud Logging にログを生成します。

パッケージの構造

gnlog の直下は provider (Google Cloud / AWS 等) を知らない共通部で、provider ごとの実装はサブパッケージにあります。利用側は使う provider のサブパッケージを明示的に import し、そこを入口にします。

モジュール 役割
gnlog.context リクエスト / タスク単位の文脈を全ログ行に付ける (ContextVar + Filter)
gnlog.fingerprint ERROR の dedup 用 fingerprint の正規化とハッシュ
gnlog.level ログレベルの変換
gnlog.output 出力形式の決定 (GNLOG_FORMAT)、テキスト形式の handler、ルートロガーへの組み込み
gnlog.trace W3C Trace Context (traceparent) の解釈・組み立てと、現在の trace の保持
gnlog.google.cloud_run Cloud Run 向けの入口 setup_logging() と is_cloud_run()
gnlog.google.cloud_logging Cloud Logging 向けの JSON formatter (severity / labels / stack_trace / fingerprint)
gnlog.google.cloud_trace X-Cloud-Trace-Context の解釈と Cloud Logging の特殊フィールド (logging.googleapis.com/trace 等)

import gnlog は gnlog.google を読み込みません。AWS 向けの実装を足す場合も gnlog.aws.* として同じ構造で置き、Google 向けアプリのプロセスに影響しない形にします。

インストール

uvを使う場合

uv add git+ssh://git@github.com/tengine/py-gn-log

ブランチを指定する場合

uv add git+ssh://git@github.com/tengine/py-gn-log --branch (ブランチ名)

依存ライブラリの版について

py-gn-log は python-json-logger に依存しており、動作確認した major に上限を付けて宣言しています (python-json-logger>=4.0.0,<5)。python-json-logger の major が上がったときは py-gn-log 側で互換性を確認してから上限を上げます。

ロックファイルを持たず、Docker のビルドのたびに pip install で依存を解決する構成のプロジェクトでは、推移依存の版が変わって起動に失敗することを防ぐため、利用側でも python-json-logger の版を明示して固定することを推奨します。

使い方

基本的な使い方

import logging
from gnlog.google.cloud_run import setup_logging

# ロギングを初期化 (Cloud Run 上なら Cloud Logging 向けの JSON、外ならテキスト)
setup = setup_logging(log_level=logging.INFO)

# ロガーを取得して使用
logger = setup.apply(__name__)
logger.info("Application started")
logger.error("An error occurred")

setup_logging() はルートロガーに handler を組み込むので、apply() を使わず logging.getLogger(__name__) で取ったロガーからの出力にも同じ設定が効きます。apply() はロガーごとに level などを変えたいときに使います。

__name__ は呼び出すモジュールの名前(この場合は .py ファイルの名前から拡張子を除いたもの)を表す特殊な変数です。詳しくは Python チュートリアル » 6. モジュール あるいは Python 言語リファレンス » 3. データモデル » module.__name__ を参照してください。

ルートロガーの level について

setup_logging() はルートロガーの level を設定します (logging.basicConfig(level=...) と同じ振る舞い)。そのため apply() していないモジュールのロガー (logging.getLogger(__name__) で取得しただけのもの) からの INFO / DEBUG も出力されます。

ハンドラの level は設定しません。どの level の行を出力するかは、行を出したロガーの実効 level (ロガー自身の level。設定していなければ、親のロガーをたどって最初に見つかった level) で決まります。そのため、apply() でロガーの level を LOG_LEVEL より低くすると、そのロガーと、その level を引き継ぐ子孫のロガー (ロガー app に対する app.db など。自身にも、間のロガーにも level を設定していないもの) から、その level の行が出力されます。

ルートロガーの level を変更したくない場合は set_root_level=False を指定してください。この場合、ルートロガーの level は Python の既定 (WARNING) のままなので、ルートロガーの level を引き継ぐロガー (自身にも、ルートロガーとの間のロガーにも level を設定していないもの。apply() していないモジュールのロガーなど) の INFO / DEBUG は出力されません。アプリがルートロガーの level を LOG_LEVEL より低くしていた場合は、ルートロガーの level を引き継ぐロガーから、その level の行が出力されます。

from gnlog.google.cloud_run import setup_logging

setup_logging(set_root_level=False)

この節の説明は、ハンドラに level を設定していない場合のものです。setup_logging() の戻り値 setup で setup.handler.setLevel(...) を呼んでハンドラに level を設定すると、ロガーの level にかかわらず、ハンドラの level より低い level の行は出力されません。

環境変数による設定

環境変数の使われ方

flowchart LR
    S(start) --> A[環境変数 LOG_LEVEL]
    A --> J{環境変数 GNLOG_FORMAT}
    J -->|json| C[標準出力 Cloud Logging用JSON形式]
    J -->|text| D[環境変数 LOG_FORMAT]
    J -->|指定なし| B{環境変数 K_SERVICE など Cloud Run の環境変数}
    B -->|通常Cloud Runによって指定| C
    B --> |指定なし| D
    D --> E{環境変数 LOG_FILE_PATH}
    E -->|指定あり| F[ファイル出力]
    E -->|指定なし| G[標準出力]
Loading

ログレベルの設定

環境変数 LOG_LEVEL でログレベルを指定できます。

export LOG_LEVEL=DEBUG

指定可能な値: DEBUG, INFO, WARN, WARNING, ERROR, CRITICAL

from gnlog.google.cloud_run import setup_logging

# 環境変数 LOG_LEVEL からログレベルを読み込む
setup = setup_logging()
logger = setup.apply("my_app")

出力形式の明示的な指定

環境変数 GNLOG_FORMAT で、Cloud Run 上かどうかによらず出力形式を指定できます。指定できる値は json (Cloud Logging 用の JSON 形式) と text (テキスト形式) です。それ以外の値を指定すると setup_logging() が ValueError を送出します (json 引数を明示した場合は環境変数を読まないので送出しません)。未設定なら Cloud Run の環境変数の有無で自動判定します。

# ローカルや CI で Cloud Logging に取り込まれる形そのままの JSON 行を確認する
export GNLOG_FORMAT=json

コードから指定する場合は setup_logging(json=True) / setup_logging(json=False) を使います。引数は環境変数より優先されます。

from gnlog.google.cloud_run import setup_logging

setup_logging(json=True)

なお、環境変数 LOG_FORMAT はテキスト形式の format 文字列 を指定するものです。LOG_FORMAT=json のように形式名を設定すると format 文字列として解釈され ValueError になります。形式の切り替えには GNLOG_FORMAT を使ってください。

ログファイルへの出力

環境変数 LOG_FILE_PATH でログファイルのパスを指定できます (テキスト形式のみ。JSON 形式は常に標準出力です)。

export LOG_FILE_PATH=/var/log/myapp.log

ログフォーマットのカスタマイズ

環境変数 LOG_FORMAT でテキスト形式のログフォーマット (format 文字列) を指定できます。JSON 形式では使われません。

export LOG_FORMAT="%(asctime)s [%(levelname)s] %(message)s"

Cloud Run での使用

環境変数 K_SERVICE が設定されている場合(Cloud Run 環境)、自動的に JSON 形式でログを出力します。 環境変数 K_SERVICE は Cloud Run によって自動的に設定されるため、特別な設定は不要です。詳しくは Cloud Run > ガイド > コンテナランタイムの契約 > 環境変数 を参照してください。

from gnlog.google.cloud_run import setup_logging

# Cloud Run では自動的に JSON フォーマットが使用される
setup = setup_logging()
logger = setup.apply("my_service")
logger.info("Service started", extra={"user_id": 123})

Cloud Run 上かどうかの判定は gnlog.google.cloud_run.is_cloud_run() として公開しています。この関数だけを使う場合、gnlog.google.cloud_run の import では python-json-logger を読み込みません。

出力例:

{
  "name": "my_service",
  "message": "Service started",
  "time": "2025-01-15T10:30:45.123456Z",
  "severity": "INFO",
  "user_id": 123
}

time は Cloud Logging がログエントリーの時刻として読むフィールドです。RFC 3339 形式 (UTC、マイクロ秒まで) で出力します。引数 extra などで渡したフィールド time は、この値で上書きされます。

ログエントリーの時刻を呼び出し側で指定したいときは、キー seconds と nanos を持つオブジェクトのフィールド timestamp か、フィールド timestampSeconds と timestampNanos の組を extra などで渡します。クラス gnlog.google.cloud_logging.JsonFormatter (setup_logging() が JSON 形式で使う formatter) はこれらを上書きせずに出力し、Cloud Logging の文書では、これらは time より先に読まれます。この文書は Logging エージェントの設定の文書ですが、Cloud Run の文書も、構造化ログの特別なフィールドの説明としてこの文書を参照しています。

フィールド stack_info (ログを書いた箇所までの呼び出し履歴) は、logger.info(..., stack_info=True) のように stack_info=True を指定してログを書いた行だけに出力します。

severity は、ログを書いたときのレベル (logger.error() なら ERROR) です。引数 extra や gnlog.context で渡したフィールド level はそのまま出力し、severity には使いません。extra などで渡したフィールド severity は、この値で上書きされます。

Python の logging にレベルが無い Cloud Logging の重大度 (NOTICE・ALERT・EMERGENCY) を出すには、関数 logging.addLevelName でその名前を付けたレベルを作り、logger.log() で使います。ERROR (40) 以上のレベルは、ERROR と同じく stack_trace と error_event のフィールドの対象になります。

import logging

logging.addLevelName(25, "NOTICE")  # INFO (20) と WARNING (30) の間
logging.addLevelName(60, "ALERT")  # CRITICAL (50) より上
logging.addLevelName(70, "EMERGENCY")

logging.getLogger(__name__).log(60, "在庫の同期が止まった")  # severity は ALERT

リクエスト / タスク単位の文脈を全ログ行に付ける

1 つのリクエストや 1 つのタスクの処理中に出るログ行を、あとから 1 つの ID で串刺しにしたい場面 (エラー応答に載せた ID から Cloud Logging を引く、複数サービスにまたがる処理を追う等) のために、gnlog.context を用意しています。

gnlog.context は contextvars.ContextVar に置いた値を、setup_logging() が組み込んだ handler の Filter が各ログ行に注入します。JSON 形式では置いたキー名がそのまま JSON のキーになります。setup_logging() を呼ぶだけで有効になり、apply() していないロガーからの行にも付きます。

import logging
from gnlog import context
from gnlog.google.cloud_run import setup_logging

setup_logging()
logger = logging.getLogger(__name__)

# with ブロックの間だけ付ける (抜けると、ここで置いたキーだけが元に戻る。入れ子にできる)
with context.bind(trace_id="4bf92f35", site="tokyo"):
    logger.info("処理開始")   # {"message": "処理開始", "trace_id": "4bf92f35", "site": "tokyo", ...}

# 明示的に消すまで残す (リクエストの開始時に set、終了時に clear する使い方)。
# bind のブロック内で set した値も、ブロックを抜けた後に残る
context.set(trace_id="4bf92f35")
logger.info("...")
context.clear()
  • キー名は自由ですが、message や name など LogRecord が自前で持つ属性名は使えません (ValueError になります)。logging.googleapis.com/trace のように Python の識別子にならないキーは、context.set({...}) / context.bind({...}) と Mapping を位置引数で渡します。
  • 値が None のキーは出力されません (文脈上で「そのキーは無い」ことを表すために使えます)。
  • extra={"trace_id": ...} で明示的に渡した値は、文脈の値より優先されます。
  • テキスト形式では、LOG_FORMAT に %(trace_id)s のように書いた場合のみ出力されます。ただし文脈が置かれていない行では該当の属性が無いため整形に失敗します。テキスト形式で使う場合は、常に値が置かれている状態を保つか、JSON 形式を使ってください。

スレッドをまたぐ場合

threading.Thread は ContextVar を継承しません。スレッドをまたいで文脈を引き継ぐには、生成元で contextvars.copy_context() を取り、その run 経由でスレッドの処理を呼び出してください。asyncio のタスクは生成時点の文脈を自動的に引き継ぎます。

import contextvars
import threading

with context.bind(trace_id="4bf92f35"):
    ctx = contextvars.copy_context()
    t = threading.Thread(target=ctx.run, args=(work,))  # work() の中でも trace_id が付く
    t.start()

concurrent.futures.ThreadPoolExecutor を使う場合も同様に executor.submit(ctx.run, work) のように渡します。

Cloud Trace と連携して全ログ行に trace を付ける

複数サービスにまたがる処理のログを串刺しにするには、独自の ID ではなく Cloud Trace の仕組みに寄せるのが自然です。Cloud Run はリクエストごとに X-Cloud-Trace-Context ヘッダ (と W3C の traceparent) を付け、Cloud Logging は JSON の特殊フィールド logging.googleapis.com/trace (projects/<PROJECT_ID>/traces/<TRACE_ID>)、logging.googleapis.com/spanId、logging.googleapis.com/trace_sampled を認識してログエントリを trace に紐付けます (Logs Explorer で同じ trace のログを横断表示でき、Cloud Trace とも繋がります)。

gnlog.google.cloud_trace は、受信ヘッダから trace を取り出して上の文脈 (gnlog.context) に特殊フィールドとして置く関数と、他サービスを呼び出すときに現在の trace をヘッダとして組み立てる関数を提供します。W3C の traceparent の解釈・組み立てと TraceContext は共通部の gnlog.trace にあり、cloud_trace はその上に X-Cloud-Trace-Context と Cloud Logging の特殊フィールドを載せたものです。

import logging
from gnlog.google import cloud_trace as trace
from gnlog.google.cloud_run import setup_logging

setup_logging()
logger = logging.getLogger(__name__)

# 受信ヘッダから trace を取り出し、ブロックの間だけ全ログ行に付ける
with trace.bind_headers(request.headers, project_id="my-project"):
    logger.info("処理開始")
    # {"message": "処理開始",
    #  "logging.googleapis.com/trace": "projects/my-project/traces/4bf92f3577b34da6a3ce929d0e0e4736",
    #  "logging.googleapis.com/spanId": "00f067aa0ba902b7",
    #  "logging.googleapis.com/trace_sampled": true, ...}

    # 下流のサービスを呼ぶときは現在の trace をヘッダに載せる
    httpx.post(url, headers=trace.to_headers())
  • プロジェクト ID は引数 project_id、無ければ環境変数 GOOGLE_CLOUD_PROJECT から取ります。どちらにも無い場合は trace のフィールドを付けません (既定値で本番のプロジェクト ID を持たないため)。その場合も trace.current() と trace.to_headers() は動作するので、下流への引き継ぎはできます。
  • traceparent と X-Cloud-Trace-Context の両方があれば traceparent を優先します。ヘッダ名の大文字小文字は区別しません。
  • X-Cloud-Trace-Context の SPAN_ID (10 進) は、Cloud Logging の spanId に合わせて 16 桁の 16 進に変換します。
  • trace.to_headers() は、span_id と sampled の両方が分かっているときだけ traceparent を付けます。W3C の traceparent は「不明」を表せないためで、どちらかが不明なら X-Cloud-Trace-Context だけを付けます (;o= や SPAN_ID の省略で不明を表せます)。
  • trace.set(trace_context, project_id=...) / trace.clear() で明示的に置いて消すこともできます。trace.parse_traceparent() / trace.parse_cloud_trace_context() / trace.from_headers() は解釈だけを行います。
  • プロジェクト ID が決まらない状態で bind() / set() を呼ぶと、特殊フィールドは置かれません (前に置いた trace のフィールドがあればそのまま残ります)。

FastAPI / Starlette の middleware の例

このライブラリは Web フレームワーク向けの middleware を同梱していません。次のように数行で書けます。

from fastapi import FastAPI, Request
from gnlog.google import cloud_trace as trace

app = FastAPI()

@app.middleware("http")
async def bind_trace(request: Request, call_next):
    with trace.bind_headers(request.headers):  # project_id は GOOGLE_CLOUD_PROJECT から
        return await call_next(request)

asyncio のタスクは生成時点の文脈を引き継ぐので、ハンドラの中で asyncio.create_task() した処理にも trace が付きます。スレッドをまたぐ場合は上の「スレッドをまたぐ場合」と同じく contextvars.copy_context() を使ってください。

HTTP 以外の経路 (Pub/Sub、Cloud Run Jobs、キュー) で trace を運ぶ

受信ヘッダが無い経路では、呼び出し側がペイロードに trace を載せ、受け側が復元します。このライブラリでは次の慣習を推奨します。

  • 呼び出し側は trace.to_headers() の内容を、Pub/Sub ならメッセージの属性 (attributes)、Cloud Run Jobs なら環境変数やジョブの引数、キューならペイロードのフィールドとして、ヘッダ名と同じキー名 (traceparent / X-Cloud-Trace-Context) で載せる。
  • 受け側はその Mapping をそのまま trace.bind_headers() (または trace.from_headers()) に渡す。ヘッダ名と同じキー名にしておけば、経路によらず同じ関数で復元できる。
# 発行側
publisher.publish(topic, data, **trace.to_headers())

# 購読側 (Pub/Sub の push 配信や Cloud Run Jobs のワーカー)
with trace.bind_headers(message.attributes):
    handle(message)

Pub/Sub の OpenTelemetry 連携が付ける属性 googclient_traceparent は読みません。必要なら trace.parse_traceparent(message.attributes["googclient_traceparent"]) の結果を trace.bind() に渡してください。

ERROR 以上のログに分類と dedup 用の fingerprint を付ける

Cloud Error Reporting は severity=ERROR かつ stack_trace のあるログを自動でグループ化しますが、例外を伴わない ERROR や、メッセージに可変部 (ID、件数、引用文字列) が多いエラーはグループ化に頼れません。setup_logging(error_event=...) を指定すると、JSON 形式で severity ERROR 以上のログに次のフィールドを付けます。既定では付けません。

フィールド 内容
event error_event に指定した固定値 (例: app_error)。ERROR 級のイベントを 1 つの名前で引くため
error_type extra で渡した分類。未指定なら unknown
operation extra で渡した操作名。未指定ならロガー名
fingerprint 同種のエラーで同じ値になる 16 文字のハッシュ。dedup のキーに使う

extra で event や fingerprint を明示的に渡した場合は上書きしません。

import logging
from gnlog.google.cloud_run import setup_logging

setup_logging(error_event="app_error", surface="worker")
logger = logging.getLogger(__name__)

logger.error("order %s not found", 123, extra={"error_type": "validation", "operation": "orders.get"})
# {"message": "order 123 not found", "severity": "ERROR", "event": "app_error",
#  "error_type": "validation", "operation": "orders.get", "fingerprint": "…", ...}

fingerprint の規則 (他言語の実装との契約)

fingerprint は gnlog.fingerprint モジュールの公開関数 normalize_message() と build_fingerprint() で計算します。TypeScript 等で対になる実装を作るときは、同じ規則にすると言語をまたいで同じ値になります。

  1. メッセージ (% 書式を展開した後の文字列) に対して、次の順に置き換える
    1. UUID ([0-9a-fA-F]{8}-[0-9a-fA-F]{4}-[0-9a-fA-F]{4}-[0-9a-fA-F]{4}-[0-9a-fA-F]{12}) を <uuid> に
    2. 引用文字列を <str> に。二重引用符で囲まれた改行を含まない文字列 ("[^"\n]*")、または単一引用符で囲まれた改行を含まない文字列のうち開き引用符の直前が ASCII の英数字・下線でないもの ((?<![0-9A-Za-z_])'[^'\n]*'。can't のようなアポストロフィは引用符とみなさない。閉じ引用符の直後は問わない)。単一引用符は引用の区切りとアポストロフィを同じ文字で兼ねるため、アポストロフィで始まる語 ('cause、'90s) や対になっていない単一引用符があると、その後ろに単一引用符が現れたときに、そこまでが <str> になります (後ろに単一引用符が無ければ置き換えは起きません)。厳密さが必要なメッセージでは二重引用符を使ってください
    3. 数値を <num> に。ASCII の数字の並びで、3 桁ごとのカンマ区切り・小数部・指数部を含めて 1 つの数値とし、前後は ASCII の単語境界で区切る (\b\d+(?:,\d{3})*(?:\.\d+)?(?:[eE][+-]?\d+)?\b。\b と \d は ASCII の意味)
  2. 先頭 300 文字に切り詰める。ここでの「文字」は Unicode のコードポイント です (Python の len() とスライスの単位)。絵文字などの BMP 外の文字も 1 文字と数え、サロゲートペアを分断しません。JavaScript の String.prototype.length / .slice() は UTF-16 コード単位なので、対になる実装では Array.from(s).slice(0, 300).join("") のようにコードポイント単位で切ってください
  3. surface、operation、error_type、正規化したメッセージのそれぞれについて \ を \\ に、| を \| に escape してから、| で連結する (surface 未指定なら空文字)
  4. UTF-8 でエンコードした SHA-1 の 16 進表現の先頭 16 文字を取る

切り詰め (2) と escape (3) の適用順もこの契約の一部です。切り詰めてから escape するため、切り詰めで残った | や \ が escape の対象になります (escape で増えた文字が切り詰めの長さに影響することはありません)。

from gnlog.fingerprint import normalize_message, build_fingerprint

normalize_message('order 123 for "alice" not found')
# => 'order <num> for <str> not found'

build_fingerprint("worker", "orders.create", "validation", "order 123 missing")
# => sha1("worker|orders.create|validation|order <num> missing")[:16]

build_fingerprint("worker|orders", "create", "validation", "boom")
# => sha1("worker\|orders|create|validation|boom")[:16]   (値の | は escape される)

入力の検証の例外から入力の値を除く

pydantic v2 の ValidationError と、FastAPI 0.100.0 以降の RequestValidationError・ResponseValidationError は、メッセージに検証に失敗した入力の値 (リクエストやレスポンスの本文。個人情報やトークンを含みうる) が入ります。JSON 形式では、例外の連鎖 (__cause__・__context__・ExceptionGroup の子) にこれらの例外があれば、そのメッセージから入力の値を除いて、フィールド stack_trace (severity WARNING 以下では exc_info。どちらに入るかは「出力するフィールドの名前を変える」の表の exc_info・stack_trace の行を参照) に出力します。

import logging
from pydantic import BaseModel, ValidationError

class Member(BaseModel):
    email: str
    age: int

try:
    Member.model_validate(body)  # body は {"email": "taro@example.com", "age": "token-abc123"}
except ValidationError:
    logging.getLogger(__name__).exception("会員の登録に失敗")
# stack_trace の最後の行:
# pydantic_core._pydantic_core.ValidationError: 1 validation error(s) (input omitted): age [int_parsing]
  • 残すのは、エラーごとの場所 (loc) と種類 (type) です。場所の要素のうち、番号と識別子の形の文字列でないもの (辞書のキーなど、入力の値でありうるもの) は <key> にします。
  • 説明 (msg) は出力しません。pydantic の組み込みの説明にも、タグで型を選ぶ union のタグの値のように、入力の値を埋め込むものがあるためです。説明は、種類の名前 (int_parsing など) で pydantic の文書を引いて調べてください。
  • FastAPI の例外は、エラーとして任意の値を受け付けます。エラーの列でない値 (None・文字列・辞書など) は 1 つのエラーとして扱います。辞書でないエラーと、識別子の形の文字列でない種類 (pydantic 2.14.1 では、種類はすべて識別子の形) は、入力の値を含みうるので、中身を出さずに <str> のように型の名前だけを出力します。
  • 連鎖のほかの例外と、traceback (ソースコードの行を含む) は、標準の traceback と同じ形で出力します。
  • py-gn-log は pydantic と FastAPI を import しません。読み込み済みのモジュールのクラスで、これらの例外を見分けます。
  • 入力の値を除く処理は、Python の traceback.TracebackException の非公開の属性に頼っています。その属性が使われなくなった Python の版では、入力の値を出力しないように、入力の検証の例外を含む行の整形を例外 RuntimeError で止めます。その行は出力されず、標準エラー出力に --- Logging error --- と RuntimeError が出ます。標準エラー出力の traceback にも、入力の検証の例外は含めません。

入力の値を除くのは、ログを書くときに渡した例外 (logger.exception() や引数 exc_info で渡したもの) から作る、JSON 形式のフィールド stack_trace と exc_info だけです。ログのメッセージとテキスト形式 (output.text_handler()) の出力からは除きません。たとえば次の行では、入力の値がフィールド message に残ります。

  • logger.error("会員の登録に失敗: %s", e) のように、例外をメッセージに埋め込んだ行
  • logging.handlers.QueueHandler を通した行。QueueHandler は、record をキューに入れる前に、例外の traceback をメッセージに整形し、例外の情報 (exc_info) を外すため

ログレベルのユーティリティ関数

from gnlog import level
import logging

# 文字列からログレベルを取得
log_level = level.parse("ERROR")  # => logging.ERROR

# 環境変数からログレベルを取得
log_level = level.from_env()  # LOG_LEVEL 環境変数から取得

# ログレベルを文字列に変換
level_str = level.to_str(logging.INFO)  # => "INFO"

高度な使い方

ロガーごとに異なる設定を適用

import logging
from gnlog.google.cloud_run import setup_logging

setup = setup_logging(log_level=logging.INFO)

# 特定のロガーは DEBUG レベルで出力
debug_logger = setup.apply("debug_module", log_level=logging.DEBUG)

# 親ロガーへの伝播を無効化
isolated_logger = setup.apply("isolated", propagate=False)

# 既存のハンドラをクリアして新規追加
clean_logger = setup.apply("clean", clear_handlers=True, add_handler=True)

ハンドラは level で絞らないので、LOG_LEVEL=WARNING で運用するアプリでも、setup.apply("audit_log", log_level=logging.INFO) としたロガー audit_log の INFO は出力されます。子孫のロガーが level を引き継ぐ場合を含め、どのロガーの行が出力されるかは「ルートロガーの level について」を参照してください。

別の provider や独自の formatter を使う

setup_logging() は共通部 gnlog.output の組み合わせです。formatter を差し替えたい場合や、別の provider の入口を作る場合は同じ部品を使えます。

import logging
from gnlog import output

handler = output.stream_handler(MyFormatter())          # 任意の formatter で標準出力へ
# handler = output.text_handler()                        # テキスト形式 (LOG_FILE_PATH / LOG_FORMAT を読む)
setup = output.install(handler, log_level=logging.INFO)  # ContextFilter を付けてルートロガーに組み込む

出力形式の決定は output.use_json_output(json, default=...) で、default に「その環境で JSON にするか」の判定 (Cloud Run なら is_cloud_run) を渡します。

非 ASCII 文字を escape せずに出力する

JSON 形式では、既定で非 ASCII 文字 (日本語など) を \uXXXX に escape して出力します (python-json-logger の既定と同じ)。Cloud Logging は JSON を復号して表示するので閲覧上の違いはありませんが、標準出力を直接読む場面 (ローカル実行、docker logs、CI のログ) では読みにくく、grep もできません。json_ensure_ascii=False を指定すると、そのまま出力します。

from gnlog.google.cloud_run import setup_logging

setup_logging(json_ensure_ascii=False)

出力するフィールドの名前を変える

JSON 形式で出力するフィールドの名前は、引数 rename_fields で変えられます。python-json-logger の同名の引数にそのまま渡します。既定では名前を変えません。クラス gnlog.google.cloud_logging.JsonFormatter を直接使う場合も、同じ引数を渡せます。

from gnlog.google.cloud_run import setup_logging

# ロガー名をキー name ではなく logger で出力する
setup_logging(rename_fields={"name": "logger"})

名前が変わるのは、python-json-logger が出力するフィールドです。name・message・stack_info と、ログを書くときに渡すフィールド (引数 extra やモジュール gnlog.context で渡したフィールドと、ログのメッセージに渡した辞書のキー) の名前が変わります。JsonFormatter が後から入れるフィールド (time・severity など) の名前は変わりません。message の名前を変えた場合、fingerprint は名前を変えた後のフィールドの値から計算します。

Cloud Logging は、構造化ログの特別なフィールドを名前で見分けます。特別なフィールドの一覧は、節「Cloud Run での使用」で引いている Cloud Logging の文書にあります。message (この文書では、Logs Explorer のログエントリーの行に表示されるメッセージ) や、モジュール gnlog.google.cloud_trace が付ける logging.googleapis.com/trace などの名前を変えると、そのフィールドは元の特別なフィールドとしては扱われません。

rename_fields のキーと値が文字列でなければ、例外 TypeError になります。また、次の場合は、出力するフィールドの値が失われるか、JsonFormatter の処理が働かなくなるので、例外 ValueError になります。テキスト形式で出力する場合も、setup_logging() は同じ検査をします。

  • 下の表のキーを、rename_fields の変換前か変換後に使う。これらのキーは JsonFormatter が読み書きする
  • 複数のキーを同じ名前に変える (例: {"a": "x", "b": "x"})
  • 名前を変えていない name・message・stack_info と同じ名前に変える (例: {"name": "message"})。{"name": "message", "message": "msg"} のように、そのフィールドの名前も変えるなら使えます
キー 使えない理由
time・severity・logging.googleapis.com/labels JsonFormatter が後から値を入れる (logging.googleapis.com/labels には値を足す)。time の扱いは「Cloud Run での使用」を参照
exc_info・stack_trace severity ERROR 以上のログで、JsonFormatter が exc_info (python-json-logger がトレースバックを入れるフィールド) を stack_trace に載せ替える
event・error_type・operation・fingerprint 引数 error_event を指定したときに JsonFormatter が読み書きする (「ERROR 以上のログに分類と dedup 用の fingerprint を付ける」を参照)。error_event を指定しない場合も使えない

ログを書くときに渡すフィールドとの重なりは、rename_fields を受け取る時点では分からないので検査しません。変換後の名前と同じ名前のフィールドを渡すと、どの値が残るかは python-json-logger が値を書く順序で決まり、ほかの値は失われます。たとえば {"name": "logger"} を指定して extra={"logger": ...} を渡すと、ロガー名は出力されません。変換後の名前と同じ名前のフィールドは渡さないでください。

診断出力を抑止する

setup_logging() と apply() は、初期化の過程 (ハンドラのクリアやロガーの状態) を診断用に標準エラー出力へ出力します。Cloud Run では標準エラー出力も Cloud Logging に取り込まれ、severity を持たない構造化されていないエントリとして混じります。不要な場合は verbose=False を指定してください。

from gnlog.google.cloud_run import setup_logging

setup = setup_logging(verbose=False)
logger = setup.apply(__name__)

google-cloud-logging の Client.setup_loggingとの併用は不要

Python 用 Cloud Logging の設定 には以下のようなコードを書くように説明がありますが、これと併用する必要はありません。

setup_logging 利用例
# Imports the Cloud Logging client library
import google.cloud.logging

# Instantiates a client
client = google.cloud.logging.Client()

# Retrieves a Cloud Logging handler based on the environment
# you're running in and integrates the handler with the
# Python logging module. By default this captures all logs
# at INFO level and higher
client.setup_logging()

不要な理由

gnlog.google.cloud_run.setup_logging() と google.cloud.logging.Client().setup_logging() のどちらも logging.root に自身の用意したハンドラを追加するためです (名前が同じですが別のものです)。gnlog の setup_logging() を呼び出す前に Client の setup_logging() を呼び出した場合は、Client が追加したハンドラを削除します。Client の setup_logging() を後で呼び出した場合はハンドラが追加されますが、その場合は一つのログ出力の呼び出しに対して複数のハンドラが動作するので、複数のログエントリが作成されます。

詳しくは py-gn-log の前身を作成した際の以下のPRを参照してください。 https://github.com/tengine/cloud-run-services-fastapi-example/pull/7

変更履歴

次の版 (未リリース)

版の番号はリリースのときに決めます。互換性のない変更を含みます。

  • 時刻をフィールド time で出力するようにした (#40)。クラス gnlog.google.cloud_logging.JsonFormatter は、これまで出力していた文字列のフィールド timestamp を出力しない。time の扱いは「Cloud Run での使用」を参照
  • extra などで渡したフィールド timestamp を上書きしなくなった。扱いは「Cloud Run での使用」を参照
  • JSON 形式で出力するフィールドの名前を、引数 rename_fields で変えられるようにした (#41)。扱いは「出力するフィールドの名前を変える」を参照
  • ハンドラの level を設定しないようにした (#47)。apply() でロガーの level を LOG_LEVEL より低くすると、その level の行も出力される。どのロガーの行が出力されるかは「ルートロガーの level について」を参照
  • フィールド stack_info を、stack_info=True を指定した行だけに出力するようにした (#48)。これまでは、ほかの行にも値が null の stack_info を出力していた
  • 入力の検証の例外 (pydantic の ValidationError、FastAPI の RequestValidationError・ResponseValidationError) のメッセージから、入力の値を除いて出力するようにした (#49)。扱いは「入力の検証の例外から入力の値を除く」を参照
  • extra や gnlog.context で渡したフィールド level で、severity を変えなくなった (#44)。扱いは「Cloud Run での使用」を参照

0.3.0 からの移行

  • JsonFormatter が出力していたフィールド jsonPayload.timestamp を参照しているログのクエリ・ログベースの指標・アラート・BigQuery のクエリは、新しい行で値を取得できなくなります。ログエントリーの時刻 (トップレベルの timestamp。BigQuery へのシンクのテーブルでは列 timestamp) を使うように直してください。
  • extra や gnlog.context でフィールド time を渡している場合は、別のキー名に変えてください。渡した値は JsonFormatter に上書きされます (「Cloud Run での使用」を参照)。
  • Cloud Logging の文書のとおりなら、ログエントリーの時刻は、Cloud Logging がログを取り込んだ時刻から、ログを書いた時刻 (LogRecord の作成時刻) に変わります。
  • apply(log_level=...) や logging.getLogger(...).setLevel(...) で、ロガーの level を LOG_LEVEL より低くしているコード (ライブラリを含む) がある場合は、LOG_LEVEL より低い level の行も出力されるようになります。set_root_level=False を指定し、ルートロガーの level を LOG_LEVEL より低くしている場合も同じです。子孫のロガーが level を引き継ぐ場合を含め、どのロガーの行が出力されるかは「ルートロガーの level について」を参照してください。これまでのようにハンドラでも LOG_LEVEL に絞るには、setup_logging() の戻り値 setup で setup.handler.setLevel(setup.log_level_default) を呼んでください。
  • 関数 gnlog.output.install に、level を設定した handler を渡している場合は、その level で行が絞られるようになります。これまでは install() が handler の level を、引数 log_level (省略したときは環境変数 LOG_LEVEL) の値で上書きしていました。handler の level で絞りたくない場合は、level を設定せずに渡してください。
  • stack_info=True を指定していない行には、フィールド stack_info が無くなります。出力にキー stack_info が必ずあることを前提にしている処理は、キーが無い行も扱えるように直してください。
  • 入力の検証の例外を記録した行では、stack_trace (severity WARNING 以下では exc_info) の、その例外のメッセージの形が変わります。ログのクエリやログベースの指標で、pydantic や FastAPI のメッセージの文字列を条件にしている場合は、新しい形 (「入力の検証の例外から入力の値を除く」を参照) に合わせて直してください。
  • extra や gnlog.context でフィールド level を渡して severity を変えていた場合、その行の severity は、ログを書いたときのレベルになります。重大度を変えるには、呼び出すメソッド (logger.warning() など) を変えてください。Python の logging にレベルが無い重大度 (NOTICE・ALERT・EMERGENCY) を出す方法は「Cloud Run での使用」を参照してください。

0.3.0

Issue #10〜#18、#29、#30 への対応です。互換性のない変更を含みます (下の移行手順を参照)。

  • provider 固有の実装を gnlog.google サブパッケージへ再配置し、共通部が provider を import しない構造にした (#30)。入口は gnlog.google.cloud_run.setup_logging()。Initializer と gnlog.init、gnlog.json_formatter は削除
  • is_cloud_run だけの利用で python-json-logger を読み込まなくなった (#29)
  • Cloud Trace 連携 gnlog.google.cloud_trace と、W3C traceparent の共通部 gnlog.trace を追加 (#17)
  • ERROR 以上のログに分類と dedup 用の fingerprint を付ける gnlog.fingerprint と setup_logging(error_event=...) を追加 (#18)
  • リクエスト / タスク単位の文脈を全ログ行に付ける gnlog.context を追加 (#15)
  • ルートロガーの level も設定するようにした (#12。set_root_level=False で従来どおり)
  • 環境変数 GNLOG_FORMAT と引数 json で Cloud Run 外でも JSON 形式を選べるようにした (#13)
  • json_ensure_ascii で非 ASCII 文字の escape を制御できるようにした (#14)
  • verbose=False で診断出力を抑止できるようにした (#11)
  • py.typed を同梱し、利用側で型情報が効くようにした (#10)
  • python-json-logger の依存に上限 (<5) を付け、uv.lock を追跡対象にした (#16)

0.2.0 からの移行

0.2.0 0.3.0
from gnlog import Initializer / Initializer(...) from gnlog.google.cloud_run import setup_logging / setup_logging(...) (引数は同じ)
initializer.apply(__name__) setup = setup_logging(...) の戻り値で setup.apply(__name__)
from gnlog.init import is_cloud_run from gnlog.google.cloud_run import is_cloud_run
from gnlog.json_formatter import JsonFormatter from gnlog.google.cloud_logging import JsonFormatter
gnlog.init.LOCAL_LOG_FORMAT gnlog.output.TEXT_LOG_FORMAT
gnlog.print_loggers gnlog.output.print_loggers

挙動の変更で注意が要るもの:

  • setup_logging() はルートロガーの level も設定します (0.2.0 の Initializer() は設定しなかった)。apply() していないモジュールのロガーからも INFO / DEBUG が出るようになります。従来どおりにするには set_root_level=False を指定してください。
  • 診断出力 (Initializer starting 等) は既定で引き続き出ます。抑止するには verbose=False を指定してください。

開発者向け

前提条件

ドキュメントサーバー

make pydoc-server

でドキュメントサーバーが起動します。ブラウザで http://localhost:9000/gnlog にアクセスして内容を確認できます。

About

No description, website, or topics provided.

Resources

Stars

0 stars

Watchers

0 watching

Forks

Releases

Packages

Used by

Contributors

Languages