1. 程式人生 > >[完整]Nodejs日誌管理log4js

[完整]Nodejs日誌管理log4js

從零開始nodejs系列文章

從零開始nodejs系列文章,將介紹如何利Javascript做為服務端指令碼,通過Nodejs框架web開發。Nodejs框架是基於V8的引擎,是目前速度最快的Javascript引擎。chrome瀏覽器就基於V8,同時開啟20-30個網頁都很流暢。Nodejs標準的web開發框架Express,可以幫助我們迅速建立web站點,比起PHP的開發效率更高,而且學習曲線更低。非常適合小型網站,個性化網站,我們自己的Geek網站!!

前言

日誌對任何的應用來說都是至關重要的。在Nodejs中使用express框架並沒有自帶的日誌模組,我們可以選擇log4js來完成日誌記錄的功能。

如果用過JAVA中log4j的同學,肯定對日誌並不陌生,學習log4js會更得心應手的。

文章目錄:

  1. 預設的控制檯輸出
  2. 通過log4js輸出日誌
  3. 配置log4js與express框架整合
  4. 根據專案配置log4js
  5. 優化log4js結構

1. 預設的控制檯輸出

我們使用express框架時,開發模式用node或者supervisor啟動nodejs應用時,控制檯都是顯示如下的日誌。

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

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

訪問頁面,結果如下。

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框架沒有日誌功能,我們需要引入log4js包來完成這個功能。

2. 通過log4js輸出日誌

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


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是一樣的格式。

3. 配置log4js與express框架整合

下載log4js包


~ npm install log4js
[email protected] node_modules\log4js
├── [email protected]
├── [email protected]
├── [email protected]
└── [email protected]

修改app.js


~ vi 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的引數進行一些調整。

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"

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

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

這樣我們就已經玩轉log4js了,為部署到生產環境,做好了日誌的準備工作。