Winstonを使用してNode.jsアプリケーションをログに記録する方法

序章

効果的なロギングソリューションは、あらゆるアプリケーションの成功に不可欠です。このガイドでは、 Winston と呼ばれるロギングパッケージに焦点を当てます。これは、非常に用途の広いロギングライブラリであり、NPMダウンロード統計に基づいてNode.jsアプリケーションで利用できる最も人気のあるロギングソリューションです。 Winstonの機能には、複数のストレージオプションとログレベル、ログクエリ、さらには組み込みのプロファイラーのサポートが含まれます。このチュートリアルでは、Winstonを使用して、このプロセスの一部として作成するNode / Expressアプリケーションをログに記録する方法を示します。また、Winstonを Morgan と呼ばれるNode.js用の別の人気のあるHTTPリクエストミドルウェアロガーと組み合わせて、HTTPリクエストデータログを他の情報と統合する方法についても見ていきます。

このチュートリアルを完了すると、Ubuntuサーバーで小さなNode/Expressアプリケーションを実行できるようになります。また、Winstonを実装して、エラーとメッセージをファイルとコンソールに記録します。

前提条件

このガイドを開始する前に、次のものが必要です。

Ubuntu16.04初期サーバーセットアップガイドに従ってセットアップされた1つのUbuntu16.04サーバー。これには、sudo非rootユーザーとファイアウォールが含まれます。
Ubuntu 16.04にNode.jsをインストールする方法で説明されているように、Node.jsは公式PPAを使用してインストールされます。

これらの前提条件が整ったら、アプリケーションをビルドしてWinstonをインストールできます。

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

Winstonの一般的な用途は、Node.jsで構築されたWebアプリケーションからのイベントをログに記録することです。 Winstonを組み込む方法を完全に示すために、Expressフレームワークを使用して単純なNode.jsWebアプリケーションを作成します。基本的なWebアプリケーションを実行するために、Node /ExpressWebアプリケーションをすばやく実行するためのコマンドラインツールであるexpress-generatorを使用します。前提条件の一部としてNodePackage Manager をインストールしたため、npmコマンドを使用してexpress-generatorをインストールできます。また、-gフラグを使用します。これにより、パッケージがグローバルにインストールされ、既存のNodeプロジェクト/モジュールの外部でコマンドラインツールとして使用できるようになります。次のコマンドを使用してパッケージをインストールします。

sudo npm install express-generator -g

express-generatorがインストールされている場合、expressコマンドに続けて、プロジェクトに使用するディレクトリの名前を使用してアプリを作成できます。これにより、開始するために必要なすべてのものを備えたアプリケーションが作成されます。

express myApp

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

sudo npm install nodemon -g

アプリケーションのセットアップを完了するには、アプリケーションディレクトリに移動し、次のように依存関係をインストールします。

cd myApp
npm install

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

sudo ufw allow 3000

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

nodemon bin/www

これにより、ポート3000で実行されているアプリケーションが起動します。 Webブラウザでhttp://your_server_ip:3000に移動すると、動作していることをテストできます。次のように表示されます。

この時点で、サーバーへの2番目のSSHセッションを開始して、このチュートリアルの残りの部分で使用し、元のセッションで実行を開始したばかりのWebアプリケーションを残しておくことをお勧めします。この記事の残りの部分では、これまで使用していて、現在アプリケーションを実行しているSSHセッションをセッションAと呼びます。コマンドの実行とファイルの編集に新しいSSHセッションを使用し、このセッションをセッションBと呼びます。特に明記されていない限り、残りのすべてのコマンドはセッションBで実行する必要があります。

ステップ2-Node.jsアプリケーションのカスタマイズ

express-generatorによって作成されたデフォルトのアプリケーションは、私たちが始めるのに素晴らしい仕事をしており、すべてのHTTPリクエストに関するデータをログに記録するために使用するMorganHTTPロギングミドルウェアも含まれています。また、Morganは出力ストリームをサポートしているため、Winstonに組み込まれているストリームサポートとの優れたペアリングを実現し、HTTPリクエストデータログをWinstonでログに記録するために選択した他のログと統合できるようにします。

