【深刻淺出Node.js系列十二】Nodejs日誌管理log4js

#0 系列目錄#css

日誌對任何的應用來講都是相當重要的。在Nodejs中使用express框架並無自帶的日誌模塊,咱們能夠選擇log4js來完成日誌記錄的功能。若是用過JAVA中log4j的同窗,確定對日誌並不陌生,學習log4js會更駕輕就熟的。node

#1 默認的控制檯輸出# 咱們使用express框架時,開發模式用node或者supervisor啓動nodejs應用時,控制檯都是顯示以下的日誌。jquery

GET /css/bootstrap.min.css 304 1ms
GET /css/my.css 304 0ms
GET /js/bootstrap.min.js 304 4ms
GET /js/jquery-1.9.1.min.js 304 6ms
GET /js/holder.js 304 3ms
GET /cat/json/latest 200 6ms
GET /cat/json/master 200 4ms
GET /cat/json/classic 200 2ms
GET /about 200 6ms
GET /css/bootstrap.min.css 304 2ms
GET /css/my.css 304 2ms
GET /js/bootstrap.min.js 304 2ms
GET /js/jquery-1.9.1.min.js 304 1ms
GET /js/holder.js 304 1ms
GET /js/bootstrap.min.js 304 1ms
GET / 304 6ms
GET /js/jquery-1.9.1.min.js 304 2ms
GET /css/my.css 304 1ms
GET /css/bootstrap.min.css 304 1ms
GET /js/bootstrap.min.js 304 2ms
GET /js/holder.js 304 2ms
GET /cat/json/latest 200 3ms
GET /cat/json/master 200 2ms
GET /cat/json/classic 200 2ms
GET /admin/ 304 13ms
GET /css/bootstrap.min.css 304 3ms
GET /js/jquery-1.9.1.min.js 304 2ms
GET /css/my.css 304 2ms
GET /js/bootstrap.min.js 304 1ms
GET /js/holder.js 304 2ms

咱們也能夠在代碼中,用console.log()打印一些控制檯日誌。修改routes/index.js:nginx

exports.index = function(req, res){
    console.log("This is an index page!");
    res.render('index', {
        title:'首頁|moive.me',
  	page:'index'
    });
};

訪問頁面,結果以下:web

This is an index page!
GET / 304 19ms
GET /css/bootstrap.min.css 304 4ms
GET /css/my.css 304 2ms
GET /js/jquery-1.9.1.min.js 304 38ms
GET /js/holder.js 304 29ms
GET /js/bootstrap.min.js 304 28ms

這樣的輸出的結果,都是在控制檯顯示,一旦server重啓日誌就丟失了。對於程序開發來講,這樣的輸出已經夠用了。可是在生產環境上,咱們但願能把控制檯的輸出,保存到文件中,並且須要更多的信息,不單單是默認的簡化的日誌信息。express

因爲express框架沒有日誌功能,咱們須要引入log4js包來完成這個功能。apache

#2 經過log4js輸出日誌# 咱們先可看一下,經過log4js輸出的日誌是什麼樣子的,下一節再介紹具體的配置。npm

This is an index page!
GET / 304 17ms
[2013-06-19 17:45:55.981] [INFO] normal - 127.0.0.1 - - "GET / HTTP/1.1" 304 - "http://localhost:3000/admin/" "Mozilla/5
.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/27.0.1453.110 Safari/537.36"
GET /css/bootstrap.min.css 304 10ms
[2013-06-19 17:45:56.015] [INFO] normal - 127.0.0.1 - - "GET /css/bootstrap.min.css HTTP/1.1" 304 - "http://localhost:30
00/admin/crawler/youku" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/27.0.1453.110
 Safari/537.36"
GET /css/my.css 304 8ms
[2013-06-19 17:45:56.017] [INFO] normal - 127.0.0.1 - - "GET /css/my.css HTTP/1.1" 304 - "http://localhost:3000/admin/cr
awler/youku" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/27.0.1453.110 Safari/537
.36"
GET /js/jquery-1.9.1.min.js 304 19ms
[2013-06-19 17:45:56.031] [INFO] normal - 127.0.0.1 - - "GET /js/jquery-1.9.1.min.js HTTP/1.1" 304 - "http://localhost:3
000/admin/" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/27.0.1453.110 Safari/537.
36"
GET /js/bootstrap.min.js 304 13ms
[2013-06-19 17:45:56.037] [INFO] normal - 127.0.0.1 - - "GET /js/bootstrap.min.js HTTP/1.1" 304 - "http://localhost:3000
/admin/" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/27.0.1453.110 Safari/537.36"

GET /js/holder.js 304 20ms
[2013-06-19 17:45:56.040] [INFO] normal - 127.0.0.1 - - "GET /js/holder.js HTTP/1.1" 304 - "http://localhost:3000/admin/
" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/27.0.1453.110 Safari/537.36"

相同的請求,控制檯輸出的結果多了不少,完整的web服務器的日誌格式。這纔是生產環境須要的!信息更豐富,而且與nginx和apache是同樣的格式。json

