前回のLesson6では、エラーハンドリングの手法について学びました。その中で言及した通り、プログラムに起因するシステムエラーは速やかに対処する必要があります。

エラーの原因を探るためには、発生した時刻や場所のログを取る（ロギングする）ことが不可欠です。

そこで今回のLesson7では、アプリケーションを作成する上で避けて通れない「ログ」について学びます。実践に則した内容となっているため、皆さんも手を動かしながら学ぶようにしてください。

ログとは

最初に、ログの簡単な説明から始めましょう。以下の画像を確認してください。

webサーバーであるApacheのログの一部

画像はWebサーバーであるApacheのログです。接続したIPアドレスや時刻、接続先などが記されています。

一般的に、ログが主に担っている役割は以下の4つです。

1. エラーの発生、パフォーマンスの低下の原因を調べる（調査）
2. 障害、パフォーマンスの低下を検知する（監視）
3. 法務的な観点から保存することが定められている
4. データマイニング

上記の通り、ログの役割はエラー原因の調査だけではありません。たとえば、ユーザーの利用状況を把握したり、不正アクセスを防いだりすることもログの役割です。また、日本の法律によって最低90日間はアクセスログを保存しなければなりません。

アプリケーションを開発する上で、ログの実装が必須であることが理解できたはずです。

それでは、Node.jsでログを扱う方法を見ていきましょう。

console.log

Node.jsにおいて、最も手軽にログを出力する方法はconsole.logです。console.logはNode.jsにより用意されている関数で、引数に渡された文字列などを標準出力に書き出します。

一例として、次のようなプログラムについて考えましょう。

sample.js

function double(number) {
  return number * 2;
}

const result = double(5);

console.log("関数doubleの結果: " + result + " です");

Node.jsでプログラムを実行すると、console.logによって以下の計算結果が出力されます。

node ./sample.js
関数doubleの結果: 10 です

以外に思えるかもしれませんが、この標準出力も立派なログです。

ログとは、アプリケーションが実行した処理を記録すること、あるいは記録それ自体のことを指します。したがって、上のプログラムを実行した結果、標準出力へ書き出された内容もログにあたります。

とはいえ、Node.jsには他にもログを扱うための方法が存在します。次のChapterでは、log4jsと呼ばれるモジュールを紹介しましょう。

Chapter1では最も手軽にログを出力する方法として、console.logを紹介しました。簡単なデバッグであればconsole.logで十分ですが、より効率的にログを出力したい場合、外部モジュールの使用をおすすめします。

今回は、Node.jsで配布されている中でも人気のモジュール「log4js」を使ってみましょう。

log4jsのインストール

まずは、npmを使ってlog4jsをインストールしてください。

コンソール（Windows / Mac / Linux）

$ npm install log4js

インストールが完了したら、以下のファイルを作成します。

log.js

const log4js = require("log4js");
const logger = log4js.getLogger();
logger.level = "debug";

function double(number) {
  return number * 2;
}

const result = double(5);
logger.debug("関数doubleの結果: " + result + " です");

コマンドラインからnode log.jsを入力し、上記のプログラムを実行します。添付画像の通り、ログが標準出力に出力されることを確認してください。

出力されたログ

console.logを利用したときに比べて、より多くの情報が出力されています。簡単に解説しましょう。

冒頭の[2022-08-23T09:00:00.000]は、ログを出力した時刻をあらわしています。

その横のDEBUGは、ログレベルの種類をあらわしています。 ログレベルとは、それぞれのログを種類や重要度で分けたものです。console.logと同じように、変数の値を確認したり処理の流れを追いたい場合は、ログレベルを[DEBUG]に設定します。

log4jsの利点として、このログレベルの存在が挙げられます。以下の項目で詳しく見ていきましょう。

ログレベルとその適用例

log4jsでは、以下の通り全部で6種類のログレベルが用意されています。

レベル	出力するログの説明（一例）
fatal	異常終了する事象
error	予期しない実行時エラー
warn	異常と言い切れないが正常ではない予期しない事象
info	処理の開始、終了、ログインなど注目すべき事象
debug	動作状況に関する詳細な情報
trace	デバッグ情報より詳細な情報

実際の開発では、情報の重要度と用途を考慮した上でログレベルを決めます。

たとえば、早急に対応すべきエラーログはメールで通知し、発生したエラーを調査するためのデバッグログはファイルに保存する、といった状況を考えてみましょう。

このとき、即時対応が必要なエラーログは重要度が高く、デバッグログは重要度が低いとみなし、それぞれログレベルの[ERROR]や[DEBUG]に対応させます。

ログ出力のフォーマット

