【深刻浅出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
相关文章
相关标签/搜索