構造化ログは println を tracing::info に置き換えることではない

文字列を連結したログは人間しか読めません。フィールドがあって初めて検索と集計ができます。フィールド、span、レベル、そして整形しない判断の 4 つが本題です。

println! を info! に変えても、残るのは相変わらず 1 行のテキストで、タイムスタンプとレベルが付いただけです。それは構造化ログではなく、出力先を変えただけです。

文字列ではなくフィールド

構造化ログの要点は、値を名前付きのフィールドに置き、機械が取り出せるようにすることです。

// 拼接字符串:日志系统只收到一行文本
info!("user {} logged in from {}", user, ip);

// 带字段:JSON 层把它们变成可查询的键
info!(user = %user, ip = %ip, "login");

2 つ目の書き方は JSON 出力で {"user":"...","ip":"...","message":"login"} になります。1 つ目は message だけで、利用者と IP は文字列に埋まっているため、利用者ごとに集計するには正規表現を書くことになります。

span が「何を」、フィールドが「誰を」

#[instrument] は関数の span を自動で作り、引数を記録します。便利ですが 2 点注意があります。

#[instrument(skip(db), fields(order_id = %id))]
async fn charge(db: &Db, id: OrderId, amount: u64) -> Result<Receipt> {
    // ...
}
  • skip(db) は必須です。コネクションプール、リクエスト本文、大きな構造体はログに載せるべきではありません。Debug の出力は遅く、漏えいの恐れもあります
  • fields(...) が代替です。引数を記録しないなら、本当に必要な識別子だけを記録します

レベルは語気ではなく意味

レベル 意味
error 人が対応する必要がある、またはデータを失った
warn 自動で回復したが、一度は見ておく価値がある
info 業務イベント(ログイン、注文、デプロイ)
debug 調査中に見たい状態

最も多い誤用は、回復可能な状況を error に書くことです。その結果、本当の障害のときに誰も見ていません。

コストとスイッチ

フィールドは遅延評価で、レベルが無効なら整形されません。文字列を自作せず tracing を使う主な利点の 1 つです。ただし debug! に serde_json::to_string のような重い式を渡すと、有効時には評価されるため、enabled!(Level::DEBUG) で明示的に守る必要があります。

本番は JSON、ローカルは色付きの pretty を環境変数で切り替えます。テストでは fmt().with_test_writer() を使います。そうしないとログを検証しようとしても何も集まりません。

ログは 3 年後の自分のために書くデータベースで、フィールドはその列です。

← 記事一覧に戻る

コメント

…