• 粉丝日志首页

解决RHadoop错误:PipeMapRed.waitOutputThreads(): subprocess failed with code 1

RHadoop实践系列文章,包含了R语言与Hadoop结合进行海量数据分析。Hadoop主要用来存储海量数据,R语言完成MapReduce 算法,用来替代Java的MapReduce实现。有了RHadoop可以让广大的R语言爱好者,有更强大的工具处理大数据1G, 10G, 100G, TB, PB。 由于大数据所带来的单机性能问题,可能会一去不复返了。

RHadoop实践是一套系列文章,主要包括”Hadoop环境搭建”,”RHadoop安装与使用”,R实现MapReduce的协同过滤算法”,”HBase和rhbase的安装与使用”。对于单独的R语言爱好者,Java爱好者,或者Hadoop爱好者来说,同时具备三种语言知识并不容 易。此文虽为入门文章,但R,Java,Hadoop基础知识还是需要大家提前掌握。

关于作者:

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

转载请注明出处:
http://blog.fens.me/rhadoop-rmr2-pipemapred/

rhadoop-pipemapred

前言

一行错误难倒一片同学,今天在准备 统计之都沙龙 的时候,我也遇到相同的错误。就让我来解决一下,在使用rhadoop的rmr2中,经常会遇到的一个错误。

按照 RHadoop实践系列之二:RHadoop安装与使用 rmr2中实例所演示。


> small.ints = to.dfs(1:10)
> mapreduce(input = small.ints, map = function(k, v) cbind(v, v^2))
> from.dfs("/tmp/RtmpWnzxl4/file5deb791fcbd5")

 

文章目录:

  1. rmr2运行错误日志
  2. 定位错误到hadoop日志
  3. 从hadoop入手找解决办法 — 失败
  4. 从rhadoop入手找解决办法 — 成功

 

1. rmr2运行错误日志

R执行的错误日志如下面:

packageJobJar: [/tmp/Rtmpdf7egm/rmr-local-env3cbb70983, /tmp/Rtmpdf7egm/rmr-global-env3cbb654b85fe, /tmp/                        Rtmpdf7egm/rmr-streaming-map3cbba213f2e, /home/conan/hadoop/tmp/hadoop-unjar1697638502297829404/] [] /tmp                        /streamjob4620072667602885650.jar tmpDir=null
13/06/23 10:44:25 INFO mapred.FileInputFormat: Total input paths to process : 1
13/06/23 10:44:25 INFO streaming.StreamJob: getLocalDirs(): [/home/conan/hadoop/tmp/mapred/local]
13/06/23 10:44:25 INFO streaming.StreamJob: Running job: job_201306231032_0001
13/06/23 10:44:25 INFO streaming.StreamJob: To kill this job, run:
13/06/23 10:44:25 INFO streaming.StreamJob: /home/conan/hadoop/hadoop-1.0.3/libexec/../bin/hadoop job  -D                        mapred.job.tracker=hdfs://master:9001 -kill job_201306231032_0001
13/06/23 10:44:25 INFO streaming.StreamJob: Tracking URL: http://master:50030/jobdetails.jsp?jobid=job_20                        1306231032_0001
13/06/23 10:44:26 INFO streaming.StreamJob:  map 0%  reduce 0%
13/06/23 10:45:04 INFO streaming.StreamJob:  map 100%  reduce 100%
13/06/23 10:45:04 INFO streaming.StreamJob: To kill this job, run:
13/06/23 10:45:04 INFO streaming.StreamJob: /home/conan/hadoop/hadoop-1.0.3/libexec/../bin/hadoop job  -Dmapred.job.tracker=hdfs://master:9001 -kill job_201306231032_0001
13/06/23 10:45:04 INFO streaming.StreamJob: Tracking URL: http://master:50030/jobdetails.jsp?jobid=job_201306231032_0001
13/06/23 10:45:04 ERROR streaming.StreamJob: Job not successful. Error: # of failed Map Tasks exceeded allowed limit. FailedCount: 1. LastFailedTask: task_201306231032_0001_m_000000
13/06/23 10:45:04 INFO streaming.StreamJob: killJob...
Streaming Command Failed!
Error in mr(map = map, reduce = reduce, combine = combine, vectorized.reduce,  :
  hadoop streaming failed with error code 1

我们光看上面的日志,根本发现不了hadoop的实际错误是什么!

2. 定位错误到hadoop日志

接下来需要定位到实际错误的位置。为了方便查询日志,我们打开jobtracker的控制台:http://192.168.1.210:50030/jobtracker.jsp
并找到刚才出现错误的, 日志中有提示的网页位置, Tracking URL: http://master:50030/jobdetails.jsp?jobid=job_201306231032_0001

rhadoop

查看map的错误,现在已经明确有了错误定义。


Running a job using hadoop streaming and mrjob: PipeMapRed.waitOutputThreads(): subprocess failed with code 1
java.lang.RuntimeException: PipeMapRed.waitOutputThreads(): subprocess failed with code 1 at 
org.apache.hadoop.streaming.PipeMapRed.waitOutputThreads(PipeMapRed.java:362) at 
org.apache.hadoop.streaming.PipeMapRed.mapRedFinished(PipeMapRed.java:576) at 
org.apache.hadoop.streaming.PipeMapper.close(PipeMapper.java:135) at 
org.apache.hadoop.mapred.MapRunner.run(MapRunner.java:57) at 
org.apache.hadoop.streaming.PipeMapRunner.run(PipeMapRunner.java:36) at 
org.apache.hadoop.mapred.MapTask.runOldMapper(MapTask.java:436) at 
org.apache.hadoop.mapred.MapTask.run(MapTask.java:372) at 
org.apache.hadoop.mapred.Child$4.run(Child.java:255) at 
java.security.AccessController.doPrivileged(Native Method) at 
javax.security.auth.Subject.doAs(Subject.java:396) at 
org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1121) at 
org.apache.hadoop.mapred.Child.main(Child.java:249)

