内存区段错误(Segmentation Fault)相信使用过Unix-like操作系统的都不陌生。 它的定义可以参考维基百科。 主因是对非法的内存访问进行保护,由硬件触发,通知操作系统;操作系统内核会进行 一些保护操作,一般是发进程信号给造成这一错误的进程,例如在Unix-Like操作系统下, 会发送SIGSEGV信号。

在开发程序的过程中我们会经常遇到一些写的还不是那么完善的程序会报出这个错误, 起因也主要是对内存的不合理访问(读或写),原因得根据各例具体分析。不过某发现 非常多的初级程序员发现这个问题出在相对底层的代码中(往往是C级别的,又或者是 脚本语言的底层实现里),就放弃对原因进行分析。

其实只要对C语言、调试器(这里指GDB)与操作系统稍加了解后,排查SEGV问题并不是 想象中那么困难。

背景

有两台运行PHP-FPM 5.3.10的服务器,这PHP当初是编译的;由于当初不是某安装的, 如何编,如何配置已无从查起。它们每天会处理大约3,000K的请求。做的事情也不复杂, 将收到的请求内容简单处理后写入磁盘文件,完成一个记录日志的工作。

其中用到的PHP C扩展,只有memcached;刚开始也是怀疑扩展的问题(经验主义,之前 遇到SEGV多半是由于扩展粗制烂造),然而事实证明查问题还得从证据出发,不能靠猜。

看到日志里的SEGV时,最先采取的做法是,“凭空想象”认为是C扩展或PHP本身的问题, 在忍受了多次休息时间被拖起来重启PHP-FPM之后决定将PHP-FPM与扩展重新编译,不过 这次换了5.3的最新版本。(不升级到当前稳定的5.5是因为怕代码有兼容性问题)

排查

想当然的解决方案到底还是解决不了问题的,现在回到线索上来看。发现PHP-FPM的错误 日志中有SEGV。

由于是内存区段错误,那么对进程内存的访问出现问题,对于上层的脚本语言来说,只 可能是脚本语言解释器本身或其他扩展,又或者更底层才是真正的原因。打开日志,发现 有如下内容

Nov 26 17:03:53 app10-102 kernel: php-fpm[831]: segfault at 0000001b00000000 rip 0000001b00000000 rsp 00007fffe9342f98 error 14

排查SEGV的一般手法是采用core dumpcore(5))文件,将当时的进程现场记录下来以供调试使用。 在使用core dump时,需要先做一些配置准备工作

  1. 如果是Linux 3.7以上内核的话,需要开启CONFIG_COREDUMP选项
  2. ulimit里解开了core dump的限制
  3. 在Linux下需要对proc里core相关的参数进行调整

分别可以使用以下命令完成

$ ulimit -c unlimited
$ echo 1 > /proc/sys/kernel/core_uses_pid  # 开启在core_pattern里使用进程号

# 设置core dump文件保存路径与文件名,例如这个例子里将是 /tmp/php-fpm-831.core
$ echo "/tmp/%e-%p.core" > /proc/sys/kernel/core_pattern

配置完成后需要将运行的程序在当前设置过的shell里重启。然后等着程序SEGV就行了…

顺利得到core dump文件后,使用GDB对其进行调试。

$ gdb /usr/local/php-fpm/sbin/php-fpm /tmp/php-fpm-831.core

进入GDB调试模式后,会得到如下输出,已经再现当时的内存现场

Program terminated with signal 11, Segmentation fault.
#0 0x0000001b00000000 in ?? ()
(gdb)

这时候我们输入bt(backstrace)并回车,会得到调用栈信息

(gdb) bt
#0 0x0000001b00000000 in ?? ()
#1 0x0000000000742f1a in fpm_event_epoll_wait (queue=, timeout=831) at /srv/php-5.3.29/sapi/fpm/fpm/events/epoll.c:143
#2 0x0000000000738082 in fpm_event_loop (err=0) at /srv/php-5.3.29/sapi/fpm/fpm/fpm_events.c:403
#3 0x0000000000738082 in fpm_run (max_requests=0x7fffe934554c) at /srv/php-5.3.29/sapi/fpm/fpm/fpm.c:113
#4 0x000000000073a377 in main (argc=6,argv=0x7fffe9345668) at /srv/php-5.2.29/sapi/fpm/fpm/fpm_main.c:1842

这里会看到第一帧的栈信息无法显示,原因有很多,这里还没细查。不过后面一帧就发 现问题出在PHP-FPM的主事件循环里,可以找到源代码

/* events have been triggered, let's fire them */
for (i = 0; i < ret; i++) {

    /* do we have a valid ev ptr ? */
    if (!epollfds[i].data.ptr) {
        continue;
    }

    /* fire the event */
    fpm_event_fire((struct fpm_event_s *)epollfds[i].data.ptr);  // <= 问题出在这行

    /* sanity check */
    if (fpm_globals.parent_pid != getpid()) {
        return -2;
    }
}

极有可能问题出在这行上。将这些栈信息到网上搜索一番后会定位到一个PHP上的一个issue。 PHP-FPM在使用epoll处理事件时可能出现了一些小批漏。前面提到的issue中指出避免的 方法是在PHP-FPM配置中间中将主循环事件机制改换成poll。

[global]
;; events.mechanism = epoll
events.mechanism = poll

使用这个配置运行20多天未发现异常。

其他疑点

请求量的变化似乎不是引起这个问题的主因,随着时间推移,出现SEGV的密度越来越大, 比较奇怪。出现SEGV的时间点,似乎都是周末?

由于之前core dump文件没有保存下来,现在无法继续追查那个显示为??的帧到底是哪 段代码,所以比较棘手。虽然绕开了问题,但这说明PHP-FPM(至少是5.3,不过某翻了一 下5.4与5.5的分支源代码,发现这段处理基本上是一样的)里对epoll还存在隐患

当然,这还未查到问题的根源(root cause),会想法子继续追查下去。

__TO BE UPDATED__