Posted at

Express + Fluentdでエラーログ

More than 5 years have passed since last update.

Expressのエラーハンドリングでエラーのロギングをcentralizeに行い、且つアプリケーションコード側ではログを吐くことだけに集中させて実際にログをどう処理するかー基本MongoDBに書きこむがseverityが高い場合はメール通知する等はFluentdに任せられると理想的と思い、実践して見ました。

サンプルコードは以下にあります

https://bitbucket.org/p_baleine/express-fluent-sample


ExpressからFluentdを利用する

fluent-logger-nodeを利用します

$ npm install fluent-logger-node --save

トップレベルのapp.jsで初期化を行います

var fluentLogger = require('fluent-logger').configure('express-fluent-sample', {

host: "localhost",
port: 24224,
timeout: 3.0
});

どうやらfluent-logger-nodeはコネクションをシングルトンに保持してくれているらしいので、アプリのエントリーポイントで一度この初期化をおこなっておけば、他のモジュールからは単にrequire('fluent-logger-node')で呼び出せるようです。


システムログ

エラー、デバッグ…等レベルのロギングを担うモジュールを設けます(lib/system-logger.js)

var fluentLogger = require('fluent-logger');

var levels = [
'info',
'debug',
'warn',
'error'
];

levels.forEach(function(level) {
module.exports[level] = function(msg) {
fluentLogger.emit('syslog.' + level, { message: msg });
};
});

こんな感じで使います

var logger = require('./system-logger');

logger.info('hoge');

上記コードでexpress-fluent-sample.syslog.infoタグでFluentに送信されます。


エラーハンドラ

肝心のエラーハンドラは以下のような感じです(lib/error-handler.js)

var logger = require('./system-logger');

module.exports = function() {
return function(err, req, res, next) {
if (err instanceof EmptyResponse) { res.status(404); }

logger.error(err.message);

res.send(('' + res.statusCode).match(/2\d{2}/) ? 500 : res.statusCode,
'Something broken!');
};
};

5行目でerrEmptyResponseのインスタンスの場合にステータスコードを404にしてみています。EmptyResponseは例えばモデル層で対象となるレコードが発生しない場合に発生する例外などです。

app.jsに以下を追加します

// ...

app.use(app.router);
app.use(errorHandler());
// ...


サンプルコントローラ

同期、非同期に発生するエラーを試すためのサンプルコントローラです(lib/routes/post.js)

var logger = require('../system-logger');

var EmptyResponse = require('../error-handler').EmptyResponse;

exports.index = function(req, res) {
logger.info('this is info');
res.send('Hello, world');
};

exports.create = function(req, res) {
throw new Error('error is thrown!');
};

exports.show = function(req, res, next) {
findPost(req.params.post, function(err, post) {
if (err) { next(err); }
});
};

function findPost(id, cb) {
cb(new EmptyResponse('not found post: %d', id));
}


Fluentの設定

Fluentはあまり詳しくないので、もっと効率の良い記述があったら教えてください、エラーレベルのシステムログの場合はMongoDBに書きこんで且つエラー通知、それ以外のレベルではMongoDBにのみ書きこんでいます(etc/td-agent/td-agent.conf)。

<match express-fluent-sample.syslog.*>

type record_reformer
output_tag reformed.${tag}

level ${tag_parts.last}
message ${message}
</match>

<match reformed.express-fluent-sample.syslog.error>
type copy
<store>
type mongo
database express-fluent-sample
collection syslog
capped
capped_size 100m
</store>
<store>
type mail
host localhost
port 25
from noreply@example.com
to hoge@gmail.com
subject express-fluent-sample error!!
message %s\n%s
message_out_keys level,message
</store>
</match>

<match reformed.express-fluent-sample.syslog.**>
type mongo
database express-fluent-sample
collection syslog
capped
capped_size 100m
</match>

動かすには以下プラグインが必要です


試してみる

$ curl -X GET http://localhost:3000/posts

MongoDBのexpress-fluent-sampleデータベースのsyslogコレクションとaccessコレクションに書き込みが在るはずです。

$ curl -X POST http://localhost:3000/posts

POSTのルーティングではわざとエラーを発生させているのでMongoDBへの書き込みに加えてメールが飛びます。


おまけ、アクセスログ

以下ミドルウェアを(lib/access-logger.js)

var fluentLogger = require('fluent-logger');

var format = require('util').format;

/**
* Emit `access` event to fluent.
*/

module.exports = function() {
return function(req, res, next) {
var sock = req.socket;
var remoteAddress = sock.socket ? sock.socket.remoteAddress : sock.remoteAddress;
var method = req.method;
var url = req.url;
var httpVersion = req.httpVersion;
var startTime = Date.now();

function logRequest() {
res.removeListener('finish', logRequest);
res.removeListener('close', logRequest);

var len = parseInt(res.getHeader('Content-Length'), 10);

fluentLogger.emit('access', {
'remote-address': remoteAddress,
'method': method,
'url': url,
'http-version': httpVersion,
'status': res.statusCode,
'res[content-length]': isNaN(len) ? '' : len,
'response-time': Date.now() - startTime
});
}

res.on('finish', logRequest);
res.on('close', logRequest);

next();
};
};

app.jsから利用してあげるとアクセスログも取れます。