• Posts tagged "log4js"

Blog Archives

Nginx反向代理Nodejs – log4js日志IP显示错误

从零开始nodejs系列文章

从零开始nodejs系列文章,将介绍如何利Javascript做为服务端脚本,通过Nodejs框架web开发。Nodejs框架是基于V8的引擎,是目前速度最快的Javascript引擎。chrome浏览器就基于V8,同时打开20-30个网页都很流畅。Nodejs标准的web开发框架Express,可以帮助我们迅速建立web站点,比起PHP的开发效率更高,而且学习曲线更低。非常适合小型网站,个性化网站,我们自己的Geek网站!!

关于作者

张丹(Conan), 程序员Java,R,PHP,Javascript
weibo:@Conan_Z
blog: http://blog.fens.me
email: bsspirit@gmail.com

转载请注明出处:
http://blog.fens.me/nodejs-nginx-log4js/

前言

为提高web应用的吞吐量,我们一般都用nginx做负载均衡器,再反向代理到真正的web服务器。像JAVA服务可以做成Nginx+Tomcat, PHP用Nginx+Spawn-fcgi, 当然nodejs服务,我们也可以做相同的架构Ngnix+Node。

我使用nginx+nodejs+log4js时,发现log4js日志的remote_addr项,总是显示127.0.0.1。本文将重点解释如何通过修改log4js的代码,解决这个问题。

我已经提交这个问题到log4js-node的issue
https://github.com/nomiddlename/log4js-node/issues/139

log4js-bug

文章目录:

  1. 配置nginx反向代理
  2. log4js做为web日志输出
  3. log4js日志ip显示错误及修复

1. 配置nginx反向代理

本地启动nodejs : node app.js ,默认3000端口。

安装nginx

~ sudo apt-get install nginx

进入nginx配置目录

~ cd /etc/nginx/sites-enabled
/etc/nginx/sites-enabled

新建一个配置文件moive

~ vi moive

#moive.me
upstream nodejs__upstream {
        server 127.0.0.1:3000;
        #server 127.0.0.1:3001;
        keepalive 64;
}
server {
        listen 80;
        server_name www.moive.me moive.me;
        access_log /var/log/nginx/moiveme.log;
        location / {
                proxy_set_header   X-Real-IP            $remote_addr;
                proxy_set_header   X-Forwarded-For  $proxy_add_x_forwarded_for;
                proxy_set_header   Host                   $http_host;
                proxy_set_header   X-NginX-Proxy    true;
                proxy_set_header   Connection "";
                proxy_http_version 1.1;
                proxy_pass         http://nodejs__upstream;
        }
}

对配置项的解释:

  • listen,监听端口80
  • server_name , 监听域名 www.moive.me moive.me
  • access_log ,nginx日志输出 /var/log/nginx/moiveme.log
  • proxy_pass ,反向代理转发 http://nodejs__upstream;
  • 通过upstream nodejs__upstream 可以配置多台nodejs节点,做负载均衡。
  • keepalive ,设置存活时间。如果不设置可能会产生大量的timewait。

重新启动nginx

~ sudo /etc/init.d/nginx restart

通过浏览器访问web站点
http://moive.me

2. log4js做为web日志输出

log4js的配置与使用,请查看 玩转Nodejs日志管理log4js

查看控制台日志,发现一个问题,客户端IP记录值都是127.0.0.1。这个是我们不期待的。

GET / 304 24ms
[2013-06-20 06:55:39.405] [WARN] [default] - 127.0.0.1 - - "GET / HTTP/1.1" 304 - "" "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 5ms
[2013-06-20 06:55:39.646] [WARN] [default] - 127.0.0.1 - - "GET /css/my.css HTTP/1.1" 304 - "http://moive.me/" "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 4ms
[2013-06-20 06:55:39.651] [WARN] [default] - 127.0.0.1 - - "GET /css/bootstrap.min.css HTTP/1.1" 304 - "http://moive.me/" "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 3ms
[2013-06-20 06:55:39.652] [WARN] [default] - 127.0.0.1 - - "GET /js/holder.js HTTP/1.1" 304 - "http://moive.me/" "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 4ms
[2013-06-20 06:55:39.653] [WARN] [default] - 127.0.0.1 - - "GET /js/jquery-1.9.1.min.js HTTP/1.1" 304 - "http://moive.me/" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/27.0.1453.110 Safari/537.36"