デフォルトでは、express-generatorボイラープレートは、morganパッケージを参照するときに、変数loggerを使用します。どちらもロギングパッケージであるmorganとwinstonを使用するため、どちらか一方をloggerと呼ぶと混乱する可能性があります。それでは、プロジェクトのルートにあるapp.jsファイルを編集し、いくつかの変更を加えて、これを変更しましょう。

app.jsを開いて編集するには、nanoコマンドを使用します。

nano ~/myApp/app.js

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

〜/ myApp / app.js

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

次のように変更します。

〜/ myApp / app.js

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

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

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

〜/ myApp / app.js

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

次のように変更します。

〜/ myApp / app.js

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

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

CTRL-X、Y、ENTERの順に入力して、ファイルを終了して保存します。

アプリがセットアップされたので、Winstonでの作業を開始する準備が整いました。

ステップ3—Winstonのインストールと構成

これで、Winstonをインストールして構成する準備が整いました。このステップでは、winstonパッケージの一部として利用できるいくつかの構成オプションを調べ、ファイルとコンソールに情報を記録するロガーを作成します。

winstonをインストールするには、次のコマンドを実行します。

cd ~/myApp
npm install winston

アプリケーションのあらゆる種類のサポートまたはユーティリティ構成ファイルを特別なディレクトリに保持すると便利なことが多いので、winston構成を含むconfigフォルダーを作成しましょう。

mkdir ~/myApp/config

次に、winston構成を含むファイルを作成しましょう。これをwinston.jsと呼びます。

touch ~/myApp/config/winston.js

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

mkdir ~/myApp/logs

最後に、Node.jsでパスを指定するときに役立つパッケージであるapp-root-pathをインストールしましょう。このパッケージはWinstonに直接関連していませんが、Node.jsコードでファイルへのパスを指定するときに非常に役立ちます。これを使用して、プロジェクトのルートからWinstonログファイルの場所を指定し、醜い相対パス構文を回避します。

npm install app-root-path --save

ロギングの処理方法を構成するために必要なものはすべて整っているので、構成設定の定義に進むことができます。編集のために~/myApp/config/winston.jsを開くことから始めます。

 nano ~/myApp/config/winston.js

次に、app-root-pathおよびwinstonパッケージが必要です。

〜/ myApp / config / winston.js

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

これらの変数を設定すると、トランスポートの構成設定を定義できます。トランスポートは、ログに使用されるストレージ/出力メカニズムを参照するWinstonによって導入された概念です。 Winstonには、 console 、 file 、およびHTTPの3つのコアトランスポートが付属しています。このチュートリアルでは、コンソールトランスポートとファイルトランスポートに焦点を当てます。コンソールトランスポートは情報をコンソールに記録し、ファイルトランスポートは情報を指定されたファイルに記録します。各トランスポート定義には、ファイルサイズ、ログレベル、ログ形式などの独自の構成設定を含めることができます。各トランスポートに使用する設定の概要は次のとおりです。

level-ログに記録するメッセージのレベル。
filename-ログデータの書き込みに使用するファイル。
handleExceptions-未処理の例外をキャッチしてログに記録します。
json-ログデータをJSON形式で記録します。
maxsize -新しいファイルが作成される前のログファイルの最大サイズ（バイト単位）。
maxFiles-ログファイルのサイズを超えたときに作成されるファイルの数を制限します。
colorize-出力を色付けします。これは、コンソールログを確認するときに役立ちます。

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

0 ：エラー
1 ：警告
2 ：情報
3 ：冗長
4 ：デバッグ
5 ：ばかげている

特定のトランスポートのログレベルを指定すると、そのレベル以上のすべてがログに記録されます。たとえば、infoのレベルを指定すると、レベルerror、warn、またはinfoのすべてがログに記録されます。ロガーを呼び出すときにログレベルが指定されます。つまり、エラーを記録するために次の操作を実行できます：logger.error('test error message')。

fileおよびconsoleトランスポートの構成設定は、winston構成で次のように定義できます。

〜/ myApp / config / winston.js

