Posted:
Jun 20, 2013
Tags:
Comments:
17 Comments

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/

打赏作者

Post Views: 7,536

This entry was posted in Javascript语言实践

0 0 votes
Article Rating
Subscribe
Notify of
guest

This site uses Akismet to reduce spam. Learn how your comment data is processed.

17 Comments
Oldest
Newest Most Voted
Inline Feedbacks
View all comments
jabez128

博主太牛了！！！

0
Reply
Conan Zhang

过奖了，谢谢支持！！

0
Reply
laoshe

Speed=306596 pages/min, 2227931 bytes/sec.

这是不用代理是的性能

使用ngnix反向代理后

Speed=7298 pages/min, 47969 bytes/sec.

0
Reply
Conan Zhang

差距真大啊！不知道你是实验环境是什么样的？
Nginx不会消耗这么多性能的。生产环境如果有这么大的差距就没法玩了！

0
Reply
laoshe

CPU：2 CPUs内存：512 M硬盘：30 G端口：6 M的vps

跑的是 go服务

0
Reply
Conan Zhang

你最好能写一下：
1. 你做压力测试的软件和脚本。
2. nginx反向代理的配置。

0
Reply
laoshe

详细信息写在http://segmentfault.com/q/1010000000323827

0
Reply
laoshe

问题不在nginx 我把go web服务端口改成80 关闭nginx 直接运行访问

oo-o.cn

性能和运行nginx反向代理差不多

Speed=6560 pages/min, 44762 bytes/sec.

但是如果直接访问ip地址204.77.6.51性能就特别好

Speed=301272 pages/min, 2189243 bytes/sec.

我是用 webbench 做的压力测试

0
Reply
Conan Zhang

IP快域名慢，就是DNS的问题了，tracert跟踪一下吧。

0
Reply
laoshe

thanks 打扰了

0
Reply
Conan Zhang

页面打不开了！

0
Reply
Conan Zhang

我可能会找个时间，写一下关于性能测试的文章。
目前，我没有做过这个案例的测试。

0
Reply
laoshe

我是门外汉 真不知该怎么调整
你的测试如何

0
Reply
Xl C

用nginx做反向代理出现502 bad gateway

0
Reply
Conan Zhang

你的node服务器挂了，就是502。

0
Reply
zhlhuang

为什么我一些静态文件还是访问的nginx 目录了

0
Reply
Conan Zhang

把配置贴一下吧。

0
Reply
17
0
Would love your thoughts, please comment.x
()
x