PHP5下的Error错误处理及问题定位

背景说明

来说说当PHP出现E_ERROR级别致命的运行时错误的问题定位方法。例如像Fatal error: Allowed memory size of内存溢出这种。当出现这种错误时会导致程序直接退出，PHP的error log中会记录一条错误日志说明报错的具体文件和代码行数，其它的任何信息都没有了。如果是PHP7的话还可以像捕获异常一样捕获错误，PHP5的话就不行了。

一般想到的方法就是看看报错的具体代码，如果报错文件是CommonReturn.class.php像下面这个样子。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
<?php

/**
 * 公共返回封装
 * Class CommonReturn
 */
class CommonReturn
{

    /**
     * 打包函数
     * @param     $params
     * @param int $status
     *
     * @return mixed
     */
    static public function packData($params, $status = 0)
    {
        $res['status'] = $status;
        $res['data'] = json_encode($params);
        return $res;
    }

}

其中json_encode那一行报错了，然后你查了下packData这个方法，有很多项目的类中都有调用，这时要怎么定位问题呢？

场景复现

好，首先我们复现下场景。假如实际调用的程序bug.php如下

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
<?php

require_once './CommonReturn.class.php';

$res = ini_set('memory_limit', '1m');

$res = [];
$char = str_repeat('x', 999);
for ($i = 0; $i < 900 ; $i++) {
    $res[] = $char;
}

$get_pack = CommonReturn::packData($res);

// something else

运行bug.php PHP错误日志中会记录

1
[08-Jan-2019 11:22:52 Asia/Shanghai] PHP Fatal error:  Allowed memory size of 1048576 bytes exhausted (tried to allocate 525177 bytes) in /CommonReturn.class.php on line 20

复现成功，错误日志中只是说明了报错的文件和哪行代码，无法知道程序的上下文堆栈信息，不知道具体是哪块业务逻辑调用的，这样一来就无法定位修复错误。如果是偶尔出现，并且没有来自前端业务的反馈要怎么排查呢。

解决思路

  1. 有人想到了修改memory_limit增加内存分配，但这种方法治标不治本。做开发肯定要找到问题的根源。
  2. 开启core dump，如果生成code文件可以进行调试，但是发现code只有进程异常退出才会生成。像E_ERROR级别的错误不一定会生成code文件，内存溢出这种可能PHP内部自己就处理了。
  3. 使用register_shutdown_function注册一个PHP终止时的回调函数，再调用error_get_last如果获取到了最后发生的错误，就通过debug_print_backtrace获取程序的堆栈信息，我们试试看。

修改CommonReturn.class.php文件如下

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
<?php

/**
 * 公共返回封装
 * Class CommonReturn
 */
class CommonReturn
{

    /**
     * 打包函数
     * @param     $params
     * @param int $status
     *
     * @return mixed
     */
    static public function packData($params, $status = 0)
    {

        register_shutdown_function(['CommonReturn', 'handleFatal']);

        $res['status'] = $status;
        $res['data'] = json_encode($params);
        return $res;
    }

    /**
     * 错误处理
     */
    static protected function handleFatal()
    {
        $err = error_get_last();
        if ($err['type']) {
            ob_start();
            debug_print_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS, 5);
            $trace = ob_get_clean();
            $log_cont = 'time=%s' . PHP_EOL . 'error_get_last:%s' . PHP_EOL . 'trace:%s' . PHP_EOL;
            @file_put_contents('/tmp/debug_' . __FUNCTION__ . '.log', sprintf($log_cont, date('Y-m-d H:i:s'), var_export($err, 1), $trace), FILE_APPEND);
        }

    }

}

再次运行bug.php，日志如下。

1
2
3
4
5
6
7
error_get_last:array (
  'type' => 1,
  'message' => 'Allowed memory size of 1048576 bytes exhausted (tried to allocate 525177 bytes)',
  'file' => '/CommonReturn.class.php',
  'line' => 23,
)
trace:#0  CommonReturn::handleFatal()

回溯信息没有来源，尴尬了。猜测因为backtrace信息保存在内存中，当出现致命错误时会清空。没办法，把backtrace从外面传进来试试。再次修改CommonReturn.class.php。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
<?php

/**
 * 公共返回封装
 * Class CommonReturn
 */
class CommonReturn
{

    /**
     * 打包函数
     * @param     $params
     * @param int $status
     *
     * @return mixed
     */
    static public function packData($params, $status = 0)
    {

        ob_start();
        debug_print_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS, 5);
        $trace = ob_get_clean();
        register_shutdown_function(['CommonReturn', 'handleFatal'], $trace);

        $res['status'] = $status;
        $res['data'] = json_encode($params);
        return $res;
    }

    /**
     * 错误处理
     * @param $trace
     */
    static protected function handleFatal($trace)
    {
        $err = error_get_last();
        if ($err['type']) {
            $log_cont = 'time=%s' . PHP_EOL . 'error_get_last:%s' . PHP_EOL . 'trace:%s' . PHP_EOL;
            @file_put_contents('/tmp/debug_' . __FUNCTION__ . '.log', sprintf($log_cont, date('Y-m-d H:i:s'), var_export($err, 1), $trace), FILE_APPEND);
        }

    }

}

再次运行bug.php，日志如下。

1
2
3
4
5
6
7
error_get_last:array (
  'type' => 1,
  'message' => 'Allowed memory size of 1048576 bytes exhausted (tried to allocate 525177 bytes)',
  'file' => '/CommonReturn.class.php',
  'line' => 26,
)
trace:#0  CommonReturn::packData() called at [/bug.php:13]

成功定位到了调用来源，在bug.php的13行。将最终的CommonReturn.class.php发布到生产环境，再次出现出现错误时候看日志就可以了。但是这样的话所有调用packData的程序都会执行trace函数，肯定也会影响性能的。

总结

  1. 对于其中使用到的register_shutdown_function函数需要注意，可以注册多个不同的回调，但是如果某一个回调函数中exit了，那么后面注册的回调函数都不会执行。
  2. debug_print_backtrace这个获取回溯信息函数第一个是否包含请求参数，第二个是回溯记录层数，我们这里是不返回请求参数，可以节省些内存，而且如果请求参数巨大的话调这个函数可能就直接内存溢出了。
  3. 最好的办法就是升级PHP7，可以像异常一样捕获错误。