3. 从hadoop入手找解决办法 — 失败

查看hadoop错误列表:code 1的错误
“OS error code 1: Operation not permitted”"OS error code 2: No such file or directory”

我来分析一下:hadoop和R的用户和用户组

启动hadoop, 用户conan, 用户组conan
启动R, 用户conan, 用户组conan

既然都是相同权限的用户,怎么会有权限的问题呢。

再找另一个hadoop环境做测试,用户使用root,没有错误如文章所示,RHadoop实践系列之二:RHadoop安装与使用

好了,这样问题已经很具体了,我们去网上查找一下错误原因。

通过google搜索,找到 org.apache.hadoop.security.AccessControlException解决办法文章
http://www.51testing.com/?uid-445759-action-viewspace-itemid-821244

具体的错误原因,在文章中有写,我就不再列出了。我们参考他的方法二,对我们的hadoop环境进行调整。
在hdfs-site.xml中增加dfs.permissions.superusergroup的定义。

superusergroup,默认值用什么我们可以在系统中查一下。


~ hadoop fs -ls /
drwxr-xr-x   - conan supergroup          0 2013-04-24 01:52 /hbase
drwxr-xr-x   - conan supergroup          0 2013-04-25 04:59 /home
drwxr-xr-x   - conan supergroup          0 2013-06-23 10:44 /tmp
drwxr-xr-x   - conan supergroup          0 2013-04-24 19:28 /user

这样就得到了supergroup的名字是supergroup, 我们修改hdfs-site.xml,增加dfs.permissions.superusergroup的定义


~ vi $HADOOP_HOME/conf/hdfs-site.xml

<configuration>
<property>
<name>dfs.data.dir</name>
<value>/home/conan/hadoop/data</value>
</property>
<property>
<name>dfs.replication</name>
<value>1</value>
</property>
<property>
<name>dfs.permissions</name>
<value>false</value>
</property>
<property>
<name>dfs.permissions.superusergroup</name>
<value>supergroup</value>
</property>
</configuration>

重启hadoop,重启R程序,重新执行rmr2脚本。还是有错误,没有解决问题。

4. 从rhadoop入手找解决办法 — 成功

我们找到rhadoop的作者github的issue 122:
https://github.com/RevolutionAnalytics/RHadoop/issues/122

发现其他人也遇到了,类似的错误。这issue已经是closed状态,证明错误已经解决。
根据作者的回答我们发现,错误是由于:“R的类库在特定的用户下面,而不是标准合位置,导致类库不能被hadoop找到”。

在我们的环境中,发现也是同样的配置,与错误描述一致。


~ R
> .libPaths()
[1] "/home/conan/R/x86_64-pc-linux-gnu-library/2.15"
[2] "/usr/local/lib/R/site-library"
[3] "/usr/lib/R/site-library"
[4] "/usr/lib/R/library"

~ ls /home/conan/R/x86_64-pc-linux-gnu-library/2.15
colorspace  functional  iterators  munsell  RColorBrewer  rhdfs    rmr2
dichromat   ggplot2     itertools  plyr     Rcpp          rJava    scales
digest      gtable      labeling   proto    reshape2      RJSONIO  stringr

~ ls /usr/local/lib/R/site-library

我们环境安装的所有类库,都在/home/conan目录下面,而/usr/local/lib/R/site-library一个库类都没有。

我们按照rhadoop作者指示,把包进行重新安装。


#切换到root下面
~ sudo -i

#查看R的类库路径
~ R
> .libPaths()
[1] "/usr/local/lib/R/site-library" "/usr/lib/R/site-library"
[3] "/usr/lib/R/library"

#在root下进行安装
~ R CMD javareconf 
~ R

