冯老师的困惑 —— PHP 挂了

认识冯老师五年以来,终于看到他露了一手,仅凭一战足以封神。此役过后,我愿尊称他为 master

PHP5 挂了

本来今天晚上计划迁移服务器的,目标服务器已经通过阿里云共享镜像创建。按道理说,环境都是一模一样的,可是当我准备测试代码的时候,发现目标服务器上 PHP7 的项目运行正常,PHP5 的项目却一直转圈圈。这还真是奇了怪了。

于是,我便开始一步步定位。

跟踪定位

外部看到的情况是:请求半天以后,报了一个 504 错误 —— 「请求超时」。

遇到这种情况,首先想到的是分析 nginx 错误日志,可通过查看 nginx 错误日志后,并没有什么发现。于是,只能考虑别的方法。

会不会是项目里配置的地址有白名单之类的没有添加,导致的超时呢?

于是,我在项目入口处打了个断点,想看下请求有没有走到项目中来。可是当我打完以后,发现依然会请求超时,这说明请求并没有走到项目中。

请求没有走到项目中,但查看 nginx 访问日志,请求已经接收到了。那只能是在 php-fpm 处理请求这一块儿出问题了。于是,我想看看php-fpm的错误日志或者慢日志。

我打算先使用php --ini命令查看下配置相关的一些内容。可是当我在控制台输入命令以后,发现控制台也卡住了,等了大概 5 分钟以后,界面上提示了一个Segment fault错误,翻译过来就是程序段错误的意思。

我尝试运行其他 PHP 命令,发现php -m也不能正常运行,php -vphp -h这些命令是可以的。

呃……看来,这就不只是php-fpm的问题了,连cli模式也有问题,说明是 PHP 程序出了问题。

那该怎么定位呢?

我首先想到了strace命令。

strace 命令

strace命令主要用来跟踪进程相关的系统调用信息,包括参数、返回值和调用时间等信息。

常用的方法如下:

strace -p 进程ID

我在一个窗口执行了php -m命令,然后又开了一个窗口,使用ps命令查看刚才命令的进程ID,然后使用strace命令进行跟踪,跟踪到的结果如下:

Process 19351 attached
restart_syscall(<... resuming interrupted call ...>) = 1
getsockopt(4, SOL_SOCKET, SO_ERROR, [110], [4]) = 0
fcntl(4, F_SETFL, O_RDWR)               = 0
gettimeofday({1714132764, 671300}, NULL) = 0
close(4)                                = 0
gettimeofday({1714132764, 671620}, NULL) = 0
--- SIGSEGV {si_signo=SIGSEGV, si_code=SEGV_MAPERR, si_addr=0} ---
+++ killed by SIGSEGV +++

看到跟踪出来的结果,我并没有眼前一亮。因为还是没有看出具体是什么原因导致的。

正在我愁眉不展的时候,冯老师从我身边走过,问我是否需要帮助。

我本来想再挣扎一下的,但排查这个问题已经用去了几个小时的时间。如果还是没有进展的话,那定于晚上十点的迁移计划肯定要推迟。事不宜迟,于是,我向冯老师诚恳地发出了「求救信号」。

冯老师也没有吝啬,爽快地答应了我的请求,当然条件是一顿猪头肉。

strace 命令的新玩法

我本来只是抱着「试一试」的想法求教冯老师的,因为之前向他求教问题时,他总是东一榔头,西一棒槌地讲一堆大道理,然后画一个望不着边际的圈:「问题就是这么个问题,按我说的去查吧!」

最后我还是一脸懵逼,只能自己来。

这次冯老师并没有像往常一样,问题还没看完就有了结论。他很认真地排查着。


「你可以用 strace 命令跟踪一下。」

「用了,没看出问题来。」


我把跟踪的结果发给冯老师,冯老师仔细地看着。

五分钟过去了。


「你来看一下,这里有个 Redis 调用,卡住了。」

「Redis ?」


我一脸疑惑地来到冯老师电脑前,他指着屏幕上输出的日志给我看:

socket(AF_INET, SOCK_STREAM, IPPROTO_IP) = 4
fcntl(4, F_GETFL)                       = 0x2 (flags O_RDWR)
fcntl(4, F_SETFL, O_RDWR|O_NONBLOCK)    = 0
connect(4, {sa_family=AF_INET, sin_port=htons(6379), sin_addr=inet_addr("172.17.×××.×××")}, 16) = -1 EINPROGRESS (Operation now in progress)
poll([{fd=4, events=POLLIN|POLLOUT|POLLERR|POLLHUP}], 1, 86400000) = 1 ([{fd=4, revents=POLLIN|POLLOUT|POLLERR|POLLHUP}])
......

