Ubuntu 20.04でNode.jsアプリケーションをログに記録する方法

紹介

効果的なログソリューションは、どんなアプリケーションでも成功するために不可欠です。 Winstonは、Node.jsアプリケーション向けの多目的なログライブラリであり、人気のあるログソリューションです。Winstonの機能には、複数のストレージオプション、ログレベル、ログクエリ、および組み込みのプロファイラが含まれます。

このチュートリアルでは、Winstonを使用して、このプロセスの一環として作成するNode/Expressアプリケーションをログに記録します。また、Node.js向けのもう1つの人気のあるHTTPリクエストミドルウェアロガーであるMorganとWinstonを組み合わせて、HTTPリクエストデータログを他の情報と統合する方法も紹介します。このチュートリアルを完了すると、Ubuntuサーバー上で小規模なNode/Expressアプリケーションが実行され、Winstonがエラーやメッセージをファイルとコンソールに記録するように実装されます。

前提条件

このチュートリアルに従うには、次のものが必要です:

• 初期サーバーセットアップに従って設定できる、sudo非ルートユーザーを持つUbuntu 20.04サーバー。

• 公式PPA（個人用パッケージアーカイブ）を使用してNode.jsをインストールし、Ubuntu 20.04にNode.jsをインストールする方法、オプション2に説明されています。

ステップ1 — 基本的なNode/Expressアプリの作成

Winstonは、Node.jsで構築されたWebアプリケーションからイベントをログに記録するためによく使用されます。このステップでは、Expressフレームワークを使用してシンプルなNode.js Webアプリケーションを作成します。express-generator、コマンドラインツールを使用してNode/Express Webアプリケーションをすばやく起動します。

前提条件でNode Package Managerがインストールされているため、npmコマンドを使用してexpress-generatorをインストールできます：

sudo npm install express-generator -g

-gフラグは、パッケージをグローバルにインストールします。これは、既存のNodeプロジェクト/モジュールの外部でコマンドラインツールとして使用できることを意味します。

express-generatorをインストールしたら、expressコマンドに続いて、プロジェクトに使用するディレクトリの名前を指定してアプリを作成できます。

express myApp

このチュートリアルでは、プロジェクトの名前をmyAppとします。

npx express-generator myApp

Need to install the following packages:
  express-generator
Ok to proceed? (y)

次に、変更を行うたびにアプリケーションを自動的にリロードするNodemonをインストールします。Node.jsアプリケーションは、ソースコードに変更が加えられるたびに再起動する必要があるため、Nodemonは変更を監視してアプリケーションを再起動します。コマンドラインツールとしてnodemonを使用できるようにしたいので、-gフラグを使用してインストールします。

sudo npm install nodemon -g

アプリケーションを設定するのを終えるために、アプリケーションディレクトリに移動して、以下のように依存関係をインストールします:

cd myApp
npm install

デフォルトでは、express-generator で作成されたアプリケーションはポート 3000 上で実行されますので、ファイアウォールがそのポートをブロックしていないことを確認する必要があります。

ポート 3000 を開くには、次のコマンドを実行します:

sudo ufw allow 3000

これでウェブアプリケーションを開始するために必要なものがすべて揃いました。これを行うには、次のコマンドを実行します:

nodemon bin/www

このコマンドはアプリケーションをポート 3000 で開始します。動作しているかどうかを確認するには、ブラウザを http://your_server_ip:3000 に向けてください。次のようなものが表示されるはずです:

この時点で、このチュートリアルの残りの部分に対してサーバーへの2番目のSSHセッションを開始し、新しいセッションでウェブアプリケーションを実行してください。先ほど開始したアプリケーションは、元のセッションで実行されます。この記事の残りの部分では、アプリケーションを実行している初期のSSHセッションをセッションAと呼びます。セッションAでのコマンドは、このように濃いネイビーの背景に表示されます:

nodemon bin/www

新しいSSHセッションでは、コマンドを実行したりファイルを編集したりします。このセッションをセッションBと呼びます。セッションBでのコマンドは、このように薄い青い背景に表示されます:

cd ~/myApp

特に指定がない限り、残りのすべてのコマンドはセッションBで実行します。

