一次php进程诡异退出的排查过程

背景

   最近给XX项目搭建一个反垃圾平台。效果不错，但是出现了一个诡异的事情。离线扫描部分会有一个常驻的php进程，以便处理发现的垃圾信息。常驻的php进程总是诡异的退出。php代码示例如下：

<?php
while(1){
    $content = fgets(STDIN);
    if(empty($content)){
        sleep(1);
    }
    //逻辑处理部分代码省略
}
?>

排查过程

   最初的想法是php执行过程中出现的致命错误，导致php进程退出。好吧，我们使用register_shutdown_function来跟踪下到底是什么错误导致的进程退出。(想更多了解register_shutdown_function，请查看博文 妙用php中的register_shutdown_function和fastcgi_finish_request)加入了错误捕捉代码。如下：

<?php
$is_end = false;
function catch_error(){
        global $is_end;
        $time = date('Y-m-d H:i:s');
        $error = error_get_last();
        $msg = "$time [error]";
        if($is_end){
                $msg .= "is_end[yes]";
        }else{
                $msg .= "is_end[no]";
        }
        if($error){
                $msg .= var_export($error,1);
        }
        echo $msg."\r\n";
}
register_shutdown_function("catch_error");
?>

   可是，php进程再次退出。而在日志中并没有记录任何信息。说明register_shutdown_function方法根本没有执行。是什么导致register_shutdown_function方法没有运行呢？在php的官方文档中又这样一个注释：

   Shutdown functions will not be executed if the process is killed with a SIGTERM or SIGKILL signal. While you cannot intercept a SIGKILL, you can use pcntl_signal() to install a handler for a SIGTERM which uses exit() to end cleanly.

   注释的意思是当php进程获得SIGTERM和SIGKILL信号而退出时，是不执行register_shutdown_function方法的。可以使用pcntl_signal()方法来捕获信息，并调用相应的处理方法。

   好，那是不是信号导致我们的php进程退出呢？我们加入如下代码：

<?php
declare(ticks = 1);
function sig_handler($signo){
        $time = date('Y-m-d H:i:s');
        echo $time." exit  signo[{$signo}]\r\n";
        exit("");
}
pcntl_signal(SIGTERM, "sig_handler");
pcntl_signal(SIGHUP, "sig_handler");
pcntl_signal(SIGINT, "sig_handler");
pcntl_signal(SIGQUIT, "sig_handler");
pcntl_signal(SIGILL, "sig_handler");
pcntl_signal(SIGPIPE, "sig_handler");
pcntl_signal(SIGALRM, "sig_handler");
?>

   过一段时间，发现php进程退出了，日志中出现了如下日志信息：

   2014-11-23 18:30:06 exit  signo[14]

   2014-11-23 18:30:06 [error]is_end[no]

   看来是sigalarm信号导致php进程退出了。这个信号是可以捕获和处理的。这样无关紧要的信号，我们还是忽略吧。最终的代码如下：

<?php
declare(ticks = 1);
$is_end = false;
function catch_error(){
        global $is_end;
        $time = date('Y-m-d H:i:s');
        $error = error_get_last();
        $msg = "$time [error]";
        if($is_end){
                $msg .= "is_end[yes]";
        }else{
                $msg .= "is_end[no]";
        }
        if($error){
                $msg .= var_export($error,1);
        }
        echo $msg."\r\n";
}
register_shutdown_function("catch_error");
 
function sig_handler($signo){
        $time = date('Y-m-d H:i:s');
        if($signo == 14){
                //忽略alarm信号
                echo $time." ignore alarm signo[{$signo}]\r\n";
        }else{
                echo $time." exit  signo[{$signo}]\r\n";
                exit("");
        }
}
pcntl_signal(SIGTERM, "sig_handler");
pcntl_signal(SIGHUP, "sig_handler");
pcntl_signal(SIGINT, "sig_handler");
pcntl_signal(SIGQUIT, "sig_handler");
pcntl_signal(SIGILL, "sig_handler");
pcntl_signal(SIGPIPE, "sig_handler");
pcntl_signal(SIGALRM, "sig_handler");
while(1){
    $content = fgets(STDIN);
    if(empty($content)){
        sleep(1);
    }
    //逻辑处理部分代码省略
}
$is_end = true;
?>

   经过一段观察，在日志中又发现了alarm相关的日志，但是php进程依然在。看来我们的修改有作用了。