log4js-nodeでロギングしてみる

VPN上で動作させる用のCLIツールを作っているけど、
console.logだと実行日時とか残らないので、
いろいろ試してみたときの備忘録(*´ω｀*)

いろいろ見てみたけど、log4jsがよさそう

• log4js-node/log4js-node: A port of log4js to node.js

log4jsの選定理由

選んだ理由はこんな感じ。

• メンテナンスされている
• HTTPサーバじゃなくても利用できる
• 時間/LogLevelを表示できる
• ログのフォーマットをカスタマイズできる
• コンソールとファイルに同時に出力できる
• ファイルのローテーションをしてくれる

このあたりを比較してみたけど、
ローテーションまで標準でしてくれるのはlog4jsだけっぽかった。

• log4js vs logging vs loglevel vs morgan vs pino vs winston | npm trends

それ以外の場合は、logrotateを併用すればよさそう。

• logrotate入門 #Linux - Qiita

インストール

npm install log4js

使い方

シンプルな使い方はこんな感じ

import log4js from "log4js";

// loggerインスタンスの取得
const logger = log4js.getLogger();

// log levelの指定: error以上のみ出力
logger.level = 'error'

// level別のログ出力
logger.trace("Entering cheese testing");
logger.debug("Got cheese.");
logger.info("Cheese is Comté.");
logger.warn("Cheese is quite smelly.");
logger.error("Cheese is too ripe!");
logger.fatal("Cheese was breeding ground for listeria.");

// loggerのシャットダウン処理(flush処理)
log4js.shutdown((err) => {
  if (err) throw err
  process.exit(0)
})

// [2010-01-17 11:43:37.987] [ERROR] cheese - Cheese is too ripe!
// [2010-01-17 11:43:37.990] [FATAL] cheese - Cheese was breeding ground for listeria.

log4jsの用語

用語についての説明はこのあたりに。

• Terminology | log4js-node

Level

ログの重要度(severity)や優先度(priority)。
カテゴリごとに扱うログレベルが決まっている。

Category

ログイベントをグループ化するラベル。モジュール(例: auth、http)別とかで利用できる。
同じカテゴリのログイベントは、同一のAppenderに送られる。

カテゴリ名は、ドット区切りで階層化できる(myapp.submoduleなど)

カテゴリを指定して取得したLoggerを使う感じ。(デフォルトはdefaultカテゴリ)
const logger = log4js.getLogger("my-category");

Appender

ログイベントを出力を担当。
標準出力、ファイルなどの出力先の指定や
ログのフォーマット(Layout)などを指定できる。

1つのカテゴリに複数のAppender(コンソールとファイルなど)を設定でできる。

Logger

メインのインターフェース。getLogger()で取得できるインスタンス。

Layout

ログイベントのフォーマット。Appenderと1対1の関係。

LogEvent

Loggerを使って送るログのデータ。
ログレベル、タイムスタンプ、データなどを含む。

カスタマイズ

コンソールとファイルに独自のフォーマットで出力するカスタマイズはこんな感じ。

import log4js, { type Logger } from "log4js";
import { join } from "path";

// ********************************************************
// * Loggerの設定
// ********************************************************
// ログファイルの出力先
const logDirectory = join(process.env.LOG_DIR || process.cwd(), "logs");
// ログレベルの指定
const logLevel = process.env.LOG_LEVEL || "all";
// ログファイルの名前
const logFileName = "my-app.log";

// ログのフォーマット: コンソールとファイルで共通
const logLayout = {
  type: "pattern",
  // タイムゾーンも表示するように変更
  pattern: "[%d{ISO8601_WITH_TZ_OFFSET}] %-5p %m",
};

