大年三十前夕用户吐槽活动很卡

大年三十前夕,用户反馈线上活动页面访问很慢,体验较差。

要放假了,但我心里没慌,观察活动页面,加载的确很卡,极其不流畅,但Web资源依稀可load出来。

这个场景太熟悉了,毕竟以前遇到过,心里基本有底,直觉告诉我是DB问题,但还是按自己排查习惯来。

记录下整个排查过程:

Ping

首先ping下域名,延迟正常,没有丢包情况,同时页面能访问,证明webserver也是ok的,nginx解析html这一部至少没问题。

结论:nginx没挂,DNS解析正常。

php-fpm和nignx排查

检查XHR接口,可以看到有接口耗时20s+,这显然是有问题。


xhr

此时,假设是否HTTP接口在处理的时候压力过大,但上线前经过多次压力测试,QPS可以承受2000+,查看此刻接口调用QPS在50以内,很低,远远没达到瓶颈。

检查web机器,cpu总占用率不到20%。php-fpm和nginx资源占用率也非常低,php-fpm进程cpu占用率最大不过1%,证明php-fpm处理能力没有问题,而且我特地使用static模式,拉起足够多的php-fpm进程应对。

结论:php-fpm和nginx、web机器也hold得住

代码排查

既然xhr发现接口有执行过长的问题,在程序中埋点,记录每个分支逻辑的执行时长,打印log分析。这一步比较枯燥,不过有收获,在一次次的试探中,发现每次执行和DB相关的逻辑,时间较长。难道DB会hold不住?但即使hold不住,也该有cache层挡着。

结论:DB可能hold不住

Sql排查

既然怀疑DB,那么选取线上一条执行频率最高的语句check一下:

select * from table where user_id = xxx and other1 = 'xxx' and other2 = 'xxx'

分析该sql语句,有很大问题,如下所示:

explain  select * from table where user_id = xxx and other1 = 'xxx' and other2 = 'xxx'
索引失效的sql

它的执行效率贼差,这条sql查询几秒才出结果,而type居然是个ALL,这是不科学的,user_id、other1、other2都加了复合索引,单表数据弄到几百万也测过,是毫秒内拉取。

由上可知复合索引肯定没有生效,再三定位,终于发现原因,请看如下sql:

explain  select * from table where user_id = 'xxx' and other1 = 'xxx' and other2 = 'xxx'
索引生效的sql

我们可以看见这次的分析,type为const,这就非常优秀了,最多只返回一行数据, const 查询速度非常快, 因为它仅仅读取一次即可。但这两条sql有什么不同呢?!没错!就是一个通过string类型查询,一个是通过int类型查询,整型的时候复合索引是完全没生效的,因为user_id本身是string类型。

于是乎,把代码改了,噼里啪啦发布。一打开网页,瞬间不卡了。

以为事情就此结束?NO,毕竟要过年,没那么简单。

结论:索引没有生效,查询效率低下

DB问题

第二天下午,用户仍然反馈活动很卡,我抽取其中一个接口,获得一个关键信息:页面的nginx报502。

php-fpm没问题,但会不会是连接DB后一直没响应呢,造成php-fpm无法返回,nginx不知道怎么办,都说是自己的错。

这一次,决定去MySql服务器上查查,果然还有问题:

3.jpg

可以看到MySql磁盘IO很高,就是下午3点多的时候。此时看下慢查询,不查则已,一查惊人。在其他业务下,连接同一个DB server,慢查询达到了20秒以上的sql非常多。其中一个日志文件就有12467条慢查询,并且查询时间在几十秒以上的也有几百条,查询效率可想而知。


单日慢查询记录数

解决方法把所有慢查询的sql优化掉,该删删,该改改。

结论:慢查询过多问题暴露。初步怀疑慢查询导致Mysql服务器cpu占用率过高和IO负载过高,造成Mysql没有正常返回给php,php-fpm无法返回结果,因此nginx一直等待,无法响应,报502 Bad Gateway。

Cache排查

前面提到,即使DB被穿透,但穿透前理论上cache能hold住,redis的扛并发能力是耳熟能详的,压测QPS也是过万,应对活动高峰时期在可控范围内。

于是乎又在代码中乏味地调试,一行一行地定位。终于,在夜深人静的晚上,我发现业务逻辑存在一个bug:
数据写入cache后,cache会重置,相当于每次写入cache就丢失,所以高峰期一来,用户数据只要变动,redis未生效就会造成缓存雪崩效应,请求全部穿透缓存抵达DB,而DB刚好因为慢查询处理不过来,造成了网页很卡或者接口502。

结论:cache层被穿透,缓存雪崩


5.jpg

优化后,MySql服务器的cpu使用率在高峰期也大大降低,几乎还有空闲的情况(业务逻辑中DB操作很少),而在7号没有优化前使用率最高达到94,这也难怪活动页面会很卡。

总结
解决方式:
1、优化sql,使得索引生效
2、修复业务bug,保证cache命中率
3、去掉多余的索引,保证写入效率

排查后,通过上面三种方式彻底解决问题,整个春节过得相对舒心。

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

推荐阅读更多精彩内容