...
var options = {
  file: {
    level: 'info',
    filename: `${appRoot}/logs/app.log`,
    handleExceptions: true,
    json: true,
    maxsize: 5242880, // 5MB
    maxFiles: 5,
    colorize: false,
  },
  console: {
    level: 'debug',
    handleExceptions: true,
    json: false,
    colorize: true,
  },
};

次に、options変数で定義されたプロパティを使用して、ファイルおよびコンソールトランスポートを使用して新しいwinstonロガーをインスタンス化します。

〜/ myApp / config / winston.js

...
var logger = new winston.Logger({
  transports: [
    new winston.transports.File(options.file),
    new winston.transports.Console(options.console)
  ],
  exitOnError: false, // do not exit on handled exceptions
});

デフォルトでは、morganはコンソールにのみ出力するので、morganで生成された出力をwinstonログファイルに取り込むことができるストリーム関数を定義しましょう。 infoレベルを使用して、出力が両方のトランスポート（ファイルとコンソール）で取得されるようにします。

〜/ myApp / config / winston.js

...
logger.stream = {
  write: function(message, encoding) {
    logger.info(message);
  },
};

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

〜/ myApp / config / winston.js

...
module.exports = logger;

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

〜/ myApp / config / winston.js

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

// define the custom settings for each transport (file, console)
var options = {
  file: {
    level: 'info',
    filename: `${appRoot}/logs/app.log`,
    handleExceptions: true,
    json: true,
    maxsize: 5242880, // 5MB
    maxFiles: 5,
    colorize: false,
  },
  console: {
    level: 'debug',
    handleExceptions: true,
    json: false,
    colorize: true,
  },
};

// instantiate a new Winston Logger with the settings defined above
var logger = new winston.Logger({
  transports: [
    new winston.transports.File(options.file),
    new winston.transports.Console(options.console)
  ],
  exitOnError: false, // do not exit on handled exceptions
});

// create a stream object with a 'write' function that will be used by `morgan`
logger.stream = {
  write: function(message, encoding) {
    // use the 'info' log level so the output will be picked up by both transports (file and console)
    logger.info(message);
  },
};

module.exports = logger;

終了してファイルを保存します。

これでロガーが構成されましたが、アプリケーションはまだロガーやその使用方法を認識していません。次に、ロガーをアプリケーションと統合します。

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

ロガーをアプリケーションで動作させるには、expressにそれを認識させる必要があります。手順2で、express構成がapp.jsにあることをすでに確認したので、ロガーをこのファイルにインポートしましょう。次のコマンドを実行して、編集用にファイルを開きます。

nano ~/myApp/app.js

ファイルの先頭近くにあるwinstonを、他のrequireステートメントとともにインポートします。

〜/ myApp / app.js

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

実際にwinstonを使用する最初の場所は、morganです。 streamオプションを使用し、winston構成の一部として作成したストリームインターフェイスに設定します。これを行うには、次の行を見つけます。

〜/ myApp / app.js

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

これに変更します：

〜/ myApp / app.js

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

終了してファイルを保存します。

ログデータを表示する準備ができました。 Webブラウザでページをリロードすると、SSHセッションAのコンソールに次のようなものが表示されます。

Output[nodemon] restarting due to changes...
[nodemon] starting `node bin/www`
info: ::ffff:72.80.124.207 - - [07/Mar/2018:17:29:36 +0000] "GET / HTTP/1.1" 304 - "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.186 Safari/537.36"

info: ::ffff:72.80.124.207 - - [07/Mar/2018:17:29:37 +0000] "GET /stylesheets/style.css HTTP/1.1" 304 - "http://167.99.4.120:3000/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.186 Safari/537.36"

ここには2つのログエントリがあります。1つはHTMLページへのリクエスト用で、もう1つは付随するスタイルシート用です。各トランスポートはinfoレベルのログデータを処理するように構成されているため、~/myApp/logs/app.logにあるファイルトランスポートにも同様の情報が表示されます。ただし、ファイルトランスポート構成でjson: trueを指定したため、ファイルトランスポートの出力はJSONオブジェクトとして記述する必要があります。 JSONの詳細については、JSONチュートリアルの概要をご覧ください。ログファイルの内容を表示するには、次のコマンドを実行します。