// log4jsのカスタマイズ
log4js.configure({
  // Appenderの設定
  appenders: {
    // コンソールに出力するアペンダ
    console: { type: "console", layout: logLayout, },
    // ファイルに出力するアペンダ
    app: {
      type: "dateFile",
      layout: logLayout,
      filename: join(logDirectory, logFileName),
      pattern: "yyyy-MM-dd", // 日毎にローテーション
      keepFileExt: true, // .logが最後に来るように指定
      compress: true, // ローテーションしたログファイルはgzip
      daysToKeep: 30, // バックアップは30日分まで保持
    },
  },
  // Categoryの設定
  categories: {
    default: {
      // コンソールとファイルの両方に出力
      appenders: ["console", "app"],
      level: logLevel,
      enableCallStack: true, // スタックトレースの表示を有効化
    },
  },
});

// Categoryが'default'のLoggerを取得
const logger = log4js.getLogger();

// ********************************************************
// * consoleの上書き
// ********************************************************
console.log = (msg: any, ...data: any[]) => !!data.length ? logger.debug(msg, data) : logger.debug(msg);
console.debug = (msg: any, ...data: any[]) => !!data.length ? logger.debug(msg, data) : logger.debug(msg);
console.info = (msg: any, ...data: any[]) => !!data.length ? logger.info(msg, data) : logger.info(msg);
console.warn = (msg: any, ...data: any[]) => !!data.length ? logger.warn(msg, data) : logger.warn(msg);
console.error = (msg: any, ...data: any[]) => !!data.length ? logger.error(msg, data) : logger.error(msg);

// ********************************************************
// * メインの処理
// ********************************************************
async function main() {
  // ...略
}

// ********************************************************
// * Graceful shutdown
// ********************************************************
function close(code?: number, event?: NodeJS.Signals) {
  log4js.shutdown((error) => {
    if (error) throw error;
    process.exit(code);
  });
}

process.on("SIGINT", () => close(1, "SIGINT")); // Ctrl + C
process.on("SIGHUP", () => close(1, "SIGHUP")); // close terminal
process.on("SIGTERM", () => close(1, "SIGTERM")); // kill process(15)

// ********************************************************
// * 処理の開始
// ********************************************************
mainAutoUpdate()
  .then((_) => close())
  .catch((_error) => {
    console.error(_error);
    close(1);
  });

この設定で実行すると、
./logs/my-app.logや
./logs/my-app.2024-01-01.log.gz
が出力されるようになる。

keepFileExt: false(デフォルト)だと、
./logs/my-app.log.2024-01-01.gz
という形になる。。

daysToKeep: 30を超えたバックアップファイル(.log.gz)は、
自動的に削除してくれる。

log4jsの設定

基本的には出力先をAppenderに追加して、
Appenderを利用するCategoryを設定/追加する感じでOK

AppenderのtypeもconsoleやdateFile以外にもたくさんある。

• Appenders | log4js-node

フォーマット(Layout)については、こっち。ファイル名(%f)や行数(%l)なども表示できる。

• Layouts | log4js-node

Categoryはこちら。

• Categories | log4js-node

consoleの上書き

他のpackageで出力されるconsole.debugとかもloggerで拾えるように、
consoleの各メソッドを上書きする。

全てには対応できないが、自分が使う範囲だとこれで十分な感じ。

インポート時に吐いているログは、上書き前のため、
loggerの設定後に、dynamic importを使ってやるとよい感じになる。

async function main() {
  // ...略
  const { myFunc } = await import("./my-func");
  awiat myFunc();
}

Graceful shutdown対応

killされたりしたときにもログが欠落しないように、
Graceful shutdownの対応も追加。

Graceful shutdownについてはこちらの記事に。

• Node.jsでgraceful shutdown - くらげになりたい。

---

以上!! これでロギングもだいぶ楽になる。。(*´ω｀*)

参考にしたサイトさま

• log4js-node/log4js-node: A port of log4js to node.js
  • log4js-node by log4js-node
• log4js-node の使い方【v5.2.2】 #JavaScript - Qiita
• 個人的log4js設定
• log4js vs logging vs loglevel vs morgan vs pino vs winston | npm trends
• util.inspect 便利 #Node.js - Qiita