#启动R程序
install.packages("rJava")
install.packages("reshape2")
install.packages("Rcpp")
install.packages("iterators")
install.packages("itertools")
install.packages("digest")
install.packages("RJSONIO")
install.packages("functional")

~ cd /home/conan/R
~ R CMD INSTALL rmr2_2.1.0.tar.gz
~ ls /usr/local/lib/R/site-library
digest  functional  iterators  itertools  plyr  Rcpp  reshape2  rJava  RJSONIO  rmr2  stringr

依赖包都安装在了/usr/local/lib/R/site-library下面,我们退出root用户,重新启动R程序测试


~ exit
~ whoami
conan

~ R
> library(rmr2)
Loading required package: Rcpp
Loading required package: RJSONIO
Loading required package: digest
Loading required package: functional
Loading required package: stringr
Loading required package: plyr
Loading required package: reshape

#再次运行 rmr2程序
> small.ints = to.dfs(1:10)
> mapreduce(input = small.ints, map = function(k, v) cbind(v, v^2))

packageJobJar: [/tmp/RtmpM87JEc/rmr-local-env1c7588ca7ed, /tmp/RtmpM87JEc/rmr-global-env1c77fdcab5f, /tmp                       /RtmpM87JEc/rmr-streaming-map1c76a4ddf6e, /home/conan/hadoop/tmp/hadoop-unjar6992113986427459004/] [] /tm                       p/streamjob2762947354578034435.jar tmpDir=null
13/06/23 13:27:36 INFO mapred.FileInputFormat: Total input paths to process : 1
13/06/23 13:27:36 INFO streaming.StreamJob: getLocalDirs(): [/home/conan/hadoop/tmp/mapred/local]
13/06/23 13:27:36 INFO streaming.StreamJob: Running job: job_201306231141_0007
13/06/23 13:27:36 INFO streaming.StreamJob: To kill this job, run:
13/06/23 13:27:36 INFO streaming.StreamJob: /home/conan/hadoop/hadoop-1.0.3/libexec/../bin/hadoop job  -D                       mapred.job.tracker=hdfs://master:9001 -kill job_201306231141_0007
13/06/23 13:27:36 INFO streaming.StreamJob: Tracking URL: http://master:50030/jobdetails.jsp?jobid=job_20                       1306231141_0007
13/06/23 13:27:37 INFO streaming.StreamJob:  map 0%  reduce 0%
13/06/23 13:27:51 INFO streaming.StreamJob:  map 100%  reduce 0%
13/06/23 13:27:58 INFO streaming.StreamJob:  map 100%  reduce 100%
13/06/23 13:27:58 INFO streaming.StreamJob: Job complete: job_201306231141_0007
13/06/23 13:27:58 INFO streaming.StreamJob: Output: /tmp/RtmpM87JEc/file1c722c5c6ae

执行成功, 错误解决!!

本文从发现错误,定位错误,查找错误,解决错误,4个步骤解决上面的问题。
希望给遇到问题束手无策的同学,不仅提供直接的错误帮助,更有一个思路上的认识,提高自己的动手能力!!

转载请注明出处:
http://blog.fens.me/rhadoop-rmr2-pipemapred/

打赏作者

upstart封装mongodb应用为系统服务

ubuntu实用工具系列文章

操作系统实用工具系列文章,将介绍基于Linux ubuntu的各种工具软件的配置和使用。有些工具大家早已耳熟能详,有些工具经常用到但确依然陌生。我将记录我在使用操作系统时,安装及配置工具上面的一些方法,把使用心得记录下来也便于自己的以后查找和回忆。

关于作者

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

转载请注明出处:
http://blog.fens.me/linux-upstart-mongodb/

upstart-mongodb

前言

本文将介绍封装mongodb应用为系统服务,mongod应用会像一个守护程序一样,被操作系统所管理。通过upstart以系统服务的方式管理mongodb应用。运维起来也会很容易!!

本次实验是针对单个进程mongodb的,如果是mongodb集群,效果会更加明显的。特别进程被非法停止后的自动重启功能,增加了系统的健壮性。

文章目录:

  1. mongodb环境介绍
  2. upstart任务脚本
  3. mongodb应用管理

 

1. Mongodb环境介绍

moive.me是一个nodejs应用,使用mongodb作为数据存储。nodejs开发请参考:从零开始nodejs系列文章

正常情况mongodb的启动命令
~ /usr/bin/mongod --config /etc/mongodb-moive.conf

为mongodb配置启动参数,配置文件mongodb-moive.conf

~ vi /etc/mongodb-moive.conf

dbpath=/var/lib/mongodb
logpath=/var/log/mongodb/mongodb-moive.log
logappend=true
bind_ip = 127.0.0.1
port = 27017
journal=true
#fork=true     #如果打开fork, 则upstart的stop,status命令失效。

上面的方式,应用程序会在当前的console界面中运行,一旦console结束,应用也会停止。我们改一下命令,让程序在后台运行。