このステップでは、基本的なアプリケーションを作成しました。次に、カスタマイズします。

ステップ2 — ログ変数のカスタマイズ

デフォルトのアプリケーションは、express-generator によって作成されますが、これは良いスタートです。ただし、必要に応じて正しいロガーを呼び出すようにアプリケーションをカスタマイズする必要があります。

express-generator には、すべてのHTTPリクエストに関するデータをログに記録するために使用するMorgan HTTPログミドルウェアが含まれています。Morganは出力ストリームをサポートしているため、Winstonに組み込まれているストリームサポートと素晴らしい組み合わせを作ります。これにより、Winstonでログに記録するHTTPリクエストデータを他のログと統合することができます。

express-generator のボイラープレートでは、morgan パッケージを参照するときに logger 変数が使用されています。しかし、morgan と winston 、どちらもロギングパッケージですので、どちらか一方を logger と呼ぶのは混乱を招く可能性があります。どの変数を指定するかを明示するには、app.js ファイルを編集して変数の宣言を変更します。

app.js を編集するには、nano またはお好みのテキストエディターを使用してください。

nano ~/myApp/app.js

ファイルの先頭付近にある次の行を見つけます：

...
var logger = require('morgan');
...

変数名を logger から morgan に変更します：

...
var morgan = require('morgan');
...

この更新により、宣言された変数 morgan が Morgan リクエストロガーにリンクされた require() メソッドを呼び出すように指定されます。

ファイル内で変数loggerがどこで参照されているかを探し、それをmorganに変更する必要があります。また、morganパッケージで使用されているログ形式をcombinedに変更する必要があります。これは標準のApacheログ形式であり、リモートIPアドレスやユーザーエージェントHTTPリクエストヘッダーなど、ログに有用な情報が含まれます。

これを行うには、次の行を見つけます:

...
app.use(logger('dev'));
...

それを以下のように更新します:

...
app.use(morgan('combined'));
...

これらの変更により、Winston構成を統合した後でも、いつでもどのログパッケージが参照されているかを理解するのに役立ちます。

作業が完了したら、ファイルを保存して閉じます。

これでアプリがセットアップされましたので、Winstonを使用する準備が整いました。

ステップ3 — Winstonのインストールと設定

このステップでは、Winstonをインストールして設定します。また、winstonパッケージの構成オプションを調査し、ファイルとコンソールに情報を記録するためのロガーを作成します。

winstonを次のコマンドでインストールします:

cd ~/myApp
npm install winston

アプリケーションのサポートやユーティリティ構成ファイルを特別なディレクトリに保管することが役立ちます。winston構成を含むconfigフォルダーを作成してください。

mkdir ~/myApp/config

次に、ログファイルを含むフォルダーを作成します：

mkdir ~/myApp/logs

最後に、app-root-pathをインストールします：

npm install app-root-path --save

app-root-pathパッケージは、Node.jsでパスを指定する際に便利です。このパッケージは直接的にはWinstonと関係ありませんが、Node.jsでファイルのパスを決定する際に役立ちます。プロジェクトのルートからWinstonログファイルの場所を指定し、見栄えの悪い相対パス構文を回避するために使用します。

ログ処理の構成が整ったので、設定を定義できます。編集用に~/myApp/config/winston.jsを作成し、開きます：

nano ~/myApp/config/winston.js

winston.jsファイルには、winstonの設定が含まれます。

次に、app-root-pathおよびwinstonパッケージを要求するための次のコードを追加します：

const appRoot = require('app-root-path');
const winston = require('winston');

これらの変数が用意されたら、転送の構成設定を定義できます。転送はWinstonによって導入された概念で、ログの保存/出力メカニズムを指します。Winstonには、Console, File, HTTP, Streamの4つのコアトランスポートが組み込まれています。

このチュートリアルでは、コンソールトランスポートとファイルトランスポートに焦点を当てます。コンソールトランスポートは情報をコンソールに記録し、ファイルトランスポートは指定されたファイルに情報を記録します。各トランスポート定義には、ファイルサイズ、ログレベル、ログ形式などの構成設定が含まれる可能性があります。