#3 配置log4js與express框架集成# 下載log4js包bootstrap

~ npm install log4js
log4js@0.6.6 node_modules\log4js
├── dequeue@1.0.3
├── semver@1.1.4
├── async@0.1.15
└── readable-stream@1.0.2

修改app.js

var log4js = require('log4js');
log4js.configure({
  appenders: [
    { 
      type: 'console' 
    }, //控制檯輸出
    {
      type: 'file', //文件輸出
      filename: 'logs/access.log', 
      maxLogSize: 1024,
      backups:3,
      category: 'normal' 
    }
  ]
});
var logger = log4js.getLogger('normal');
logger.setLevel('INFO');

...
//app.use(...)
//app.use(...)
app.use(log4js.connectLogger(logger, {level:log4js.levels.INFO}));
app.use(app.router);

須要在app.js中進行log4js的配置:

appenders中配置了兩個輸出,一個是控制檯輸出,一個是文件輸出。

appenders.type=file的對象,指定文件輸出位置及文件大小,當超過maxLogSize大小時,會自動生成一個新文件。

logs的文件目錄要手動建立。

level:log4js.levels.INFO, 設置默認日誌輸出級別是INFO。

log4js的輸出級別6個: trace, debug, info, warn, error, fatal

logger.trace(‘Entering cheese testing’);

logger.debug(‘Got cheese.’);

logger.info(‘Cheese is Gouda.’);

logger.warn(‘Cheese is quite smelly.’);

logger.error(‘Cheese is too ripe!’);

logger.fatal(‘Cheese was breeding ground for listeria.’);

若是輸出級別是INFO,則不會打印出低於info級別的日誌trace,debug,只打印info,warn,error,fatal。這樣作的好處在於,在生產環境中咱們可能只關心異常和錯誤,並不關心調試信息。從而大大減小日誌的輸出,能減小磁盤寫入。而在開發環境中,咱們能夠須要打印很是多的信息,幫助開發人員定位錯誤,調試代碼。

還有一個好處就是,代碼中能夠混有各類的日誌打印代碼。咱們只要在一個配置文件中,修改輸出級別,日誌輸出就會發生變化,不用修改全部的代碼。若是全部地方都是console.log(),那麼上線的時候,改動這個東西就要花不少時間。

#4 根據項目配置log4js# 上一節中,介紹了log4js和express集成。但默認的配置可能並不合適咱們的項目,還須要對log4js的參數進行一些調整。

##4.1 代替console.log()## 增長replaceConsole配置,讓全部console輸出到日誌中,以[INFO] console代替console默認樣式。

~ vi app.js
var log4js = require('log4js');
log4js.configure({
  appenders: [
    { 
      type: 'console' 
    },
    {
      type: 'file', 
      filename: 'logs/access.log', 
      maxLogSize: 1024,
      backups:4,
      category: 'normal' 
    }
  ],
  replaceConsole: true
});

查看輸出結果:

[2013-06-19 18:18:41.997] [INFO] console - This is an index page!
GET / 304 15ms
[2013-06-19 18:18:42.010] [INFO] normal - 127.0.0.1 - - "GET / HTTP/1.1" 304 - "http://localhost:3000/admin/" "Mozilla/5
.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/27.0.1453.110 Safari/537.36"
GET /css/bootstrap.min.css 304 5ms
[2013-06-19 18:18:42.042] [INFO] normal - 127.0.0.1 - - "GET /css/bootstrap.min.css HTTP/1.1" 304 - "http://localhost:30
00/admin/crawler/youku" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/27.0.1453.110
 Safari/537.36"
GET /css/my.css 304 11ms
[2013-06-19 18:18:42.051] [INFO] normal - 127.0.0.1 - - "GET /css/my.css HTTP/1.1" 304 - "http://localhost:3000/admin/cr
awler/youku" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/27.0.1453.110 Safari/537
.36"
GET /js/jquery-1.9.1.min.js 304 35ms
[2013-06-19 18:18:42.089] [INFO] normal - 127.0.0.1 - - "GET /js/jquery-1.9.1.min.js HTTP/1.1" 304 - "http://localhost:3
000/admin/" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/27.0.1453.110 Safari/537.
36"
GET /js/holder.js 304 42ms
[2013-06-19 18:18:42.098] [INFO] normal - 127.0.0.1 - - "GET /js/holder.js HTTP/1.1" 304 - "http://localhost:3000/admin/
" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/27.0.1453.110 Safari/537.36"
GET /js/bootstrap.min.js 304 11ms
[2013-06-19 18:18:42.101] [INFO] normal - 127.0.0.1 - - "GET /js/bootstrap.min.js HTTP/1.1" 304 - "http://localhost:3000
/admin/" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/27.0.1453.110 Safari/537.36"

##4.2 調整日誌輸出的格式##

app.use(log4js.connectLogger(logger, {level: level:log4js.levels.INFO, format:':method :url'}));

輸出結果:

