概要
cluster環境では複数のプロセスが並列に動きます。
この状態で1つのログファイルにアクセスすると干渉が起きます。
かと言って各プロセス毎にログファイルを作成してしまうのは集約が面倒です。
今回はlog4jsを使ってその問題を解決します。
環境
- Node.js 5.1.0
- log4js 0.6.28
フォルダ構造
. ├── app.js ├── config.js ├── logger.js ├── master.js ├── package.json ├── public ├── routes ├── server.js ├── views └── worker.js
cluster環境を用意
以下の3つのファイルを主に使用します。
ファイル | 役割 |
---|---|
server.js | masterとworkerを区別して起動 |
master.js | workerをspawnする |
worker.js | /bin/wwwのような処理 |
server.js
master
かworker
かを判別して処理を分けます。
'use strict'; const cluster = require('cluster'); const Master = require('./master'); const Worker = require('./worker'); if (cluster.isMaster) { let master = new Master(); master.run(); } else { let worker = new Worker(); worker.run(); }
master.js
workerをCPUの分だけforkします。
またuncaughtException
などでプロセスが死んだ場合はworkerをrespawnします。
#!/usr/bin/env node 'use strict'; const os = require('os'); const cluster = require('cluster'); const logger = require('./logger')(); class Master { constructor() { } run() { let cpuCount = os.cpus().length; for (let i = 0; i < cpuCount ; i++) { cluster.fork(); logger.system.info("forked: " + i); } cluster.on('exit', (worker, code, signal) => { logger.system.info('worker exit', { worker: worker.id, pid: worker.process.pid, signal: signal, code: code }); cluster.fork(); }); } }; module.exports = Master;
worker.js
/bin/www
を削ってES6に則って変更しただけです。
'use strict'; const app = require('./app'); const http = require('http'); const port = 3000; app.set('port', port); function onError(error) { if (error.syscall !== 'listen') { throw error; } var bind = typeof port === 'string' ? 'Pipe ' + port : 'Port ' + port; // handle specific listen errors with friendly messages switch (error.code) { case 'EACCES': console.error(bind + ' requires elevated privileges'); process.exit(1); break; case 'EADDRINUSE': console.error(bind + ' is already in use'); process.exit(1); break; default: throw error; } } class Worker { constructor() { } run() { let server = http.createServer(app); server.listen(port); server.on('error', onError); } } module.exports = Worker;
log4jsの設定
まずpackage.json
でlog4js
を追加しておいてください。
clustered
タイプを使います。
これを使用するとworker
のログはmaster
に送信され、ログファイルへの書き込みはmaster
のみとなります。これにより前述の干渉問題を解決してます。
今回は以下の2つのファイルを使います。
ファイル | 役割 |
---|---|
config.js | log4jsの設定 |
logger.js | loggerの初期化 |
config.js
master
側にlog4jsの設定を書きます。
worker
側はtype
のみ書きます。
'use strict'; let config = {}; config.log4js = { master: { appenders: [ { type: 'clustered', appenders: [ { category: 'access', type: 'dateFile', filename: './access.log', pattern: '-yyyy-MM-dd', backups: 3 }, { category: 'error', type: 'dateFile', filename: './error.log', pattern: '-yyyy-MM-dd', backups: 3 }, { category: 'system', type: 'dateFile', filename: './system.log', pattern: '-yyyy-MM-dd', backups: 3 }, { type: 'console' } ], levels: { access: 'ALL', system: 'ALL', error: 'ALL' } } ] }, worker: { appenders: [ { type: 'clustered' } ] } }; module.exports = config;
logger.js
master
とworker
を区別して設定を読み込みます。
'use strict'; const cluster = require('cluster'); const log4js = require('log4js'); const config = require('./config'); module.exports = () => { if (cluster.isMaster) { log4js.configure(config.log4js.master); } else { log4js.configure(config.log4js.worker); } return { access: log4js.getLogger('access'), system: log4js.getLogger('system'), error: log4js.getLogger('error'), express: log4js.connectLogger(log4js.getLogger('access'), { level: log4js.levels.INFO, format: JSON.stringify({ date: ':date', ip: ':remote-addr', status: ':status', path: ':url', method: ':method', contentLength: ':content-length', ua: ':user-agent', latency: ':response-time' }) }) }; };
その他設定
app.js
のデフォルトのloggerを変更しておきます。
// var logger = require('morgan'); const logger = require('./logger')(); ~~~ // app.use(logger('dev')); app.use(logger.express);
動作確認
起動してみます。
$ node server.js [2015-11-26 21:52:10.053] [INFO] system - forked: 0 [2015-11-26 21:52:10.061] [INFO] system - forked: 1 [2015-11-26 21:52:10.065] [INFO] system - forked: 2 [2015-11-26 21:52:10.068] [INFO] system - forked: 3 [2015-11-26 21:52:10.071] [INFO] system - forked: 4 [2015-11-26 21:52:10.074] [INFO] system - forked: 5 [2015-11-26 21:52:10.077] [INFO] system - forked: 6 [2015-11-26 21:52:10.080] [INFO] system - forked: 7
ちゃんとclusterで起動しますね。
アクセスしてみます。
[2015-11-26 21:52:18.083] [INFO] access - {"date":"Thu, 26 Nov 2015 12:52:18 GMT","ip":"::1","status":"200","path":"/","method":"GET","contentLength":"170","ua":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_11_1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/46.0.2490.86 Safari/537.36","latency":"325"} [2015-11-26 21:52:18.287] [INFO] access - {"date":"Thu, 26 Nov 2015 12:52:18 GMT","ip":"::1","status":"200","path":"/stylesheets/style.css","method":"GET","contentLength":"111","ua":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_11_1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/46.0.2490.86 Safari/537.36","latency":"8"} [2015-11-26 21:52:21.601] [INFO] access - {"date":"Thu, 26 Nov 2015 12:52:21 GMT","ip":"::1","status":"200","path":"/","method":"GET","contentLength":"170","ua":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_11_1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/46.0.2490.86 Safari/537.36","latency":"322"} [2015-11-26 21:52:21.801] [INFO] access - {"date":"Thu, 26 Nov 2015 12:52:21 GMT","ip":"::1","status":"200","path":"/stylesheets/style.css","method":"GET","contentLength":"111","ua":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_11_1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/46.0.2490.86 Safari/537.36","latency":"8"} [2015-11-26 21:52:22.259] [INFO] access - {"date":"Thu, 26 Nov 2015 12:52:22 GMT","ip":"::1","status":"404","path":"/favicon.ico","method":"GET","contentLength":"1365","ua":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_11_1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/46.0.2490.86 Safari/537.36","latency":"23"}
問題なく出力されます。
お疲れ様でした。