winstonでログを出力してみよう

はじめに

この記事では主にwinstonを使ったログ出力の方法を解説します。
上記に加えてログをどこに出力すべきかも解説します。

対象者
nodeでログを出力したい人
言語に関わらずログ出力について情報が欲しい人

前提条件
基礎的なプログラム知識がある方
Next.jsのRoute Handlerを理解していること(今回Route Handlerを使用します)

環境
今回の記事では主にNext.jsやExpressといったNode上で動くプログラムを想定しています。
使用するライブラリはwinstonです。

ログとは?

「何が起きたか」を記録した情報のことです。適切にログを挟むことで、後から「何があったのか」を追跡しやすくなります。

ログが必要な例

例えば以下のような処理があったとします。
logがない場合、errをcatchすることでアプリケーションを止めずに処理することはできますが、エラーが発生した記録が残りません。
記録がないと開発者はエラーの発生に気づくことができないので、ログを出力する必要があります。

const getData = async () => {
	try {
		const res = await fetch("url");
		
		if (!res.ok) {
			throw new Error("HTTP error! status: ${response.status}");
		}
		
		return res.json();
	} catch (err) {
		// エラー発生時にログを出力
		logger.error("エラーが発生しました", { error })
		return []
	}
}

consoleではダメなのか

JavaScript(TypeScript)ではconsole.logを使用してログを出力することが可能です。
外部ライブラリを使用するメリットはなんでしょうか。
consoleは開発時のデバックでは便利ですが、winstonなどと比べると機能が限られます。
専用のライブラリを使えば、consoleよりも豊富なログレベルによるグループ分けや、slackやsentry等外部サービスへの連携が簡単に行えます。
またerrorは外部サービスへ、infoはファイルへといった細かいを簡単に行うことができます。

ログをどこに表示すべきか

ログファイルへの追記やコンソールでの表示など、出力先に複数の選択肢があります。
従来と現在では考え方が少し異なりますので整理してみます。

従来

本番環境: ファイルに出力 (全てのlog, errorのみのlogで2つに出力など、用途別に分ける)
開発環境: コンソールに出力

アプリケーションがクラッシュしてもログが残るようにするために本番環境ではファイルに出力する形式が一般的でした。複数のログを管理やすいように、ログ管理サービスに集約して一括で管理するのが主流。

現在

本番環境: コンソールに出力
開発環境: コンソールに出力

現在のクラウドが主流な環境は両者コンソールへ出力するのが良いでしょう。
AWSなどのクラウドサービス上でDockerを使って気軽にスケールアウトが可能になったことで、コンテナが動的に増減。コンテナ毎にログファイルを分けるのは現実的ではなく、　Amazon Cloud Watchのようなサービスを使って、コンソールに出力されたログを集約するのが一般的です。

Nodeのログ出力ライブラリを選定する

Nodeには複数のパッケージがります。
WinstonかPinoが人気です。

Winstone・・・GitHubスター数23900
Pino・・・GitHubスター数16000

今回はWinstonを使います。

使ってみる

// src/lib/logger.ts
import winston from 'winston';

const logger = winston.createLogger({
  level: 'debug', // debug以上のログを表示
  format: winston.format.combine(
    winston.format.timestamp(),
    winston.format.errors({ stack: true }),
    winston.format.json() // json形式
  ),
  transports: [
    new winston.transports.Console() // 出力先はコンソール
  ],
});

export default logger;

// src/app/route.ts
import logger from "@/lib/logger";
import { NextResponse } from "next/server";

export async function GET() {
	logger.info("GET request received")
	return NextResponse.json({ message: "ok" });
}

この状態で curl /apiにcurlで叩いてみると、next.jsのterminalに以下のように表示されます。

ベストな構成を考えてみる

現在は標準出力 + ログ収集サービスが主流。 ファイル出力はAWSのようなクラウドを使用しない場合に使用すると良い
現在はクラウドサービスを使うことがほとんどだと思います。
以下で考えてみます。

1 本番環境は常にJSONでconsole出力
2 local環境はsimpleな出力で色付け
3 productionではslack等別サービスに飛ばせるような設定の余地を残しておく
4 規模が大きくなる場合はスタックトレースの導入を検討する

以下の設定は本番環境ではJSON形式で出力+外部サービスへ通知、開発環境ではsimpleな表示形式で色付きにしています。

// logger.ts
import winston from "winston";

const isProduction = process.env.NODE_ENV === "production";
const logger = winston.createLogger({
  level: isProduction ? "warn" : "debug",
  format: winston.format.combine(
    winston.format.timestamp(),
    winston.format.errors({ stack: true })
  ),
  transports: [ // 出力先の設定
    // 本番環境用
    ...(isProduction
      ? [
          new winston.transports.Console({
            format: winston.format.json(),
          }),
          // 必要であればslack等外部に通知する設定
        ]
      : []),

    // 開発環境用
    ...(!isProduction
      ? [
          new winston.transports.Console({
            format: winston.format.combine(
              winston.format.colorize(), // 色付き
              winston.format.simple() // simpleにする
            ),
          }),
        ]
      : []),
  ],
});

export default logger;

simpleな形式 + 色付きは以下のように表示されます
infoに色がついていてみやすいですね

他の形式サンプル

ファイルに記述もできる

// error levelだけlogs/error.logへ
// 全てのlevelをlogs/combined.logへ
import winston from 'winston';

const logger = winston.createLogger({
  level: process.env.NODE_ENV === 'production' ? 'info' : 'debug',
  format: winston.format.combine(
    winston.format.timestamp(),
    winston.format.errors({ stack: true }),
    winston.format.json()
  ),
  transports: [
    new winston.transports.Console(),
    new winston.transports.File({
      filename: 'logs/error.log', // level errorのみ
      level: 'error',// 全てのログ
    }),
    new winston.transports.File({
      filename: 'logs/combined.log',
    }),
  ],
});

export default logger;

カスタムログ形式で対応する

import winston from 'winston';

// ログの出力形式を定義
const logFormat = winston.format.printf(({ level, message, timestamp }) => {
  return `${timestamp} ${level}: ${message}`;
});

const logger = winston.createLogger({
  // 開発環境では'debug'、本番環境では'info'以上のログを出力
  level: process.env.NODE_ENV === 'production' ? 'info' : 'debug',
  format: winston.format.combine(
    winston.format.timestamp({ format: 'YYYY-MM-DD HH:mm:ss' }),
    logFormat
  ),
  transports: [
    // 常にコンソール（標準出力）にログを出力する
    new winston.transports.Console({
      format: winston.format.combine(
        // 開発環境向けに色付けする
        process.env.NODE_ENV !== 'production' ? winston.format.colorize() : winston.format.uncolorize(),
        winston.format.simple()
      )
    })
  ],
});

export default logger;

終わりに

ログの重要性、推奨のログ出力先、winstonの設定方法がわかりました。
誰かの役に立てば嬉しい限りです。