记一次PHP并发性能调优实战 -- 性能提升104%

文章编写计划

待完成: 详细介绍用到的各个工具

作者: 万千钧(祝星)

适合阅读人群

文中的调优思路无论是php, java, 还是其他任何语言都是用. 如果你有php使用经验, 那肯定就更好了

业务背景

框架及相应环境

  1. laravel5.7, mysql5.7, redis5, nginx1.15
  2. centos 7.5 bbr
  3. docker, docker-compose
  4. 阿里云 4C和8G

问题背景

php已经开启opcache, laravel也运行了optimize命令进行优化, composer也进行过dump-autoload命令.

首先需要声明的是, 系统的环境中是一定有小问题的(没有问题也不可能能够提升如此大的性能), 但是这些问题, 如果不通过使用合适的工具, 可能一辈子也发现不出来.

本文关注的就是如何发现这些问题, 以及发现问题的思路.

我们首先找到系统中一个合适的API或函数, 用来放大问题.

这个api设计之初是给nginx负载均衡做健康检查的. 使用ab -n 100000 -c 1000 进行压测, 发现qps只能到140个每秒.

我们知道Laravel的性能是出了名的不好, 但是也不至于到这个程度, 从api的编写来看不应该这么低. 所以决定一探究竟.

 public function getActivateStatus()
    {
        try {
            $result = \DB::select('select 1');
            $key = 1;
            if ($result[0]->$key !== 1) {
                throw new \Exception("mysql 检查失败");
            }
        } catch (\Exception $exception) {
            \Log::critical("数据库连接失败: {$exception->getMessage()}", $exception->getTrace());
            return \response(null, 500);
        }
        try {
            Cache::getRedis()->connection()->exists("1");
        } catch (\Exception $exception) {
            \Log::critical("缓存连接失败: {$exception->getMessage()}", $exception->getTrace());
            return \response(null, 500);
        }
        return \response(null, 204);
    }

问题表现以及排查思路

top

top命令发现系统CPU占用100% 其中用户态占80%, 内核态占20%, 看起来没什么大问题. 有一个地方看起来很奇怪, top命令的运行结果

top命令运行结果

<figcaption style="box-sizing: border-box; display: block; text-align: center; font-size: 0.8em; line-height: 2em; color: rgb(144, 144, 144);"></figcaption>

就是有一部分php-fpm进程处在Sleep状态, 但CPU占用还是达到了近30%. 当一个进程处于Sleep状态的时候, 任然占用了不少CPU, 先不要怀疑是不是进程的问题, 我们看一下Ttop命令的man page.

%CPU -- CPU usage

The task's share of the elapsed CPU time since the last screen update, expressed as a percentage of total CPU time.

大致意思是这个占用是最后一次屏幕刷新的时候, 进程CPU的占用. 由于top命令收集信息的时候, 可能linux把这个进程强制调度了 ( 比如用于top收集进程信息 ), 所以在这一瞬间(屏幕刷新的这一瞬间)某些php-fpm进程处于sleep状态, 可以理解, 所以应该不是php-fpm的问题.

pidstat

首先选出一个php-fpm进程, 然后使用pidstat查看进程详细的运行情况

image

<figcaption style="box-sizing: border-box; display: block; text-align: center; font-size: 0.8em; line-height: 2em; color: rgb(144, 144, 144);"></figcaption>

过程中也没发现什么异样, 并且和top命令的运行结果也基本一致.

vmstat

保持压测压力, 运行vmstate查看, 除了context switch (上下文切换)有点高之外, 并没有看到太多异常. 由于我们使用的docker, redis, mysql都运行在同一台机器上, 7000左右的CS还是一个合理的范围, 但是这个IN(中断)就有点太高了, 达到了1.4万左右. 一定有什么东西触发了中断.

image

<figcaption style="box-sizing: border-box; display: block; text-align: center; font-size: 0.8em; line-height: 2em; color: rgb(144, 144, 144);"></figcaption>

我们知道中断有硬中断和软中断, 硬中断是由网卡, 鼠标等硬件发出中断信号, cpu马上停下在做的事情, 处理中断信号. 软中断是由操作系统发出的, 常用于进程的强制调度.

不管是vmstat还是pidstat都只是新能探测工具, 我们无法看到具体的中断是由谁发出的. 我们通过/proc/interrupts 这个只读文件中读取系统的中断信息, 获取到底是什么导致的中断升高. 通过watch -d命令, 判断变化最频繁的中断.

watch -d cat /proc/interrupts

image