log4jsには、ログレベルに対応する６つのメソッドfatal、error、warn、info、debug、traceがあり、それぞれ次のように記述して利用します。

実際に以下のプログラムを実行してみましょう。

log-level.js

const log4js = require("log4js");
const logger = log4js.getLogger();
logger.level = "trace";

logger.trace("trace");
logger.debug("debug");
logger.info("info");
logger.warn("warn");
logger.error("error");
logger.fatal("fatal");

画像のようなログが標準出力に出力されることを確認してください。

出力されたログ

上の例では、logger.level = "trace"と記述して、ログレベルがtrace以上のログを出力するよう指定しています。

たとえば、logger.level = "error"とすれば、ログレベルがerror以上のerror、fatalのログが出力されるようになります。

ここまで、log4jsを利用してログを出力する方法を見てきました。今回はlog4jsを使いましたが、他にも以下のログモジュールがnpmで提供されています。

• winston
• pino
• bunyan
• npmlog

ログ管理ひとつ取っても、これだけの選択肢があります。開発するアプリケーションに応じて、上手く選定できるといいでしょう。

次のChapterでは、ログをファイルに出力する方法について学びます。

ここまで見てきた例では、ログを標準出力として画面に表示してきました。ログを永続的に保存したい場合、出力先をファイルに変更する必要があります。

ログをファイルに保存することで、必要な情報だけを抽出したり、特定の観点で集計したりといった2次利用することも可能です。

さっそく、log4jsによるファイル出力の方法を見ていきましょう。

log4jsでログをファイルに出力する

log4jsでログをファイルに出力するには、次のように記述します。

log-to-file.js

const log4js = require("log4js");

  log4js.configure({
  appenders: {
    logFile: {
      type: "file",
      filename: "sample-log.log"
    }
  },

  categories: {
    default: {
      appenders: ["logFile"],
      level: "debug"
    }
  }
});

function double(number) {
  return number * 2;
}

const result = double(5);
const logger = log4js.getLogger();
logger.debug("関数doubleの結果: " + result + " です");

記述したら、実際にプログラムを実行してみましょう。同じディレクトリ内にsample-log.logというファイルが生成され、そのファイル内にログが書き込まれているはずです。

ログを標準出力する場合と比べて、log4js.configure以下の記述が増えています。このlog4js.configureがファイル出力の設定を行っている箇所です。

具体的なフォーマットを見てみましょう。ログをファイルに出力するには、appendersとcategoriesの2つを宣言し、log4js.getLoggerメソッドで呼び出す必要があります。

appenders

appendersは、ログの出力先を指定する部分です。

今回は、ログをファイルに出力するためtype: fileと記述し、ファイル名をfilename: sample-log.logと記述して定めています。ログの出力先は複数宣言可能で、ファイルの他にも、メール、標準出力などを出力先として指定できます。

categories

categoriesは、ログの種類を指定する部分です。

カテゴリは複数指定が可能で、それぞれにログレベルと出力先を指定します。また、カテゴリには、少なくとも1つdefaultを含めなければなりません。今回は単純な例として、defaultのカテゴリを1つ指定しています。

カテゴリdefaultを見てください。appendersの部分で、出力先を指定しています。今回は、先ほどファイルに出力するよう記述したlogFileを指定しています。さらに、ログレベルがdebug以上のログを出力するようlevel: debugと記述しています。

default以外のカテゴリを設定する場合、カテゴリ名はログをとる対象（ファイル入出力関連など）やモジュール名単位とすることが多いです。

getLogger

以上の記述が終わったら、log4js.getLogger()メソッドから設定を呼び出します。

log4js.getLogger()と記述することで、log4js.configureに記述した内容が反映されたロガーがインスタンス化されます。

getLogger()の第1引数にカテゴリ名を記述することで、対応するカテゴリのロガーインスタンスを生成します。第1引数に何も記述しなければ、defaultが割り当てられます。

このように、log4jsではログの出力先や種類を細かく設定することが可能です。設定次第では、ログレベルと出力先のファイルを自在に切り替えられるようになります。

ここまで出力したログの形式は、以下の画像のような形式でした。

出力されたログ

このままでも十分に機能しますが、実際の現場におけるロギングでは、より見やすいフォーマットを求められたり、最初からフォーマットが指定されたりする場合があります。

そんなとき、log4jsでは設定によって表示形式の細かい変更が可能です。

今回のChapter4では、log4jsにおけるログフォーマットのを指定方法を見ていきましょう。

log4jsによるフォーマットの指定

log4jsで独自のログ形式を指定するには、以下のように記述します。

my-log-format.js

