Deliverer 1.1.2 修复使用魔术方法后调用栈丢失的问题

梦康 2021-08-30 00:00:00 866

非常高兴还是有不少朋友在使用这个项目的,从而帮助他们解决了一些线上的问题。

如果你对线上一个项目运行逻辑不熟悉,或者你对某个方法的调用来源不清楚,又或者线上有一个接口不知道是哪里异常退出了,还有线上调用特别耗时,都比较适合使用 Deliverer 来解决,帮助你避免跑路。

前几日有一位群友线上遇到一些问题,使用 Deliverer 来排查,但是也还是没能立马解决,于是微信联系了我。在工具使用上和我沟通了下,虽然通过 Deliverer 的历史日志记录最终定位了线上 bug,但是也发现了 Deliverer 工具之前忽略的一个问题:

因为为了尽量减少日志的输出和性能的损耗,只监控了用户自定义的方法和函数,导致一些通过系统的魔术方法,比如__get__call

比如下面这段代码

error_reporting(E_ALL);
ini_set('display_errors',true);
function aaa($a){
    return bbb($a+100);
}

function bbb($b){
    return ccc($b*100);
}

function ccc($c){
    echo 11111;
    return 1;
}

function ddd(){
    return 2;
}
class abc{
    public function test(){
        $this->aaa;
    }

    private function test2($name){
        echo $name;
        $abcd = new abcd();
        call_user_func([$abcd,"test"]);
    }

    public function __get($name)
    {
        return $this->test2($name);
    }
}

class abcd{
    public function test(){
        $this->aaa;
    }

    private function test2($name){
        $this->test3($name);
    }

    private function test3($name){
        echo $name;
    }

    public function __get($name)
    {
        return $this->test2($name);
    }
}

aaa(1234);
ddd();

$abc = new abc();
$abc->test();
$abcd = new abcd();
$abcd->test();
call_user_func([$abcd,"test"]);
24307-1630335728072334 cli /root/deliverer-main/deliverer/extension/test.php
1630335728072690|0x7ff12cc1e030|(nil)|aaa|/root/deliverer-main/deliverer/extension/test.php|56
1630335728072710|0x7ff12cc1e1a0|0x7ff12cc1e030|bbb|/root/deliverer-main/deliverer/extension/test.php|5
1630335728072712|0x7ff12cc1e220|0x7ff12cc1e1a0|ccc|/root/deliverer-main/deliverer/extension/test.php|9
1630335728072725|0x7ff12cc1e030|(nil)|ddd|/root/deliverer-main/deliverer/extension/test.php|57
1630335728072735|0x7ff12cc1e030|(nil)|abc::test|/root/deliverer-main/deliverer/extension/test.php|60
1630335728072749|0x7ff12cc1e200|0x7fff6976a640|abc::test2|/root/deliverer-main/deliverer/extension/test.php|33
1630335728072762|0x7ff12cc1e270|0x7ff12cc1e200|abcd::test|/root/deliverer-main/deliverer/extension/test.php|28
1630335728072764|0x7ff12cc1e390|0x7fff6976a060|abcd::test2|/root/deliverer-main/deliverer/extension/test.php|52
1630335728072766|0x7ff12cc1e400|0x7ff12cc1e390|abcd::test3|/root/deliverer-main/deliverer/extension/test.php|43
1630335728072772|0x7ff12cc1e030|(nil)|abcd::test|/root/deliverer-main/deliverer/extension/test.php|62
1630335728072773|0x7ff12cc1e200|0x7fff6976a640|abcd::test2|/root/deliverer-main/deliverer/extension/test.php|52
1630335728072774|0x7ff12cc1e270|0x7ff12cc1e200|abcd::test3|/root/deliverer-main/deliverer/extension/test.php|43
1630335728072777|0x7ff12cc1e030|(nil)|abcd::test|/root/deliverer-main/deliverer/extension/test.php|63
1630335728072778|0x7ff12cc1e200|0x7fff6976a640|abcd::test2|/root/deliverer-main/deliverer/extension/test.php|52
1630335728072779|0x7ff12cc1e270|0x7ff12cc1e200|abcd::test3|/root/deliverer-main/deliverer/extension/test.php|43

可以看到abcd::test两次通过call_user_func,是没问题的,是一个 callback 的方式,有独立的入栈出栈,但是因为__get是系统方法,没有在日志里记录,所以abc::test2abcd::test2都找不到
0x7fff6976a060父节点。

本来计划是单独监控魔术方法的,但是想了下,单线程模型下,我直接根据时间戳来就行了,直接挂在前一时刻的函数下就行了。

https://github.com/zhoumengkang/deliverer/releases/tag/1.1.2