~ /usr/bin/mongod --config /etc/mongodb-moive.conf &

这样程序就就在后台启动了。进程正常运行着,我也不用做太多的事情。

如果我想停止这个程序,怎么办呢? 找到mongod的系统进程,再杀死。如果我们系统中跑着多个mongod的进程,那么找起来也是一个工作量,而且如果杀错了进程,后果不堪设想。多进程的mongod请参考 MongoDB部署实验系列文章

如果moive的单个应用,能像系统服务一样,通过start, stop, status管理,那将会是多么方便的一件事啊!

2. upstart任务脚本

upstart的使用在 upstart把应用封装成系统服务 一文中已经介绍过了。

~ vi /etc/init/mongodb-moive.conf

description "mongodb moive.me"
author "bsspirit <http://blog.fens.me>"

limit nofile 20000 20000

kill timeout 300

respawn
respawn limit 2 5

pre-start script
    mkdir -p /var/lib/mongodb/
    mkdir -p /var/log/mongodb/
end script

start on runlevel [2345]
stop on runlevel [06]

script
    exec  /usr/bin/mongod --config /etc/mongodb-moive.conf
end script

3. Mongodb应用管理

启动mongodb-moive应用,进程ID:2037


~ start mongodb-moive
mongodb-moive start/running, process 2037

~ ps -aux|grep mongo
root      2037  0.7  1.5 705112 15960 ?        Ssl  07:53   0:00 /usr/bin/mongod --config /etc/mongodb-moive.conf

查看运行状态, 进程2037正常运行


~ status mongodb-moive
mongodb-moive start/running, process 2037

~ mongo
MongoDB shell version: 2.0.4
connecting to: test

> show dbs
local   (empty)
nodejs  0.203125GB
session 0.203125GB

非法关闭测试:杀死nodejs应用进程2037,通过upstart管理,mongodb-moive应用会自动重启


~ kill -9 2037

#查看系统进程,发现进程ID变了  
~ ps -aux|grep mongo
root      2054  2.0  1.5 638548 15872 ?        Ssl  07:53   0:00 /usr/bin/mongod --config /etc/mongodb-moive.conf

#查看进程状态,进程ID确实变了,而且是自动完成的
~ status mongodb-moive
mongodb-moive start/running, process 2054

#命令进行mongo
~ mongo
MongoDB shell version: 2.0.4
connecting to: test

> show dbs
local   (empty)
nodejs  0.203125GB
session 0.203125GB

刚才mongod被进程杀死时的日志, 2037被杀死,2054自动重启。


***** SERVER RESTARTED *****

Sat Jun 22 07:53:35 [initandlisten] MongoDB starting : pid=2037 port=27017 dbpath=/var/lib/mongodb 64-bit host=li478-194
Sat Jun 22 07:53:35 [initandlisten] db version v2.0.4, pdfile version 4.5
Sat Jun 22 07:53:35 [initandlisten] git version: nogitversion
Sat Jun 22 07:53:35 [initandlisten] build info: Linux lamiak 2.6.42-37-generic #58-Ubuntu SMP Thu Jan 24 15:28:10 UTC 2013 x86_64 BOOST_LIB_VERSION=1_46_1
Sat Jun 22 07:53:35 [initandlisten] options: { config: "/etc/mongodb-moive.conf", dbpath: "/var/lib/mongodb", journal: "true", logappend: "true", logpath: "/var/log/mongodb/mongodb-moive.log" }
Sat Jun 22 07:53:35 [initandlisten] journal dir=/var/lib/mongodb/journal
Sat Jun 22 07:53:35 [initandlisten] recover : no journal files present, no recovery needed
Sat Jun 22 07:53:35 [initandlisten] waiting for connections on port 27017
Sat Jun 22 07:53:35 [websvr] admin web console waiting for connections on port 28017
Sat Jun 22 07:53:38 [initandlisten] connection accepted from 127.0.0.1:37554 #1
Sat Jun 22 07:53:39 [conn1] end connection 127.0.0.1:37554

***** SERVER RESTARTED *****

