pino（ログライブラリ）導入した日記
🙇♂️ 挨拶
こんばんは。アドベントカレンダー参加記事です。
Node.jsのロギングライブラリ導入日記（個人的に詰まったところ、考えたこと）を書きました。
前提として筆者は普段Golangをたくさん書いていて、Node.jsについては日が浅く、知識が少ない傾向にあります。
🎯 テーマ
「構造化ログ」の実現とロギングライブラリの導入
これまで雑に使用していた console.log から、構造化ログ対応で高速なロギングライブラリ pinoへの移行を検討・実施した。
📌 問題点
-
運用コスト: サービス立ち上げ時は
console.logを使っていたが、運用を見据えて CloudWatch Logs 等のロギングサービスを使う際、JSON形式で出力してほしい。 - 制御性: 環境変数でサクッとログレベルを制御できないのは、開発・運用において不便。
💡 選択したライブラリ: pino
-
選定理由:
-
パフォーマンス:
pinoは非常に高速であることが大きな特徴。 -
シンプルさ: 多機能すぎず、構造化ログ出力など必要な機能がシンプル。
-
メジャー感: コミュニティの利用実績が多く、知見が得やすい（ここが最大の決め手）。
-
比較検討:
-
WinstonやBunyanも検討したが、軽量さとコミュニティの勢いを信じてpinoを選択。
📦 インストール
pnpm add pino
pnpm add -D pino-pretty
🛠️ 導入方針: ラッパーの作成
ロギングライブラリを直接使わず、自前のラッパー関数を通して利用する方針とした。
-
目的: 将来的に
pinoから別のライブラリへリプレイスする際の疎結合を維持するため。 - メリット: ライブラリ変更の影響をラッパー内部に限定でき、アプリケーションコード全体の大幅な改修を避けられる。
🤔 TS/Node.jsでのログメタ情報に関する考察
Goの標準ロギングでは容易な「ファイル名、関数名、スタックトレース」等のログ発生元メタ情報について。
-
Goとの違い:
-
Node.js/TypeScriptでは、これらの情報をプロダクションで出力するのは非推奨とされることが多いらしい（
pinoもデフォルトでは出力しない）。 -
理由:
-
これらの情報の取得にはスタックトレースの解析が必要で、オーバーヘッドが非常に高いためであるとか。（あんまり気にしたことなかったのでちょっとびっくりした）
※エラー発生時はスタックトレース勝手に含んでくれるのでそこは便利だと思いました（ここは逆にデフォルトで備えていないGolangが特殊なのかもしれない）
🚀 実装時のメモ
1. ログの表示順について
当初のメソッドシグネチャと出力（Pinoデフォルト）:
loggerInstance.info(context, message)
// 出力例: {"level":"info","time":"YYYY-MM-DDTHH:MM:SS.SSSZ","dbName":"template_db","msg":"Test database setup completed"}
👉 context が優先され、msg が末尾に来るため視認性が低い。
改善後のメソッドシグネチャと出力（採用）:
loggerInstance.info({ msg: message, ...context })
// 出力例: {"level":"info","time":"YYYY-MM-DDTHH:MM:SS.SSSZ","msg":"Test database setup completed","dbName":"template_db"}
👉 level, time, msg が前方に固定され、視認性が向上。
※おまけ
ローカル環境（pino-prettyで整形）はこんな感じ
[YYYY-MM-DD HH:MM:SS.SSS +0900] INFO: Test database setup completed
dbName: "template_db"
2. 非同期書き込みとプログラム終了の問題
非同期処理（DuckDB接続など）において、エラーログが出力される前にプログラムが終了する事象に遭遇。
- 問題のコード:
const database = new DuckDB.Database(dbPath, (error) => {
if (error) {
log.error(error)
throw error // ログが書き出される前にプロセスが終わる
}
})
- 解決策 (
log.fatalの使用):
const database = new DuckDB.Database(dbPath, (error) => {
if (error) {
log.fatal(error) // 同期的にフラッシュされる
throw error
}
})
- 考察:
- Pinoはデフォルトで非同期書き込みを行うため、強制終了時にログが欠けることがある。
-
fatalレベルは致命的な問題として、書き出しを保証する（同期的にフラッシュする）動作になることが多い。 - そもそもDB接続不可は「致命的」なので、セマンティクス的にも
fatalが妥当。
🛠️ 成果物
import pino from 'pino'
// JSON形式での出力を有効にするサーバー環境のリスト
const serverEnv = ['prd', 'dev']
// 全環境共通で、Errorオブジェクトを確実にシリアライズするための設定
// また、baseConfigを設定することでホスト名やプロセスIDなどのデフォルト情報を出力されないようになる（使用環境だと不要だったので）
const commonSerializers = {
err: pino.stdSerializers.err,
}
// pinoロガーインスタンスの初期化
const loggerInstance = pino(
serverEnv.includes(env)
? // サーバ環境 (prd/dev) の場合の設定
{
level: 'info', // ログレベルを環境に応じて設定
serializers: commonSerializers,
formatters: {
level: (label) => {
return { level: label.toLowerCase() } // レベルラベルを小文字に変換（ここは好み）
},
},
// タイムスタンプのフォーマット（デフォルトはUNIX Timestamp）をISO 8601形式に変更
timestamp: pino.stdTimeFunctions.isoTime,
base: undefined, // pid, hostname を出力しない
}
: // ローカルの場合の設定
{
level: 'trace',
serializers: commonSerializers,
// pino-prettyトランスポートを使用して、色付きで人間が読みやすい形式で出力
transport: {
targets: [
{
target: 'pino-pretty',
options: {
colorize: true, // ログレベルなどに色を付ける
translateTime: 'SYS:standard', // タイムスタンプを標準的な形式で表示
ignore: 'pid,hostname', // pidとhostnameは出力に含めない
},
},
],
},
},
)
const info = (message: string, context?: Record<string, unknown>) => {
loggerInstance.info({ msg: message, ...context })
}
.
.
.
📚 雑記
まだ読めてないです。（読みたい）
Discussion