在浏览器通过IP直接访问,http://50.116.27.194:3000/, 所有的客户端IP显示正常。

GET / 304 12ms
[2013-06-20 06:57:49.492] [WARN] [default] - 114.252.83.33 - - "GET / HTTP/1.1" 304 - "" "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 2ms
[2013-06-20 06:57:49.720] [WARN] [default] - 114.252.83.33 - - "GET /js/holder.js HTTP/1.1" 304 - "http://50.116.27.194:3000/" "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 2ms
[2013-06-20 06:57:49.723] [WARN] [default] - 114.252.83.33 - - "GET /css/bootstrap.min.css HTTP/1.1" 304 - "http://50.116.27.194:3000/" "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 2ms
[2013-06-20 06:57:49.724] [WARN] [default] - 114.252.83.33 - - "GET /css/my.css HTTP/1.1" 304 - "http://50.116.27.194:3000/" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/27.0.1453.110 Safari/537.36"

我们把问题定位在nginx转发出现的。

在程序中打印客户端IP。

~ vi routes/index.js

        console.log("ip=>"+req.ip);
	console.log("REMOTE_ADDR=>"+req.get['REMOTE_ADDR']);
	console.log("HTTP_X_REAL_IP=>"+req.get['HTTP_X_REAL_IP']);
	console.log("x-real-ip=>"+req.get['x-real-ip']);
	console.log("x-forwarded-for=>"+req.get['x-forwarded-for']);

	var headers = req.headers;
	console.log("headers=>"+ (headers['x-real-ip'] || headers['x-forwarded-for']));
	console.log("headers x-real-ip=>"+headers['x-real-ip']);
	console.log("headers x-forwarded-for=>"+headers['x-forwarded-for']);

	console.log("====================================================");

	var proxy_ip=headers['x-real-ip'] || headers['x-forwarded-for']
	if(proxy_ip) return console.log("proxy"+proxy_ip);
	if(req.ip) return console.log(req.ip);

	console.log("====================================================");

http://moive.me, 通过nginx转发的输出结果:

[2013-06-20 07:01:48.731] [INFO] console - ip=>127.0.0.1
[2013-06-20 07:01:48.732] [INFO] console - REMOTE_ADDR=>undefined
[2013-06-20 07:01:48.732] [INFO] console - HTTP_X_REAL_IP=>undefined
[2013-06-20 07:01:48.732] [INFO] console - x-real-ip=>undefined
[2013-06-20 07:01:48.732] [INFO] console - x-forwarded-for=>undefined
[2013-06-20 07:01:48.732] [INFO] console - headers=>114.252.83.33
[2013-06-20 07:01:48.732] [INFO] console - headers x-real-ip=>114.252.83.33
[2013-06-20 07:01:48.732] [INFO] console - headers x-forwarded-for=>114.252.83.33
[2013-06-20 07:01:48.732] [INFO] console - ====================================================
[2013-06-20 07:01:48.733] [INFO] console - proxy114.252.83.33
[2013-06-20 07:01:48.733] [INFO] console - req.ip127.0.0.1

http://50.116.27.194:3000, 直接通过IP访问的输出结果

[2013-06-20 06:57:49.480] [INFO] console - ip=>114.252.83.33
[2013-06-20 06:57:49.480] [INFO] console - REMOTE_ADDR=>undefined
[2013-06-20 06:57:49.480] [INFO] console - HTTP_X_REAL_IP=>undefined
[2013-06-20 06:57:49.481] [INFO] console - x-real-ip=>undefined
[2013-06-20 06:57:49.481] [INFO] console - x-forwarded-for=>undefined
[2013-06-20 06:57:49.481] [INFO] console - headers=>undefined
[2013-06-20 06:57:49.481] [INFO] console - headers x-real-ip=>undefined
[2013-06-20 06:57:49.481] [INFO] console - headers x-forwarded-for=>undefined
[2013-06-20 06:57:49.481] [INFO] console - ====================================================
[2013-06-20 06:57:49.482] [INFO] console - req.ip114.252.83.33