Sat Jun 22 07:53:56 [initandlisten] MongoDB starting : pid=2054 port=27017 dbpath=/var/lib/mongodb 64-bit host=li478-194
Sat Jun 22 07:53:56 [initandlisten] db version v2.0.4, pdfile version 4.5
Sat Jun 22 07:53:56 [initandlisten] git version: nogitversion
Sat Jun 22 07:53:56 [initandlisten] build info: Linux lamiak 2.6.42-37-generic #58-Ubuntu SMP Thu Jan 24 15:28:10 UTC 2013 x86_64 BOOST_LIB_VERSION=1_46_1
Sat Jun 22 07:53:56 [initandlisten] options: { config: "/etc/mongodb-moive.conf", dbpath: "/var/lib/mongodb", journal: "true", logappend: "true", logpath: "/var/log/mongodb/mongodb-moive.log" }
Sat Jun 22 07:53:56 [initandlisten] journal dir=/var/lib/mongodb/journal
Sat Jun 22 07:53:56 [initandlisten] recover begin
Sat Jun 22 07:53:56 [initandlisten] info no lsn file in journal/ directory
Sat Jun 22 07:53:56 [initandlisten] recover lsn: 0
Sat Jun 22 07:53:56 [initandlisten] recover /var/lib/mongodb/journal/j._0
Sat Jun 22 07:53:56 [initandlisten] recover cleaning up
Sat Jun 22 07:53:56 [initandlisten] removeJournalFiles
Sat Jun 22 07:53:56 [initandlisten] recover done
Sat Jun 22 07:53:56 [websvr] admin web console waiting for connections on port 28017
Sat Jun 22 07:53:56 [initandlisten] waiting for connections on port 27017
Sat Jun 22 07:54:04 [initandlisten] connection accepted from 127.0.0.1:37559 #1
Sat Jun 22 07:54:56 [clientcursormon] mem (MB) res:47 virt:1008 mapped:160
Sat Jun 22 07:59:56 [clientcursormon] mem (MB) res:47 virt:1008 mapped:160
Sat Jun 22 08:00:25 [conn1] end connection 127.0.0.1:37559

正常关闭mongodb测试:通过stop命令


~ stop mongodb-moive
mongodb-moive stop/waiting

~ status mongodb-moive
mongodb-moive stop/waiting

~  ps -aux|grep mongo

正常关闭mongodb测试:通过mongo命令


~ mongo
MongoDB shell version: 2.0.4
connecting to: test

> use admin
switched to db admin

> db.shutdownServer()
Sat Jun 22 08:10:11 DBClientCursor::init call() failed
Sat Jun 22 08:10:11 query failed : admin.$cmd { shutdown: 1.0 } to: 127.0.0.1
server should be down...
Sat Jun 22 08:10:11 trying reconnect to 127.0.0.1
Sat Jun 22 08:10:11 reconnect 127.0.0.1 failed couldn't connect to server 127.0.0.1
Sat Jun 22 08:10:11 Error: error doing query: unknown shell/collection.js:151
>
bye

~ ps -aux|grep mongo
root      2332  0.6  1.5 705112 15960 ?        Ssl  08:10   0:00 /usr/bin/mongod --config /etc/mongodb-moive.conf

我们看们通过mongo的shutdownServer()命令,mongo也会重启,可能是runlevel的设置问题。我们选择要不要使用respawn的重启功能。

我们已经按照moive应用的需求,配置好了mongodb-moive启动程序。

系统运维也将变得如此简单。

转载请注明出处:
http://blog.fens.me/linux-upstart-mongodb/

打赏作者

upstart封装nodejs应用为系统服务

从零开始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/linux-upstart-nodejs/

upstart-nodejs

 

本文将介绍封装nodejs应用为系统服务,应用会像一个守护程序一样,被操作系统所管理。

文章目录:

  1. nodejs应用介绍
  2. upstart任务脚本
  3. nodejs应用管理

1. nodejs应用介绍

终于要把nodejs的应用程序部署上线了, node和npm在ubuntu下安装,请参考:准备Nodejs开发环境Ubuntu

把源代码通过git复制到目录下面
/root/deploy/movie
然后搞命令:


~ cd /root/deploy/movie
node ./app.js

上面的方式,nodejs程序会在当前的console界面中运行,一旦console结束,应用也会停止。我们改一下命令,让程序在后台运行


~ node ./app.js &
[1] 21333
[2013-06-21 09:38:30.696] [INFO] console - Start App: http://moive.me
[2013-06-21 09:38:30.700] [INFO] console - Express server listening on port 3000

这样程序就就在后台启动了。进程正常运行着,我也不用做太多的事情。

如果我想停止这个程序,怎么办呢? 找到nodejs的系统进程,再杀死。


~ ps -aux|grep node
root     21333  0.6  3.7 909200 38292 pts/0    Sl   09:38   0:00 node app.js
~ kill -9 21333  

直接暴力解决。如果能像系统服务一样,来启动和关闭nodejs应用,多好啊!下面就通过upstart来完成把nodejs应用封装为系统服务。

2. upstart任务脚本

upstart的使用在 upstart把应用封装成系统服务 一文中已经介绍过了。


~ vi /etc/init/nodejs-moive.conf

description "node.js moive.me"
author "bsspirit <http://blog.fens.me>"

start on startup
stop on shutdown

script
    export HOME="/root/deploy/movie"
    echo $$ > /var/run/moiveme.pid
    export NODE_ENV=production
    exec /usr/bin/node /root/deploy/movie/server.js

    #日志输出
    #exec /usr/bin/node /root/deploy/movie/server.js >> /var/log/moiveme.log 2>&1
end script