tail ~/myApp/logs/app.log

次のようなものが表示されます。

{"level":"info","message":"::ffff:72.80.124.207 - - [07/Mar/2018:17:29:36 +0000] \"GET / HTTP/1.1\" 304 - \"-\" \"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.186 Safari/537.36\"\n","timestamp":"2018-03-07T17:29:36.962Z"}
{"level":"info","message":"::ffff:72.80.124.207 - - [07/Mar/2018:17:29:37 +0000] \"GET /stylesheets/style.css HTTP/1.1\" 304 - \"http://167.99.4.120:3000/\" \"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.186 Safari/537.36\"\n","timestamp":"2018-03-07T17:29:37.067Z"}

これまでのところ、ロガーはHTTPリクエストと関連データのみを記録しています。これはログに記録する非常に重要な情報ですが、カスタムログメッセージを記録するにはどうすればよいですか？たとえば、エラーの記録やデータベースクエリのパフォーマンスのプロファイリングなどにこの機能が必要になる場合があります。これを行う方法を説明するために、エラーハンドラルートからロガーを呼び出しましょう。

express-generatorパッケージには、デフォルトで404および500エラーハンドラルートが含まれているため、これを使用します。 ~/myApp/app.jsファイルを開きます。

nano ~/myApp/app.js

次のようなファイルの下部にあるコードブロックを見つけます。

〜/ 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アドレス。

次のようにエラーハンドラルートを更新します。

〜/ 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 : {};

  // add this line to include winston logging
  winston.error(`${err.status || 500} - ${err.message} - ${req.originalUrl} - ${req.method} - ${req.ip}`);

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

終了してファイルを保存します。

これをテストするために、存在しないプロジェクトのページにアクセスしてみましょう。これにより、404エラーがスローされます。 Webブラウザーに戻り、次のURLをロードしてみます：http://your_server_ip:3000/foo。 express-generatorによって作成されたボイラープレートのおかげで、アプリケーションはこのようなエラーに応答するようにすでに設定されています。ブラウザに次のようなエラーメッセージが表示されるはずです（エラーメッセージは表示されているものよりも詳細な場合があります）。

ここで、SSHセッションAのコンソールをもう一度見てください。エラーのログエントリがあるはずです。色付け設定のおかげで、簡単に見つけることができます。

Output[nodemon] starting `node bin/www`
error: 404 - Not Found - /foo - GET - ::ffff:72.80.124.207
info: ::ffff:72.80.124.207 - - [07/Mar/2018:17:40:11 +0000] "GET /foo HTTP/1.1" 404 985 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.186 Safari/537.36"

info: ::ffff:72.80.124.207 - - [07/Mar/2018:17:40:11 +0000] "GET /stylesheets/style.css HTTP/1.1" 304 - "http://167.99.4.120:3000/foo" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.186 Safari/537.36"

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

tail ~/myApp/logs/app.log

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

{"level":"error","message":"404 - Not Found - /foo - GET - ::ffff:72.80.124.207","timestamp":"2018-03-07T17:40:10.622Z"}

エラーメッセージには、エラーステータス（404-見つかりません）、リクエストされたURL（localhost / foo）、リクエストメソッド（GET ）、リクエストを行ったIPアドレス、およびリクエストが行われたときのタイムスタンプ。

結論

このチュートリアルでは、単純なNode.js Webアプリケーションを構築し、アプリケーションのパフォーマンスに関する洞察を提供する効果的なツールとして機能するWinstonロギングソリューションを統合しました。特にニーズがより複雑になるにつれて、アプリケーション用の堅牢なロギングソリューションを構築するためにさらに多くのことを行うことができます。時間をかけて、これらの他のドキュメントのいくつかを確認することをお勧めします。

Winstonトランスポートの詳細については、WinstonTransportsのドキュメントを参照してください。
独自のトランスポートの作成の詳細については、カスタムトランスポートの追加を参照してください。
HTTPコアトランスポートで使用するHTTPエンドポイントを作成するには、winstondを参照してください。
Winstonをプロファイリングツールとして使用するには、プロファイリングを参照してください。