各トランスポートに使用する設定の概要を次に示します：

• level: ログメッセージのレベル。
• filename: ログデータを書き込むファイル。
• handleExceptions: 未処理の例外をキャッチしてログに記録する。
• maxsize: 新しいファイルが作成される前のログファイルの最大サイズ（バイト単位）。
• maxFiles: ログファイルサイズが超過したときに作成されるファイルの数の制限。
• format: ログ出力のフォーマット方法。

ログレベルはメッセージの優先度を示し、整数で表されます。 Winstonは、0から6までの優先度が付けられたnpmログレベルを使用します（高い順から低い順）：

• 0: エラー
• 1: 警告
• 2: 情報
• 3: HTTP
• 4: 冗長
• 5: デバッグ
• 6: くだらない

特定のトランスポートのログレベルを指定すると、そのレベル以上のものがログに記録されます。 たとえば、infoのレベルを設定すると、error、warn、またはinfoのレベルのものがすべてログに記録されます。

ログレベルは、ロガーを呼び出すときに指定されます。 つまり、次のコマンドを実行してエラーを記録できます：logger.error('テストエラーメッセージ')。

まだ設定ファイル内で、winston構成内のfileとconsoleトランスポートの設定を定義するために次のコードを追加します。

...
// 各輸送手段（ファイル、コンソール）のカスタム設定を定義する
const options = {
  file: {
    level: "info",
    filename: `${appRoot}/logs/app.log`,
    handleExceptions: true,
    maxsize: 5242880, // 5MB
    maxFiles: 5,
    format: winston.format.combine(
      winston.format.timestamp(),
      winston.format.json()
    ),
  },
  console: {
    level: "debug",
    handleExceptions: true,
    format: winston.format.combine(
      winston.format.colorize(),
      winston.format.simple()
    ),
  },
};

次に、options変数で定義されたプロパティを使用して、ファイルとコンソールの輸送手段を持つ新しいwinstonロガーをインスタンス化するための次のコードを追加します：

...
// 上記で定義された設定を使用して新しい Winston ロガーをインスタンス化する
const logger = winston.createLogger({
  transports: [
    new winston.transports.File(options.file),
    new winston.transports.Console(options.console),
  ],
  exitOnError: false, // ハンドルされた例外で終了しない
});

デフォルトでは、morganはコンソールにのみ出力されるため、morgan が生成した出力をwinstonログファイルに取得できるようにするストリーム関数を定義します。出力を両方の輸送手段（ファイルとコンソール）で受け取るためにinfoレベルを使用します。以下のコードを設定ファイルに追加します：

...
// 'morgan' が使用する 'write' 関数を持つストリームオブジェクトを作成する
logger.stream = {
  write: function(message, encoding) {
    // 出力が両方の輸送手段（ファイルとコンソール）によって受け取られるように 'info' ログレベルを使用する
    // （ファイルとコンソール）
    logger.info(message);
  },
};

最後に、ロガーをエクスポートしてアプリケーションの他の部分で使用できるように以下のコードを追加します：

...
module.exports = logger;

完成したwinston構成ファイルは次のようになります：

const appRoot = require("app-root-path");
const winston = require("winston");

// 各輸送方法（ファイル、コンソール）のカスタム設定を定義する
const options = {
  file: {
    level: "info",
    filename: `${appRoot}/logs/app.log`,
    handleExceptions: true,
    maxsize: 5242880, // 5MB
    maxFiles: 5,
    format: winston.format.combine(
      winston.format.timestamp(),
      winston.format.json()
    ),
  },
  console: {
    level: "debug",
    handleExceptions: true,
    format: winston.format.combine(
      winston.format.colorize(),
      winston.format.simple()
    ),
  },
};

// 上記で定義された設定を使用して新しい Winston ロガーをインスタンス化する
const logger = winston.createLogger({
  transports: [
    new winston.transports.File(options.file),
    new winston.transports.Console(options.console),
  ],
  exitOnError: false, // ハンドルされた例外で終了しない
});