我们已经发现,通过nginx转发的客户端IP是不能直接使用express3框架中req.ip获得的,而是需要通过req.headers[‘x-real-ip’]和req.headers[‘x-forwarded-for’]才能得到。

3. log4js日志ip显示错误及修复

下面我们要再查一下log4js代码,看看他是怎么实现的,为什么会出现IP的错误。

打开 log4js/lib/connect-logger.js 118行

~ vi connect-logger.js
 function format(str, req, res) {
        return str
        .replace(':url', req.originalUrl)
        .replace(':method', req.method)
        .replace(':status', res.__statusCode || res.statusCode)
        .replace(':response-time', res.responseTime)
        .replace(':date', new Date().toUTCString())
        .replace(':referrer', req.headers['referer'] || req.headers['referrer'] || '')
        .replace(':http-version', req.httpVersionMajor + '.' + req.httpVersionMinor)
        .replace(':remote-addr',req.socket && (req.socket.remoteAddress || (req.socket.socket && req.socket.socket.remoteAddress)))
        .replace(':user-agent', req.headers['user-agent'] || '')
        .replace(':content-length', (res._headers && res._headers['content-length']) || (res.__headers && res.__headers['Content-Length']) || '-')
        .replace(/:req\[([^\]]+)\]/g, function(_, field){ return req.headers[field.toLowerCase()]; })
        .replace(/:res\[([^\]]+)\]/g, function(_, field){
                return res._headers
                ? (res._headers[field.toLowerCase()] || res.__headers[field])
                : (res.__headers && res.__headers[field]);
        });
 }

我们发现他的代码和express3的req.ip实现的代码是类似的,这样是不识别通过代理程序转发的客户端IP。

.replace(':remote-addr',req.socket && (req.socket.remoteAddress || (req.socket.socket && req.socket.socket.remoteAddress)))

下面对这行代码进行修改。

.replace(':remote-addr', req.headers['x-forwarded-for'] || req.connection.remoteAddress)

先检查不是转发的IP,再取默认IP。

重起nodejs服务器

浏览器访问测试。

  • http://moive.me
  • http://50.116.27.194:3000
[2013-06-20 07:12:58.706] [WARN] [default] - 114.252.83.33 - - "GET / HTTP/1.1" 304 - "http://moive.me/" "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-20 07:12:58.949] [WARN] [default] - 114.252.83.33 - - "GET /css/bootstrap.min.css HTTP/1.1" 304 - "http://moive.me/" "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 3ms
[2013-06-20 07:12:59.153] [WARN] [default] - 114.252.83.33 - - "GET /css/my.css HTTP/1.1" 304 - "http://moive.me/" "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 2ms
[2013-06-20 07:12:59.156] [WARN] [default] - 114.252.83.33 - - "GET /js/jquery-1.9.1.min.js HTTP/1.1" 304 - "http://moive.me/" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/27.0.1453.110 Safari/537.36"

两种访问测试都正常,解决了log4js通过nginx反向代理,日志IP显示错误的问题。

转载请注明出处:
http://blog.fens.me/nodejs-nginx-log4js/

打赏作者

玩转Nodejs日志管理log4js

从零开始nodejs系列文章

从零开始nodejs系列文章,将介绍如何利Javascript做为服务端脚本,通过Nodejs框架web开发。Nodejs框架是基于V8的引擎,是目前速度最快的Javascript引擎。chrome浏览器就基于V8,同时打开20-30个网页都很流畅。Nodejs标准的web开发框架Express,可以帮助我们迅速建立web站点,比起PHP的开发效率更高,而且学习曲线更低。非常适合小型网站,个性化网站,我们自己的Geek网站!!

关于作者

张丹(Conan), 程序员Java,R,PHP,Javascript
weibo:@Conan_Z
blog: http://blog.fens.me
email: bsspirit@gmail.com

转载请注明出处:
http://blog.fens.me/nodejs-log4js/

前言

日志对任何的应用来说都是至关重要的。在Nodejs中使用express框架并没有自带的日志模块,我们可以选择log4js来完成日志记录的功能。

如果用过JAVA中log4j的同学,肯定对日志并不陌生,学习log4js会更得心应手的。

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
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


~ 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了,为部署到生产环境,做好了日志的准备工作。

 

转载请注明出处:
http://blog.fens.me/nodejs-log4js/

打赏作者