线上长达四十分钟的服务不可用,看我如何解决~

昨天是个汗流浃背的周一,我们的后端服务竟然在一天内三次不可用,最长的一次达到了四十分钟,到底发生了什么,且听我细说。

在每周例行的需求评审会后,我就开始对我的需求进行排期,规划这周要做的工作,当我开始着手规划时,突然发现线上服务有几个没人发现的后端小 bug,于是我开始了悄无声息的改 bug。正当我改的上头时,小 y 突然喊我,cq!线上怎么访问不了了,我猛然一惊,我擦,不会是那几个小 bug 给线上干崩了吧,但是转念一想应该也不是,我赶紧放下手上的工作,开始排查线上服务。

第一次排查

定位问题

1、登录网站,确认问题

我赶紧先登录我们的网站,发现确实访问不了,而且前端的资源响应很快

image-20240722230347032

而后端一直在 pending,如图:

image-20240722230708906

2、登录微信云托管,查看后端服务状态

由于我们的后端部署在微信云托管,于是我下意识的先去微信云托管看下服务的状态,发现我们服务的平均响应竟然达到了 21 秒!

image-20240722225903323

然后我合理推测肯定是 qps 猛增,结果发现,qps 很稳定,再看看内存、CPU 占用都还算平滑

image-20240722232056718

image-20240722232112651

3、登录阿里云接口监控平台定位具体问题

此时我已经发觉事情不太对,既然 qps、内存、CPU 都还算正常,那怎么接口响应这么慢,不过我们后端服务接入了阿里云的应用实时监控服务(ARMS),我赶紧进入控制台查看详细的数据,一进去就发现平均每分钟的响应时间达到了 16.2s

image-20240722231620003

此时我的心理:

但是很快我镇定下来,我要一点点排查到问题所在,正好这个接口监控平台提供了这些监控,我就一个一个点进去看都有啥问题。

image-20240722233448302

4、查看 jvm 监控

于是我赶紧打开 jvm 监控定位下问题,我直呼好家伙,怎么每隔五分钟 FullGC 一次?因为每次 FullGC 都会暂停应用程序的执行,这么频繁的 FullGC 显然是有问题的,怪不得线上接口一直无法访问。

image-20240722232602094

5、查看线程池监控

但是光看 jvm 监控也定位不到问题,我需要赶紧找到 FullGC 的根本原因,于是我点开了线程池监控,好家伙,这 TM 所有的线程全都上场了,甚至还有一堆在排队的。。。

image-20240722233033081

这是我更不能能理解了,到底是什么阻塞了所有的线程?

6、 查看连接池监控

带着疑问,我又打开了连接池监控,好家伙,什么鬼?为什么连接池满了?

image-20240722233546399

解决问题(bushi)

看到连接池全部爆满,我就知道肯定是连接池满了,导致在查数据库,所有的请求都在等待连接池空闲,也就导致线程全部阻塞,最终导致频繁 FullGC,但是也不合理,因为所有的数据库请求按理来说都会自动释放掉链接呀,为什么连接池会满呢?但是这时候线上事故已经发生很久了,我得先让用户能访问网站再说,要不然用户还不得骂死我,我赶紧在 SpringBoot 的 application.yml 中配置连接池的最大容量为 20,如下:

spring:
    hikari:
      maximum-pool-size: 20

发布到线上,很快线上就可以正常访问了,速度很丝滑~

第二次排查

我本来也以为事情告一段落,可以继续修我的 bug 了,顺便我还跟同时吐槽了一波,hikaricp 就是不好用,回头要是有机会一定得给给换成 druid,还能监控 sql、防 sql 注入之类的。。。刚吐槽着,小 y 又高呼:cq、cq,线上又卡住了,又不行了,快去看看。我心里一沉,好家伙,不给我喘息的机会是吧,我赶紧去看看连接池监控:

image-20240722235310833

怎么回事?20 个链接都不够用?这不对吧?到底是谁一直占着链接不放手!于是我赶紧进入微信云托管的 webshell,使用 jstack 看看是哪个线程卡死了,发现都是 TIMED_WAITING,好吧,并不能代表什么,和我第一次排查问题时查看的线程池监控的结果一致。

image-20240722235751586