const log4js = require("log4js");

log4js.configure({
  appenders: {
    logFile: {
      type: "file",
      filename: "sample-log.log",
      layout: {
        type: "pattern",
        pattern:
          "[%d{ISO8601_WITH_TZ_OFFSET}] [SUCCESS] MESSAGE: %m"
      }
    }
  },
  categories: {
    default: {
      appenders: ["logFile"],
      level: "debug"
    }
  }
});

function double(number) {
  return number * 2;
}

const result = double(5);
const logger = log4js.getLogger();

logger.info("関数doubleの結果: " + result + " です");

実際に上記のプログラムを実行してみましょう。次の画像のようなログが「sample-log.log」ファイルに出力されるはずです。

独自に指定した形式のログの画像

独自のログ形式を指定するには、先ほど見たlog4js.configure以下を編集します。

具体的には、appenders以下にlayoutを追加することで可能です。例のようにtype: "pattern"と記述し、"pattern: [%d{ISO8601_WITH_TZ_OFFSET}] ..."など具体的なパターンを指定してください。

パターン指定子

パターンを設定するには、%mや%dといった指定子（変換用の文字）を使用します。たとえば上記の例では、%d{ISO8601_WITH_TZ_OFFSET}によって日付の表示形式を指定しています。

参考として、よく使われる指定子を以下の表にまとめました。実際に先ほどのファイルを編集し、パターンの変化を確かめてみましょう。

パターン	説明
%r	時刻
%d	日付
%p	ログレベル
%c	ログカテゴリ
%m	ログメッセージ
%n	改行
%[...%]	カラーブロックの定義

今回はログの出力フォーマットについて学習しました。表示パターンを少し工夫するだけで、誰でも共有しやすいログが出力できます。

プロジェクトで一貫したログ構造を維持することで、迅速な行動や洞察につながるでしょう。

Lesson7では、一貫してロギングの手法について学んできました。最後のTipsとして、Chapter5では「ログローテーション」に触れておきましょう。

ログローテーションとは

ログローテーションとは、ログファイルの肥大化を避けるため、一定の容量や期間ごとに古いログを削除する仕組みのことです。

もしログローテーションを行わないと、大容量のログファイルがサーバーを圧迫し、深刻な障害を引き起こす可能性があります。実際にサーバーを運用する上で、ログローテーションは不可欠の仕組みと言えるでしょう。

なお、ログローテーションにはロガー内部でファイルを管理する方法と、外部（ログの出力先）でファイルを管理する方法の二通りがあります。本章で扱ってきたlog4jsにはログローテーションの機能が組み込まれており、ロガー内部でのファイル管理が可能です。

ログローテーションの挙動

log4jsでログローテーションを行うには、以下のような記述を行います。

log-rotation.js

const log4js = require("log4js");

log4js.configure({
  appenders: {
  logFile: {
    type: "file",
    filename: "sample-log.log",
      maxLogSize: 600,
      backups: 2,
      compress: true
    }
  },
  categories: {
    default: {
      appenders: ["logFile"],
      level: "debug"
    }
  }
});

function double(number) {
  return number * 2;
}

const result = double(5);
const logger = log4js.getLogger();

logger.debug("関数doubleの結果: " + result + " です");

実際にプログラムを実行してみましょう。一度実行しただけでは、今まで通り「sample-log.log」にログが出力されるだけです。

ファイルサイズの増加を再現するため、繰り返しプログラムを実行してみましょう。「sample-log.log」ファイルにログを追加していくと、やがて「sample-log.log.1.gz」が作成され、「sample-log.log」のログはリセットされます。

さらに実行を続けると、最終的に作成されるログファイルは以下の画像のようになります。

作成されるログファイル

以上がlog4jsによるログローテーションの挙動です。

ログローテーションの設定

先ほどの記述を詳しく見てみましょう。

ログローテーションを設定するためには、log4js.configureのappendersに次のプロパティを追加します。

1. maxLogSize: 1ファイルあたりの上限を指定します。
2. backups: 作成したログファイルの保持数を指定します。
3. compress: ログファイル作成時の圧縮有無を指定します。

今回の設定では、ログファイルのサイズが600バイトを超えた時点で圧縮ファイル（.gz）が作成され、ログファイルはリセットされます、圧縮ファイルは2つまで保持されるため、最終的に上記のログファイルが作成されました。

以上でLesson7の学習は終了です。console.logから始まり、log4jsによる本格的なロギングの実践へと至りました。実際のWebサーバーでは無数のログと対峙することになります。ぜひ本章で学んだ知識を役立ててください。

次のLesson8では、デバッグの方法を学んでいきます。