pre-start script
    echo "[`date -u +%Y-%m-%dT%T.%3NZ`] (sys) Starting" >> /var/log/moiveme.log
end script

pre-stop script
    rm /var/run/moiveme.pid
    echo "[`date -u +%Y-%m-%dT%T.%3NZ`] (sys) Stopping" >> /var/log/moiveme.log
end script

3. nodejs应用管理

启动nodejs-moive应用,进程ID:21257


~ start nodejs-moive
nodejs-moive start/running, process 21257

~ tail -f /var/log/moiveme.log
[2013-06-21T09:21:17.122Z] (moive.me) Starting

~ ps aux|grep node
root     21257  8.0  3.7 909204 37824 ?        Ssl  09:21   0:00 /usr/bin/node /root/deploy/movie/server.js

查看运行状态, 进程21257正常运行


~ status nodejs-moive
nodejs-moive start/running, process 21257

杀死nodejs应用进程21257,通过upstart管理,nodejs-moive应用会自动重启


~ kill -9 21257

#自动重启日志
~ tail -f /var/log/moiveme.log
[2013-06-21T09:21:33.662Z] (moive.me) Starting

#查看系统进程,发现进行ID变了
~ ps -aux|grep node
root     21280  9.1  3.7 909204 37704 ?        Ssl  09:21   0:00 /usr/bin/node /root/deploy/movie/server.js

#查看进程状态,进程ID确实变了,而且是自动完成的
~ status nodejs-moive
nodejs-moive start/running, process 21280

这样很方便地我们可以通过upstart,以系统服务的方式管理nodejs应用。运维起来会很容易!!

 

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

打赏作者

upstart把应用封装成系统服务

ubuntu实用工具系列文章

操作系统实用工具系列文章,将介绍基于Linux ubuntu的各种工具软件的配置和使用。有些工具大家早已耳熟能详,有些工具经常用到但确依然陌生。我将记录我在使用操作系统时,安装及配置工具上面的一些方法,把使用心得记录下来也便于自己的以后查找和回忆。

关于作者

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

转载请注明出处:
http://blog.fens.me/linux-upstart/

upstart-basic

前言

对于使用linux的同学,敲大段的命令都已经是家长便饭了。但有些时候用命令也不是那么方便,比如启动一个后台程序, sh ./app & 执行启动命令很简单,如果想停止这个应用或者重启这个应用,就不是那么方便了。

如果能把应用封装成系统服务,那么就可以使用的 启动,重起,停止,状态检查等的标准方法了。应用会像一个守护程序一样,被操作系统所管理。

 

文章目录

  1. 初识upstart
  2. upstart任务文件的语法
  3. upstart命令
  4. upstart封装mytest
  5. 例子:upstart封装Nginx
  6. 例子:upstart封装MySQL
  7. 例子:upstart封装ssh

1. 初识upstart

说来惭愧,用了很多年的linux,也没有想法去怎么能优化一下应用启动。最近部署Nodejs应用时才发现,原来ubuntu有这么优雅的应用管理方式。

upstart可以用来代替/etc/init.d/的执行脚本,额外提供了一些特性,像速度,状态检查,简单定义任务等。

upstart两个核心点:事件(events),任务(jobs)

事件状态图

upstart

对状态的描述

  • waiting : initial state.
  • starting : job is about to start.
  • pre-start : running pre-start section.
  • spawned : about to run script or exec section.
  • post-start : running post-start section.
  • running : interim state set after post-start section processed denoting job is running (But it may have no associated PID!)
  • pre-stop : running pre-stop section.
  • stopping : interim state set after pre-stop section processed.
  • killed : job is about to be stopped.
  • post-stop : running post-stop section.

每个任务需要有一个配置文件,存放在/etc/init/目录下面。

~ vi /etc/init/mytest.conf

完成任务配置文件后,可以直接用initctl, start, stop 命令对任务进行启动,停止,查看状态 等的操作。

start mytest.conf

注:下面所有实例都以root权限进行操作

本文主要以实践为主。原理及更多细节介绍,请查看Upstart Cookbook:

http://upstart.ubuntu.com/cookbook/

2. upstart任务文件的语法

详细介绍: http://upstart.ubuntu.com/wiki/Stanzas
注:Stanzas的文档很多内容已经过期,建议参考cookbook或者man的使用帮助。

任务文件支持的语法关键字

Process Definition:
exec, script, pre-start, post-start, pre-stop, post-stop,

Event Definition:
start on, stop on, manual

Job Environment:
env, export

Services, tasks and respawning:
normal exit, respawn, respawn limit, task

Instances:
instance

Documentation:
description, author, version, emits, usage

Process environment:
console none,console log, console output, console owner, nice, limit, chroot, chdir, oom score, setgid, setuid, umask

Process Control:
expect fork, expect daemon, expect stop, kill signal, kill timeout

过期关键字:
service, daemon, pid

