PHP 性能优化：记一次服务器性能排查

背景：公司最近在 APP 上推广一系列活动。其中有两个活动：签到 + 红包雨。红包雨属于整点抢。用户参与红包雨活动前后会参与签到活动。这样就造成每天 10 点 Web 服务器压力很大。突然，有一天服务器 TCP 连接数直接飙升超过了 PHP-FPM 能响应的数量。导致 APP 响应异常缓慢。于是就有了本文排查性能的记实。

思路一：查看请求数量

我的第一反应是查看整点时的 API 请求数量。通过日志统计，请求数量很大，但是在服务器承受范围内。换句话说，服务器处理这些请求绰绰有余。因为，我们有 9 台服务器。每台服务器配置如下：

CPU：16核。
内存：16 GB
硬盘：SSD。
PHP-FPM 进程数：400

均衡负载采用的是阿里云的 SLB。

数据库采用了阿里云的 RDS 高配版。查看其负载也属于低消状态。

根据理论值，我们 9 台服务器最少能承受的请求数量等于：9 * 400 = 3200。

当然要达到这个并发数量级别，有可能数据库会出现性能问题。

思路二：查看 MySQL 慢查询日志

通过对 MySQL 慢查询日志进行分析，几乎没有出现。或者说，出现的 MySQL 慢查询日志跟平常的差不多。都属于一些管理后台复杂查询类别的慢查询。

如思路一中所说：MySQL 服务器负载很小。所以，排除了 MySQL 服务器的问题。

思路三：查看 PHP-FPM 慢请求

对 PHP-FPM 熟悉的同学，都应该知道在 PHP-FPM 配置文件当中有如下两个配置：

request_slowlog_timeout = 1
slowlog = log/slow.log

request_slowlog_timeout 的作用是告诉 PHP-FPM，凡是请到开始到响应结束之间消耗的时间超过 1 秒就认为慢请求。就将造成慢请求的日志记录在 slowlog 指定的文件当中。

结果，通过这个日志我们发现了大量的慢请求。慢请求的关键日志如下:

[27-Nov-2018 14:50:48]  [pool www] pid 19708
script_filename = xxxxxxx/public/index.php
[0x00007fb12cc48688] file_put_contents() xxxxxxx/library/winer/Log.php:98
[0x00007fb12cc48138] store() xxxxxxx/apps/controllers/Index.php:54
[0x00007fff0b8f8780] indexAction() unknown:0
[0x00007fb12cc47998] run() xxxxxxx/public/index.php:13

上面的信息我隐去了与环境相关的路径前缀。通过慢请求日志可以看出，我们在调用 file_put_contents 位置造成了慢请求的产生。这个位置是我们写日志造成的。

奇怪的是。我们写日志使用了阿里云的云盘。根据购买云盘的配置为 5000 IOPS/s。也不会出现瓶颈。于是，我查看了我们这个位置的 PHP 代码。

file_put_contents($logPath, $logCtx, FILE_APPEND|LOCK_EX);

可以看到，我们加了一个 LOCK_EX 参数。就是说写入日志的时候排它性，独占写锁。之所以当初要增加这个，是因为并发写的时候会造成日志位置错乱，两次日志信息互相包含。导致不能按照完整的顺序写入。

于是，我暂时把这个参数去掉之后，发现服务器 TCP 连接数瞬间下降到合理水平。基本可以确定是这里的问题了。于是，我把写日志更改为了异步。在异步里面进行独占写。

以上就是我排查本次问题的思路步骤。谢谢！