// 'morgan' によって使用される 'write' 関数を持つストリームオブジェクトを作成する
logger.stream = {
  write: function (message, encoding) {
    // 'info' ログレベルを使用するため、出力は両方の輸送方法（ファイルおよびコンソール）で受け取られる
    //（ファイルおよびコンソール）の輸送に出力されるログレベルを 'info' に設定する
    logger.info(message);
  },
};

module.exports = logger;

保存してファイルを閉じる。

これで、ロガーが設定されましたが、アプリケーションはまだそれを認識しておらず、またその使用方法もわかっていません。したがって、ロガーをアプリケーションと統合する必要があります。

ステップ4 — アプリケーションへの Winston の統合

ロガーをアプリケーションで動作させるには、express がそれを認識する必要があります。ステップ2で、express の構成が app.js にあることがわかりましたので、このファイルにロガーをインポートできます。

編集するためにファイルを開きます：

nano ~/myApp/app.js

他の require 文と一緒にファイルの先頭付近に winston 変数の宣言を追加します。

...
var winston = require('./config/winston');
...

最初にwinstonを使用する場所はmorganです。まだapp.jsにいて、次の行を見つけてください：

...
app.use(morgan('combined'));
...

streamオプションを含めるように更新します：

...
app.use(morgan('combined', { stream: winston.stream }));
...

ここでは、winstonの構成の一部として作成したストリームインターフェースをstreamオプションに設定します。

ファイルを保存して閉じます。

このステップでは、ExpressアプリケーションをWinstonと連携するように設定しました。次に、ログデータを確認します。

ステップ5 — ログデータへのアクセスとカスタムログメッセージの記録

アプリケーションが構成されたので、いくつかのログデータを確認する準備が整いました。このステップでは、ログエントリを確認し、サンプルのカスタムログメッセージを設定します。

ウェブブラウザでページをリロードすると、SSHセッションAのコンソールに次の出力と同様のものが表示されるはずです：

Output
[nodemon] restarting due to changes...
[nodemon] starting `node bin/www`
info: ::1 - - [25/Apr/2022:18:10:55 +0000] "GET / HTTP/1.1" 200 170 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/100.0.4896.127 Safari/537.36"

info: ::1 - - [25/Apr/2022:18:10:55 +0000] "GET /stylesheets/style.css HTTP/1.1" 304 - "http://localhost:3000/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/100.0.4896.127 Safari/537.36"

ここには2つのログエントリがあります：1つ目はHTMLページへのリクエストのためのもので、2つ目は関連するスタイルシートのためのものです。各転送がinfoレベルのログデータを処理するように構成されているので、~/myApp/logs/app.logにあるファイル転送でも同様の情報が表示されるはずです。

ログファイルの内容を表示するには、次のコマンドを実行します：

tail ~/myApp/logs/app.log

tailは、ファイルの末尾の部分をターミナルに出力します。

次のようなものが表示されるはずです:

{"level":"info","message":"::1 - - [25/Apr/2022:18:10:55 +0000] \"GET / HTTP/1.1\" 304 - \"-\" \"Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/100.0.4896.127 Safari/537.36\"\n","timestamp":"2022-04-25T18:10:55.573Z"}
{"level":"info","message":"::1 - - [25/Apr/2022:18:10:55 +0000] \"GET /stylesheets/style.css HTTP/1.1\" 304 - \"http://localhost:3000/\" \"Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/100.0.4896.127 Safari/537.36\"\n","timestamp":"2022-04-25T18:10:55.588Z"}

ファイル転送の出力は、ファイル転送構成のformatオプションでwinston.format.json()を使用したため、JSONオブジェクトとして書き込まれます。JSONについての詳細は、JSON入門で学ぶことができます。

これまでのところ、ロガーはHTTPリクエストと関連データのみを記録しています。この情報はログに含めておくと便利です。

将来的には、エラーやデータベースクエリのパフォーマンスのプロファイリングなど、カスタムログメッセージを記録したい場合があります。たとえば、エラーハンドラルートからロガーを呼び出します。デフォルトでは、express-generatorパッケージにはすでに404や500のエラーハンドラルートが含まれているので、それを使用します。

~/myApp/app.jsファイルを開きます:

nano ~/myApp/app.js

次のようなコードブロックをファイルの最下部で見つけます:

