异常现象:
在/etc/rc.local中添加/usr/local/nginx/sbin/nginx来开机自动启动NGINX时,PassengerHelperAgent进程不停反复重启,而从shell上手动启动NGINX时一切正常。
追查过程:
查阅异常时的error.log日志发现以下错误:
1 | [ pid=3413 thr=140583025772288 file=ext/nginx/HelperAgent.cpp:963 time=2014-09-30 11:05:20.925 ]: Uncaught exception in PassengerServer client thread: |
根据日志错误信息,可以确定是PassengerHelperAgent进程文件描述符达到了上限。
找到ext/nginx/HelperAgent.cpp文件的963行:
1 | void threadMain() { |
通过上下文可以确定是调用acceptConnection()出错,查看acceptConnection()代码,确定是由该函数抛出的异常。
1 | FileDescriptor acceptConnection() { |
syscalls::accept是对系统调用accept的简单封装。
1 | syscalls::accept(int sockfd, struct sockaddr *addr, socklen_t *addrlen) { |
错误原因就是accept由于进程文件描述符达到上限而出错返回了。
接下来追查为什么进程文件描述符数会达到上限。
首先看一下PassengerHelperAgent的整体代码逻辑:
1 | int |
首先创建一个Server对象,然后调用Server对象的mainLoop成员函数。Server对象构造函数会调用成员函数startListening。
1 | void startListening() { |
createUnixServer函数会创建一个socket文件,然后监听这个文件。NGINX收到请求后,会由Passenger模块转发请求到该socket文件。
mainLoop会调用成员函数startClientHandlerThreads,它会创建numberOfThreads个Client对象。
1 | void startClientHandlerThreads() { |
Client对象构造函数会启动一个线程执行threadMain。threadMain就是我们上面出错的函数。每个线程等待接收通过socket文件发来的请求,接收请求后调用handleRequest进行处理。
1 | Client(unsigned int number, ApplicationPool::Ptr pool, |
问题出在线程调用accept等待接收请求时。我们所创建的线程数量numberOfThreads是在Server对象被创建时指定的。
1 | numberOfThreads = maxPoolSize * 4; |
而maxPoolSize由passenger_max_pool_size配置项指定,我们指定的是256。256 × 4 = 1024,开机启动时PassengerHelperAgent进程的文件描述符上限就是1024。这个数字值得怀疑。因而我将配置修改为128,果然正常了。
1 | passenger_max_pool_size 256; |
可以确定每个线程中占用了文件描述符。然而从代码中并没有找到打开文件相关的逻辑。当accept成功返回时,会返回一个新的文件描述符。开始怀疑accept在还没有接收到请求时就预先占用了一个文件描述符。通过一个简单程序来验证。
1 |
|
使用ulimit将shell文件打开数上限修改为1024:
1 | $ ulimit -n 1024 |
编译验证程序,并执行
1 | $ gcc emfile.c -lpthread |
得到结果:
1 | accept failed: 591611648: Too many open files |
确实如些,那再来看一下accept的实现。accept系统调用的内核实现是sys_accept,而sys_accept是对sys_accept4的简单封装。
1 | SYSCALL_DEFINE3(accept, int, fd, struct sockaddr __user *, upeer_sockaddr, |
1 | SYSCALL_DEFINE4(accept4, int, fd, struct sockaddr __user *, upeer_sockaddr, |
sys_accept4中在调用sock->ops->accept去接收网络请求前就调用sock_alloc_file来分配文件描述符。再来看sock_alloc_file这个函数:
1 | static int sock_alloc_file(struct socket *sock, struct file **f, int flags) |
sock_alloc_file会调用get_unused_fd_flags,这是一个宏,实际会调用函数alloc_fd, 而alloc_fd又会调用函数expand_files:
1 | int expand_files(struct files_struct *files, int nr) |
可以看到expand_files进行文件描述符限制的检查,当超过限制时返回”EMFILE”。”EMFILE”错误的提示就是”Too many open files”。
1 |
结合上面的测试程序,使用一个systemtap脚本可以捕获到上述调用路径。
1 | probe kernel.function("expand_files").return { |
执行stap:
1 | $sudo stap emfile.stap |
捕获结果为:
1 | start |
最终确定异常原因:
开机自启时,进程的打开文件数限制为1024,而创建1024个线程执行accept()时。每个accept会占用一个文件描述符, 达到了进程的文件描述符上限而异常。而从shell启动时,我们shell进程的文件描述符限制是32768,因而不会出现问题。
解决方法:
创建一个启动脚本,在执行/usr/local/nginx/sbin/nginx前执行ulimit修改文件描述符限制。
1 | ulimit -SHn 65535 |
注意:
- /etc/security/limits.conf中的设置只针对登录动作发生时才生效,因而对于开机自动启动进程这种情况,这种修改该文件的方式不生效。
- Passenger版本为3.0.11
- kernel版本为CentOS 6.2内核,kernel-2.6.32-220.4.2.el6