暂时没有找到根本原因,但为了线上能继续访问,我只能先把这些问题抛之脑后,重新发布一版,把连接池清空掉重新来。

第三次排查

这次我老实了,感觉这不是我能处理得了的 bug,赶紧请上我们公司的大佬 yes 哥,我把情况大概给 yes 说明了一下:我们线上的连接池总是被很快的耗尽,但是排查不到是哪个地方占用了链接不释放,yes 立马就反应过来,慢 sql 你排查了吗?我一惊,好像没排查。。。

image-20240723000842236

定位问题

这次,我直接查看慢 sql,果然有个慢 sql 执行了七千多次,而且平均时间居然达到了 1.4 秒,这连接池根本没有闲着的时候啊。

image-20240723001131616

分析问题

再仔细看下这个 sql,发现 scene 这个字段没有加索引,也就是说每次这个请求都会走一遍全表扫描,然后我看了下这个 sql 执行的场景,是在微信公众号扫码登录时,前端轮询用户是否已经扫码并关注公众号,如果扫码关注了公众号则登录成功。大致的流程如下:

  1. 用户点击登录按钮。
  2. 前端向后端发起登录请求。
  3. 后端生成一个登录二维码和一个场景码(scene),并将其响应给前端。
  4. 前端显示二维码,并携带场景码发起请求,轮询后端是否登录成功的接口。
  5. 用户使用微信扫描二维码,关注微信公众号。
  6. 微信服务器向后端发送携带场景码的请求。
  7. 后端根据 unionId 找到对应的用户,或者根据微信携带的用户信息和 unionId 新增一个用户,并将场景码与用户信息关联。
  8. 后端更新数据库的场景码,记录扫码成功,并更新场景码对应的用户信息。
  9. 后端轮询接口检测到场景码对应的用户信息已经更新,返回登录成功的状态给前端。
  10. 前端显示登录成功页面。
    在这里插入图片描述

那么很显然,我们的问题就出在后端根据场景码轮询用户信息这里,这里有个慢 sql,因为我们的 scene 没有设置索引,因此导致每次查询用户是否扫码登录时都要进行全表扫描,用 explain 看下这个 sql:

image-20240723003632475

解决问题

但是当时我比较犹豫,因为加上这个字段后,大概率只会命中一次,只要有一次查到了,这个 scene 就无效了,所以我总感觉这个索引加了会浪费性能,我跟 yes 哥表达了我自己的想法,但是 yes 哥的想法是,就算他只有一次生效,至少不会在轮询的时候一直扫全表,毕竟这个 sql 是前端轮询的产物,我想了想有道理,这时候,我们老板出来了,怎么回事,你们在讨论什么?!线上服务不可用都已经四十多分钟了,还不先把服务恢复了再讨论详细解决方案,于是我赶紧按照 yes 哥的方案,把这个索引加上了,让我没想到的是,效果立竿见影,线上一下就可用了,看下连接池的变化:

image-20240723004603079

此时我长舒了一口气,终于算是搞定了,这时候我再 explain一下,发现这时候已经是走索引了:

image-20240723003718055

好吧,我为我的无知向 hikaricp 道歉,不是你的锅,是我的锅~

后来我又查了下阿里巴巴的 Java 开发手册,发现这本手册第五章中的第(二)节里明确写了创建索引时要避免的误解,如下图:

image-20240723004322410

我就是因为第二点认为索引不应该随便创建,因为可能会导致拖慢记录的更新之类的,后来想了下,其实 user 表的更新并不频繁,包括这个 scene 的更新也不频繁,因为用户在正常使用过程中又有几次会重新触发登录呢?

最后

好了,汗流浃背的周一就这么度过了,算是长了个记性,赶紧把所有的慢 sql 都看一下,能加索引加加索引,不能加索引的,看看能不能换个实现方式。以后排查问题又多了个思路,线上的连接池用完了要先排查下有没有慢 sql 导致链接一直没被释放,再往下排查。

最后,希望普天下的程序员写代码都不遇 bug。

评论 1
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包

打赏作者

bug-cq2020

你的鼓励将是我创作的最大动力

¥1 ¥2 ¥4 ¥6 ¥10 ¥20
扫码支付:¥1
获取中
扫码支付

您的余额不足,请更换扫码支付或充值

打赏作者

实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值