[2013-06-19 18:23:25.230] [INFO] console - This is an index page!
GET / 304 28ms
[2013-06-19 18:23:25.251] [INFO] normal - GET /
GET /css/bootstrap.min.css 304 5ms
[2013-06-19 18:23:25.287] [INFO] normal - GET /css/bootstrap.min.css
GET /css/my.css 304 3ms
[2013-06-19 18:23:25.292] [INFO] normal - GET /css/my.css
GET /js/jquery-1.9.1.min.js 304 15ms
[2013-06-19 18:23:25.310] [INFO] normal - GET /js/jquery-1.9.1.min.js
GET /js/holder.js 304 9ms
[2013-06-19 18:23:25.321] [INFO] normal - GET /js/holder.js
GET /js/bootstrap.min.js 304 17ms
[2013-06-19 18:23:25.338] [INFO] normal - GET /js/bootstrap.min.js

##4.3 自動調整日誌輸出級別## 日誌級別對應規則:

http responses 3xx, level = WARN

http responses 4xx & 5xx, level = ERROR

else, level = INFO

設置level爲auto:

app.use(log4js.connectLogger(logger, {level: 'auto', format:':method :url'}));

下面日誌爲了對比方便我多打出了幾行:

[2013-06-19 18:24:56.040] [INFO] console - This is an index page!
GET / 304 16ms
[2013-06-19 18:24:56.053] [WARN] normal - GET /
GET /css/bootstrap.min.css 304 9ms
[2013-06-19 18:24:56.086] [WARN] normal - GET /css/bootstrap.min.css
GET /css/my.css 304 9ms
[2013-06-19 18:24:56.097] [WARN] normal - GET /css/my.css
GET /js/jquery-1.9.1.min.js 304 26ms
[2013-06-19 18:24:56.128] [WARN] normal - GET /js/jquery-1.9.1.min.js
GET /js/holder.js 304 32ms
[2013-06-19 18:24:56.164] [WARN] normal - GET /js/holder.js
GET /js/bootstrap.min.js 304 1ms
[2013-06-19 18:24:56.166] [WARN] normal - GET /js/bootstrap.min.js
[2013-06-19 18:24:56.204] [INFO] normal - GET /cat/json/latest
GET /cat/json/latest 200 10ms
[2013-06-19 18:24:56.211] [INFO] normal - GET /cat/json/master
GET /cat/json/master 200 4ms
[2013-06-19 18:24:56.219] [INFO] normal - GET /cat/json/classic
GET /cat/json/classic 200 9ms
GET /img/movie/emptySmall.png 304 1ms
[2013-06-19 18:24:56.263] [WARN] normal - GET /img/movie/emptySmall.png

#5 優化log4js結構# 應該有同窗發現了,咱們在配置log4js時會有一個問題。就是全部配置信息都是在app.js中作的,logger也是在這裏直接定義的。若是在控制器(routes)想用log4js進行輸出,咱們如今拿不到logger的句柄

修改app.js:

~ vi app.js

var log4js = require('log4js');
log4js.configure({
  appenders: [
    { type: 'console' },{
      type: 'file', 
      filename: 'logs/access.log', 
      maxLogSize: 1024,
      backups:4,
      category: 'normal' 
    }
  ],
  replaceConsole: true
});
//var logger = log4js.getLogger(name);
//logger.setLevel('INFO');
....
app.use(log4js.connectLogger(this.logger('normal'), {level:'auto', format:':method :url'}));
....

exports.logger=function(name){
  var logger = log4js.getLogger(name);
  logger.setLevel('INFO');
  return logger;
}

咱們把logger單獨定義出來,而且作爲API暴露出來。在index.js中使用logger輸出:

~ vi routes/index.js
var logger = require('../app').logger('index');
exports.index = function(req, res){
	console.log("This is an index page!");
	logger.info("This is an index page! -- log4js");

	res.render('index', {
  		title:'首頁|moive.me',
  		page:'index'
  	});
};

打印出來結果:

[2013-06-19 18:56:51.924] [INFO] console - This is an index page!
[2013-06-19 18:56:51.925] [INFO] index - This is an index page! -- log4js
GET / 304 17ms
[2013-06-19 18:56:51.938] [WARN] [default] - GET /
GET /css/bootstrap.min.css 304 5ms
[2013-06-19 18:56:51.978] [WARN] [default] - GET /css/bootstrap.min.css
GET /css/my.css 304 2ms
[2013-06-19 18:56:51.981] [WARN] [default] - GET /css/my.css
GET /js/jquery-1.9.1.min.js 304 2ms
[2013-06-19 18:56:51.984] [WARN] [default] - GET /js/jquery-1.9.1.min.js
GET /js/holder.js 304 3ms
[2013-06-19 18:56:51.989] [WARN] [default] - GET /js/holder.js
GET /js/bootstrap.min.js 304 9ms
[2013-06-19 18:56:52.002] [WARN] [default] - GET /js/bootstrap.min.js
相關文章
相關標籤/搜索