一个 Bug 改了三次，汗流浃背了。。

大家好，我是程序员鱼皮。还记得么？几天前我写了一篇文章 《一下午连续故障两次，谁把我们接口堵死了？！》 ，我从团队管理的视角给大家分享了我们的编程导航网站线上故障的经历和解决方案。

虽然这次的故障解决的效率不高，但还是得表扬下我团队的开发同学，认真写了一篇完整的复盘文章。今天，咱们就换一个视角，来看看亲身经历和解决故障的开发同学，他的心路历程是怎样的？

四个字总结：汗流浃背 ！

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

在每周例行的需求评审会后，我就开始对我的需求进行排期，规划这周要做的工作，当我开始着手规划时，突然发现线上服务有几个没人发现的后端小 bug，于是我开始了悄无声息的改 bug。正当我改的上头时，同事小 y 突然喊我：线上怎么访问不了了！

我猛然一惊，我擦，不会是那几个小 bug 给线上干崩了吧？但是转念一想应该也不是，我赶紧放下手上的工作，开始排查线上服务。

第一次排查

定位问题

1、登录网站，确认问题

我赶紧先登录我们的网站，发现确实访问不了。打开网络控制台发现前端的资源响应很快：

而后端却一直在 pending，如图：

2、登录容器平台，查看后端服务状态

由于我们的后端部署在云托管容器平台，于是我下意识的先去平台查看服务的状态，发现我们服务的平均响应竟然达到了 21 秒！

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

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

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

此时我的心理：

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

4、查看 jvm 监控

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

5、查看线程池监控

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

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

6、 查看数据库连接池监控

带着疑问，我又打开了数据库连接池监控，好家伙，什么鬼？为什么连接池满了？

解决问题（bushi）

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

spring:
  hikari:
    maximum-pool-size: 20

然后发布到线上，很快线上就可以正常访问了，使用很丝滑～

第二次排查

我本来也以为事情告一段落，可以继续修我的 bug 了，顺便我还跟同时吐槽了一波，hikaricp 就是不好用，回头要是有机会一定得换成 druid，还能监控 sql、防 sql 注入之类的。。。刚吐槽着，同事小 y 又高呼：线上又卡住了，又不行了，快去看看！

我心里一沉，好家伙，不给我喘息的机会是吧，我赶紧去看看数据库连接池监控：

怎么回事？20 个连接都不够用？这不对吧？到底是谁一直占着连接不放手！于是我赶紧进入容器平台的 webshell，使用 jstack 看看是哪个线程卡死了，发现都是 TIMED_WAITING，好吧，并不能代表什么，和我第一次排查问题时查看的线程池监控的结果一致。

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

第三次排查

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

定位问题

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

分析问题

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

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

解决问题

但是当时我比较犹豫，因为加上这个字段后，大概率只会命中一次，只要有一次查到了，这个 scene 就无效了，所以我总感觉这个索引加了会浪费性能。我跟 yes 哥表达了我自己的想法，但是 yes 哥的想法是，就算他只有一次生效，至少不会在轮询的时候一直扫全表，毕竟这个 sql 是前端轮询的产物。

我想了想有道理，这时候，我们老板出来了（也就是鱼皮）：怎么回事，你们在讨论什么？！线上服务不可用都已经四十多分钟了，还不先把服务恢复了再讨论详细解决方案？

于是我赶紧按照 yes 哥的方案，把这个索引加上了，让我没想到的是，效果立竿见影，线上一下就可用了，看下连接池的变化：

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

好吧，我为我的无知向 hikaricp 道歉，不是你的锅，是我的锅～

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

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

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

鱼皮总结

通过这次事故，暴露了我们开发同学经验的不足。

1. 遇到服务卡死问题时，赶紧先扩个容新增一台可用实例，然后再对着原有故障实例的现场进行排查。
2. 时间紧迫的情况下加大数据库连接数没问题，但是才加了 10，显然是有点太保守了，我们的数据库还是扛得住的。
3. 应该能够预料到问题并没有根本解决，并且赶紧继续观察和排查，怎么就开始做别的了呢？
4. 排查定位问题的效率不高，像 “如何定位线程池爆满问题” 这种八股文知识还是要背背的。

而且我在 上一篇文章 中也提到了，导致本次故障的慢 SQL 我们早就发现并且发到群里了，结果团队几个开发竟然没一个人去处理。。。

当然，最遗憾的是，这篇写出来的事故复盘仍然是残缺的！

现在的这个解决方案并不完整，在我看来还是 临时 解决了这个问题。信不信，并发量再大点，系统的某个地方还会出现类似的问题？难道到时候再汗流浃背一次？俗话说事不过三，这次的损失我们忽略不计，下一次可就不一定了。

既然我们用了可以根据资源利用率自动扩容的容器平台，那么当并发量增大、单个节点处理不过来时，就应该自动扩容，自然能够应对更大的并发请求。通过本次事故，我们发现请求连接数满的时候，节点的 CPU 利用率才不到 20%、内存才不到 60%，根本达不到扩容的阈值。所以应该适度增大数据库连接池数量、增大服务器请求处理线程的数量，提高系统资源利用率，并且通过压力测试来验证能否触发自动扩容。或者调整容器的扩容策略，也是一种方案。

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

      

       

        


        
点击关注公众号，阅读更多精彩内容