部分语法关键字介绍:

exec : 执行命令,在script块中使用。

语法:exec /usr/bin/zip -v

script: 脚本块,包括主运行脚本

语法:


script
    exec /usr/bin/zip /root/upstart.zip /root/upstart.txt
end script

pre-start: 脚本块,在主运行脚本之前执行的脚本

语法:


pre-start script
    exec rm /root/upstart.txt
    exec echo pre-start >> /root/upstart.txt
end script

post-start: 脚本块,在主运行脚本之后,running状态之前

语法:


post-start script
    exec echo post-start >> /root/upstart.txt
end script

pre-stop: 脚本块,在执行stop之前

语法:


pre-stop script
    exec echo pre-stop >> /root/upstart.txt
end script

post-stop: 脚本块,在主运行脚本被杀死之后

语法:


post-stop script
    exec echo post-stop >> /root/upstart.txt
end script

start on: 事件,启动任务

语法:

start on startup

stop on: 事件,停止任务

语法:

stop on suhtdown

description: 描述,信息提示
语法:

description "This is a upstart testing."

author: 描述,作者信息
语法:

author "Conan_Z <bsspirit@gmail.com>"

version: 描述,版本信息
语法:

version "0.0.1 dev"

respawn: 命令,设置服务异常停止后自动重启
语法:

respawn

respawn limit: 命令,设置服务异常停止后重启次数及间隔时间
语法:

respawn limit 15 3

service: 命令,0.6版本后不再使用,被respawn取代

instance: 定义实例名字,可以通过命令给任务传参数
语法:


instance $TTY
exec /sbin/getty -8 38300 $TTY

#通过命令传参数
~ start mytest $TTY=tty1

daemon: 作为守护进程的标志,0.5.0版本后被expect fork取代

kill timeout: 命令,在到达指定时间后,停止应用

语法:

kill timeout 5

kill timeout: 命令,正常退出,不会被respawn重启

语法:

normal exit 0 TERM

console: 命令,控制后输出,支持4种操作logged|output|owner|none

语法:

console owner

env: 变量,设置任务的环境变量

语法:

env PIDFILE=/var/run/myprocess.pid

umask: 变量,设置任务的文件权限的掩码

语法:

umask 0755

nice: 变量,设置任务的调度优先级

语法:

nice -5

limit: 变量,设置任务的资源限制

语法:

limit nproc 10 10

chroot: 变量,设置任务的根目录

语法:

chroot /var/lib/www/jail

chdir: 变量,设置任务的工作目录

语法:

chdir /var/tmp

3. upstart命令介绍

upstart-cmd

查看upstart版本

~ initctl version
init (upstart 1.5)

查看mytest应用状态

#方法1
~ initctl list|grep mytest
#方法2
~ status mytest

启动mytest应用

#方法1:
~ initctl start mytest
#方法2
~ start mytest

停止mytest应用

#方法1:
~ initctl stop mytest
#方法2
~ stop mytest

4. upstart封装mytest

用upstart写一个简单的应用脚本。

~ vi /etc/init/mytest.conf

description "mytest"
author "bsspirit <http://blog.fens.me>"

env var=bar
export var

start on startup
stop on shutdown

respawn
respawn limit 2 5

console output

pre-start script
        logger "pre-start: before: var=$var"
        var=pre-start
        export var
        logger "pre-start: after: var=$var"
end script

post-start script
        logger "post-start: before: var=$var"
        var=post-start
        export var
        logger "post-start: after: var=$var"
end script

script
        logger "script: before: var=$var"
        var=main
        export var
        sleep 60000
        logger "script: after: var=$var"
end script

post-stop script
        logger "post-stop: before: var=$var"
        var=post-stop
        export var
        logger "post-stop: after: var=$var"
end script

 

测试mytest程序:

启动mytest任务


~ start mytest
mytest start/running, process 20682

查看日志跟踪运行状态


~ tail -f /var/log/syslog

Jun 21 08:11:21 li478-194 logger: pre-start: before: var=bar
Jun 21 08:11:21 li478-194 logger: pre-start: after: var=pre-start
Jun 21 08:11:21 li478-194 logger: script: before: var=bar
Jun 21 08:11:21 li478-194 logger: post-start: before: var=bar
Jun 21 08:11:21 li478-194 logger: post-start: after: var=post-start

查看mytest任务状态


~ status mytest
mytest start/running, process 20682

查看系统进程,因为在程序中用sleep停止,要通过sleep查询


~ ps -aux|grep sleep

root     20686  0.0  0.0   4304   352 ?        S    08:11   0:00 sleep 60000

杀掉sleep进程,mytest自动重启


~ kill -9 20686
~ ps -aux|grep sleep
root     20703  0.0  0.0   4304   344 ?        S    08:14   0:00 sleep 60000