<figcaption style="box-sizing: border-box; display: block; text-align: center; font-size: 0.8em; line-height: 2em; color: rgb(144, 144, 144);"></figcaption>

我们发现其中Rescheduling interrupts变化的最快, 这个是重调度中断(RES),这个中断类型表示,唤醒空闲状态的CPU 来调度新的任务运行。这是多处理器系统(SMP)中,调度器用来分散任务到不同 CPU的机制,通常也被称为处理器间中断(Inter-Processor Interrupts,IPI)。 结合vmstat中的命令, 我们可以确定造成qps不高的原因之一是过多的进程争抢CPU导致的, 我们现在还不能确定具体是什么, 所以还需要进一步的排查.

strace

strace可以查看系统调用, 我们知道, 当使用系统调用的时候, 系统陷入内核态, 这个过程是会产生软中断的, 通过查看php-fpm的系统调用, 验证我们的猜想

image

<figcaption style="box-sizing: border-box; display: block; text-align: center; font-size: 0.8em; line-height: 2em; color: rgb(144, 144, 144);"></figcaption>

果然, 发现大量的stat系统调用, 我们猜想, 是opcache在检查文件是否过期导致的. 我们通过修改opcache的配置, 让opcache更少的检查文件timestamp, 减少这种系统调用

    opcache.validate_timestamps="60"
    opcache.revalidate_freq="0"

再次执行ab命令进行压测

image

<figcaption style="box-sizing: border-box; display: block; text-align: center; font-size: 0.8em; line-height: 2em; color: rgb(144, 144, 144);"></figcaption>

果然qps直接涨到了205, 提升非常明显, 有接近 46% 的提升

perf

现在任然不满足这个性能, 希望在更多地方找到突破口. 通过

perf record -g
perf report -g

看到系统的分析报告

image

<figcaption style="box-sizing: border-box; display: block; text-align: center; font-size: 0.8em; line-height: 2em; color: rgb(144, 144, 144);"></figcaption>

我们看到, 好像这里面有太多tcp建立相关的系统调用(具体是不是我还不清楚, 请大神指正, 但是看到send, ip, tcp啥的我就怀疑可能是tcp/ip相关的问题). 我们怀疑两种情况

  1. 与mysql, redis重复大量的建立TCP连接, 消耗资源
  2. 大量请求带来的tcp连接

先说第一个, 经过检查, 发现数据库连接使用了php-fpm的连接池, 但是redis连接没有, redis用的predis, 这个是一个纯PHP实现, 性能不高, 换成了phpredis:

打开laravel的config/database.php文件, 修改redis的driver为phpredis, 确保本机已安装php的redis扩展. 另外由于Laravel自己封装了一个Redis门面, 而恰好redis扩展带来的对象名也叫Redis. 所以需要修改Laravel的Redis门面为其他名字, 如RedisL5.

再次进行压测

image

<figcaption style="box-sizing: border-box; display: block; text-align: center; font-size: 0.8em; line-height: 2em; color: rgb(144, 144, 144);"></figcaption>

达到了喜人的286qps, 虽然和其他主打高性能的框架或者原生php比, 还有很高的提升空间(比如Swoole), 但是最终达到了104%的提升, 还是很有意义的

总结

我们通过top, 发现系统CPU占用高, 且发现确实是php-fpm进程占用了CPU资源, 判断系统瓶颈来自于PHP.

接着我们通过pidstat, vmstat发现压测过程中, 出现了大量的系统中断, 并通过 watch -d cat /proc/interrupts 发现主要的中断来自于重调度中断(RES)

通过strace查看具体的系统调用, 发现大量的系统调用来自于stat, 猜测可能是opcache频繁的检查时间戳, 判断文件修改. 通过修改配置项, 达到了46%的性能提升

最后再通过perf, 查看函数调用栈, 分析得到, 可能是大量的与redis的TCP连接带来不必要的资源消耗. 通过安装redis扩展, 以及使用phpredis来驱动Laravel的redis缓存, 提升性能, 达到了又一次近50%的性能提升.

最终我们完成了我们的性能提升104%的目标

©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 213,752评论 6 493
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 91,100评论 3 387
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 159,244评论 0 349
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 57,099评论 1 286
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 66,210评论 6 385
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 50,307评论 1 292
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 39,346评论 3 412
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 38,133评论 0 269
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 44,546评论 1 306
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 36,849评论 2 328
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 39,019评论 1 341
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 34,702评论 4 337
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 40,331评论 3 319
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 31,030评论 0 21
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 32,260评论 1 267
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 46,871评论 2 365
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 43,898评论 2 351

推荐阅读更多精彩内容