解决Nginx反向代理NodeJS时log4js日志中IP错误的问题-中存储网

2013-10-27 22:36:02 来源：kejihao

从零开始nodejs系列文章

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

前言

为提高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

文章目录：

配置nginx反向代理

log4js做为web日志输出

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显示错误的问题。

继续阅读