~ /var/log/syslog
Jun 21 08:15:59 li478-194 logger: post-stop: before: var=bar
Jun 21 08:15:59 li478-194 logger: post-stop: after: var=post-stop
Jun 21 08:15:59 li478-194 logger: pre-start: before: var=bar
Jun 21 08:15:59 li478-194 logger: pre-start: after: var=pre-start
Jun 21 08:15:59 li478-194 logger: script: before: var=bar
Jun 21 08:15:59 li478-194 logger: post-start: before: var=bar
Jun 21 08:15:59 li478-194 logger: post-start: after: var=post-start

停止mytest


~ stop mytest
mytest stop/waiting

~ /var/log/syslog
Jun 21 08:16:49 li478-194 logger: post-stop: before: var=bar
Jun 21 08:16:49 li478-194 logger: post-stop: after: var=post-stop

~ ps -aux|grep sleep

通过命令传参数,启动mytest


~ start mytest var=conan
mytest start/running, process 20735

~ /var/log/syslog
Jun 21 08:18:51 li478-194 logger: pre-start: before: var=conan
Jun 21 08:18:51 li478-194 logger: pre-start: after: var=pre-start
Jun 21 08:18:51 li478-194 logger: script: before: var=conan
Jun 21 08:18:51 li478-194 logger: post-start: before: var=conan
Jun 21 08:18:51 li478-194 logger: post-start: after: var=post-start

不同参数,再次启动mytest


~ start mytest var=bsspirit
start: Job is already running: mytest

启动已经启动,禁止应用多次启动。
实验成功,我们可以很方便地利用upstart,来封装我们自己的应用成为系统服务。

下面将介绍同个软件使用upstart的例子。

5. upstart封装Nginx

Nginx官方配置:http://wiki.nginx.org/Upstart

增加配置文件


~ vi /etc/init/nginx

# nginx

description "nginx http daemon"
author "George Shammas <georgyo@gmail.com>"

start on (filesystem and net-device-up IFACE=lo)
stop on runlevel [!2345]

env DAEMON=/usr/sbin/nginx
env PID=/var/run/nginx.pid

expect fork
respawn
respawn limit 10 5
#oom never

pre-start script
        $DAEMON -t
        if [ $? -ne 0 ]
                then exit $?
        fi
end script

exec $DAEMON

查看nginx的系统状态


~ initctl list | grep nginx

启动nginx


~ initctl start nginx

6. upstart封装MySQL

查看upstart配置文件,把MySQL变为系统服务.


~ vi /etc/init/mysql.conf

description     "MySQL Server"
author          "Mario Limonciello <superm1@ubuntu.com>"

start on runlevel [2345]
stop on starting rc RUNLEVEL=[016]

respawn
respawn limit 2 5

env HOME=/etc/mysql
umask 007

# The default of 5 seconds is too low for mysql which needs to flush buffers
kill timeout 300

pre-start script
    #Sanity checks
    [ -r $HOME/my.cnf ]
    [ -d /var/run/mysqld ] || install -m 755 -o mysql -g root -d /var/run/mysqld
    /lib/init/apparmor-profile-load usr.sbin.mysqld
    LC_ALL=C BLOCKSIZE= df --portability /var/lib/mysql/. | tail -n 1 | awk '{ exit ($4<4096) }'
end script

exec /usr/sbin/mysqld

post-start script
   for i in `seq 1 30` ; do
        /usr/bin/mysqladmin --defaults-file="${HOME}"/debian.cnf ping && {
            exec "${HOME}"/debian-start
            # should not reach this line
            exit 2
        }
        statusnow=`status`
        if echo $statusnow | grep -q 'stop/' ; then
            exit 0
        elif echo $statusnow | grep -q 'respawn/' ; then
            exit 1
        fi
        sleep 1
    done
    exit 1
end script

7. upstart封装ssh


~ vi /etc/init/ssh.conf

# ssh - OpenBSD Secure Shell server
#
# The OpenSSH server provides secure shell access to the system.

description     "OpenSSH server"

start on filesystem or runlevel [2345]
stop on runlevel [!2345]

respawn
respawn limit 10 5
umask 022

# 'sshd -D' leaks stderr and confuses things in conjunction with 'console log'
console none

pre-start script
    test -x /usr/sbin/sshd || { stop; exit 0; }
    test -e /etc/ssh/sshd_not_to_be_run && { stop; exit 0; }
    test -c /dev/null || { stop; exit 0; }

    mkdir -p -m0755 /var/run/sshd
end script

# if you used to set SSHD_OPTS in /etc/default/ssh, you can change the
# 'exec' line here instead
exec /usr/sbin/sshd -D

我在这里介绍的内容还很初级,只要会写任务脚步就可以了。
后面文章我会介绍upstart封装nodejsmongodbphp,java等的应用的任务脚本。

 

转载请注明出处:
http://blog.fens.me/linux-upstart/

打赏作者

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/

打赏作者