...
// error handler
app.use(function(err, req, res, next) {
  // set locals, only providing error in development
  res.locals.message = err.message;
  res.locals.error = req.app.get('env') === 'development' ? err : {};

  // render the error page
  res.status(err.status || 500);
  res.render('error');
});
...

このセクションは、最終的なエラーハンドリングルートであり、最終的にエラーレスポンスをクライアントに送信します。すべてのサーバーサイドエラーはこのルートを通過するため、ここにwinstonロガーを含めるのは良いアイデアです。

今、エラーに対処しているので、error ログレベルを使用することを希望します。両方の転送は error レベルのメッセージを記録するように設定されているため、コンソールとファイルログに出力が表示されるはずです。

ログには、次のような情報を含めることができます:

• err.status: HTTP エラーのステータスコード。既存のものがない場合は、デフォルトで 500 を使用します。
• err.message: エラーの詳細。
• req.originalUrl: リクエストされた URL。
• req.path: リクエスト URL のパス部分。
• req.method: リクエストの HTTP メソッド (GET、POST、PUT など)。
• req.ip: リクエストのリモート IP アドレス。

エラーハンドラー ルートを winston ロギングを含めるように更新してください:

...
// エラーハンドラー
app.use(function(err, req, res, next) {
  // ローカルを設定して、開発中にエラーのみを提供します
  res.locals.message = err.message;
  res.locals.error = req.app.get('env') === 'development' ? err : {};

  // winston ロギングを含める
  winston.error(
    `${err.status || 500} - ${err.message} - ${req.originalUrl} - ${req.method} - ${req.ip}`
  );

  // エラーページをレンダリング
  res.status(err.status || 500);
  res.render('error');
});
...

ファイルを保存して閉じてください。

このプロセスをテストするために、プロジェクト内の存在しないページにアクセスしようとしてください。存在しないページにアクセスすると、404 エラーが発生します。Web ブラウザで、次の URL にアクセスしようとしてください: http://your_server_ip:3000/foo。express-generator によって生成されたボイラープレートのおかげで、アプリケーションはこのようなエラーに対応するように設定されています。

あなたのブラウザは、次のようなエラーメッセージを表示します:

SSHセッションAのコンソールを見ると、エラーのログエントリが表示されます。 colorize フォーマットが適用されているため、簡単に見つけることができます:

Output
[nodemon] starting `node bin/www`
error: 404 - Not Found - /foo - GET - ::1
info: ::1 - - [25/Apr/2022:18:08:33 +0000] "GET /foo HTTP/1.1" 404 982 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/100.0.4896.127 Safari/537.36"

info: ::1 - - [25/Apr/2022:18:08:33 +0000] "GET /stylesheets/style.css HTTP/1.1" 304 - "http://localhost:3000/foo" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/100.0.4896.127 Safari/537.36"

ファイルロガーについては、tail コマンドを再度実行すると、新しいログレコードが表示されます:

tail ~/myApp/logs/app.log

次のようなメッセージが表示されます:

{"level":"error","message":"404 - Not Found - /foo - GET - ::1","timestamp":"2022-04-25T18:08:33.508Z"}

エラーメッセージには、エラーハンドラの一部として winston に明示的にログ記録するように指示したすべてのデータが含まれます。この情報には、エラーステータス (404 – Not Found)、要求されたURL (localhost/foo)、リクエストメソッド (GET)、リクエストを行ったIPアドレス、およびリクエストが行われたタイムスタンプが含まれます。

結論

このチュートリアルでは、シンプルなNode.jsウェブアプリケーションを構築し、アプリケーションのパフォーマンスに対する洞察を提供する効果的なツールとして機能するWinstonログソリューションを統合しました。

アプリケーションのために堅牢なロギングソリューションを構築するためには、さらに多くのことができます。特に、ニーズがより複雑になるにつれて。Winstonトランスポートについて詳しくは、Winstonトランスポートドキュメントを参照してください。独自のトランスポートを作成するには、カスタムトランスポートの追加を参照してください。HTTPコアトランスポートで使用するためのHTTPエンドポイントを作成するには、winstondを参照してください。Winstonをプロファイリングツールとして使用するには、プロファイリングを参照してください。