我看冯老师的日志中确实有 Redis 连接的「痕迹」。端口是 6379 ,大概率是 Redis 的问题。


「php -m 怎么会触发连接 Redis 呢?我的 strace 命令怎么没有跟踪到呢,你是怎么跟踪到的?」

「用 strace php -m。你是不是用 strace 跟踪的进程号?」

「是的。」

「你用 strace 跟踪进程的时候,可能连接 redis 的操作已经执行了,所以在控制台界面没有打印出来。」


听到这里,我若有所思。

php -m怎么会触发连接 redis 的操作呢?我怎么想也想不明白,但是strace跟踪到的的确如此。

Session !!!


「你来看,找到在哪里用的了。」


冯老师像发现新大陆一样,摆手让我过去看。

我来到他屏幕前,看到了在php.ini文件中有一行配置了 Redis 地址。配置的名称是session.save_path。我恍然大悟,瞬间明白是怎么回事了。

session 可以设置存储机制为 redis。当设置了 Redis 的时候,存储路径自然要设置 Redis 地址了。

原来如此。

我谢过冯老师,并在记账簿上记下:「欠冯老师猪头肉一顿」。冯老师嘴角微微上扬,洋溢着得意的笑容。

后续工作

虽然问题解决了,但是有些疑点仍然值得进一步探究。

  1. strace 命令的高级用法整理。
  2. PHP 脚本底层执行过程研究(比如php -vphp -m执行过程的区别)。

关于这些疑点,我会单独整理成文章。感谢大家的持续关注~

本作品采用《CC 协议》,转载必须注明作者和本文链接
你应该了解真相,真相会让你自由。
本帖由系统于 1周前 自动加精
《L05 电商实战》
从零开发一个电商项目,功能包括电商后台、商品 & SKU 管理、购物车、订单管理、支付宝支付、微信支付、订单退款流程、优惠券等
《G01 Go 实战入门》
从零开始带你一步步开发一个 Go 博客项目,让你在最短的时间内学会使用 Go 进行编码。项目结构很大程度上参考了 Laravel。
讨论数量: 4

看到楼主的文章后,又去温习了CLI的生命周期,在模块初始化阶段:

  1. 启动 PHP 输出、初始化垃圾收集器
  2. 启动 Zend 引擎,注册 Zend 核心扩展、Zend 标准常量
  3. 解析 php.ini,映射 php.ini 相关配置
  4. 注册静态、动态编译的扩展
  5. 回调各扩展定义的 module startup 钩子函数。

加载php.ini在注册扩展之前,难怪php -m会报错,感谢楼主分享。:tada::tada::tada:

1周前 评论
快乐的皮拉夫 (楼主) 1周前
梦想星辰大海

strace是神器,我遇到过接口卡慢的情况,怀疑是mysql,但是我们没有nginx日志、mysql日志,各种日志都没有,真是头皮发麻,只好用strace分析进程调用,最后分析下来,不是mysql慢,是redis有个key的值太大了,导致接口卡慢。当时用的脚本如下:

<?php

/**
 * mysql慢查询分析脚本
 * 使用方式:
 * 1. 先收集目标进程的系统调用:rm -fr ./strace.log && strace -o ./strace.log -T -yy -C -tt -xx -s 16384 -w -e sendto,poll -p pid
 * 2. 再用这个脚本对收集的日志进行分析,找到其中系统调用过慢的日志
 * 3. 如果是针对mysql的poll系统调用,则说明sql语句发送给mysql,但是mysql响应太慢,php在等待,此时可以往上找sendto的系统调用,将其入参打印出来,得到真正的sql。
 */

if (count($argv) != 3) {
    die(help());
}
$timeLimit = $argv[1];
if (!is_numeric($timeLimit)) {
    die(help());
}
$timeLimit = intval($timeLimit);

$file = $argv[2];
if (!is_file($file)) {
    die(help());
}

$fileFd = fopen($file, "r");
if (!$fileFd) {
    echo "can not open file: $file", PHP_EOL;
}
$lineIndex = 0;
while (($line = fgets($fileFd)) !== false) {
    // 每次读取一行内容进行处理
    $lineIndex++;
    preg_match('/<[0-9.]+>$/', $line, $matches);
    if (empty($matches)) {
        continue;
    }
    $timeConsuming = floatval(trim($matches[0], '<>')) * 1000;
    if ($timeConsuming >= $timeLimit) {
        echo 'line: ', $lineIndex, ' text: ', $line;
    }
}
fclose($fileFd);

function help(): string
{
    return 'usage examples: php slow.php 200 ./strace.log' . PHP_EOL;
}
1周前 评论
快乐的皮拉夫 (楼主) 1周前

讨论应以学习和精进为目的。请勿发布不友善或者负能量的内容,与人为善,比聪明更重要!