数据库查询慢-排查问题总结

Posted 2020-11-23 liboware

最近的一次上线突然发现系统的某些数据库查询偶尔会超过300ms, 正常的情况都只有100ms，我花了一段时间开始调查原因，这篇文章记录了整个过程。

项目背景

项目提供了一个支持水平扩展的功能，扩展是基于扩展多数据库来分散压力，我就是在这个大场景下要求新增一些数据库来环境线上的压力。

• 线上分为南方和北方两个大机房，80%的流量都在北方机房
• 线上流量是写多读少，写大概是读的10倍量左右
• 本次修改是为了解决北方机房的压力
• 数据库是读写分离的，一个写库，多个从库负责读取

　　 那么我做了什么修改呢？新申请了10个写库，30个读库，把读写库的配置更新到线上，将1%的流量导入到新库中观察一下是否有问题，没问题的话就全量上。

系统报警了？

       1%流量刚切完, 正当我觉得一切都很简单，突然发现报表里这部分流量的读取耗时有些异常，经常大于300ms。我本以为是网络问题，但是发现同机房的其他的数据库完全没有问题，不得不说我当时有点慌，赶紧检查一下读库的配置是否配错地方了。。。

       费了九牛二虎之力，配置貌似没有什么问题，我又在本地用线上的配置跑了一把，也就是本地直接连线上的数据库跑(别喷，我知道这样不好)，加入了计算时间的日志，运行了一下查询和插入，耗时没有任何异常，都是几毫秒。关键这个时候，原来的流量都挺正常的，就我切走的1%流量有问题，这个时候短信和邮件报警齐刷刷的来了，崩溃！！！！

仔细观察现象

以我多年的经验(其实也没有几年哈哈哈)，这个时候一定要淡定，反正只有1%的流量，只是查询慢一点而已，并不是功能不能用，所以我可以仔细的调查一下。那这个时候我们能用到的工具有什么呢？无非就是线上的报表，机器上的日志。因此我们只能从这2个方面寻找突破口了：

报表

我打开查询耗时的报表，我发现查询的耗时并不是一直都大于300ms，有点像毛刺，一段时间一个，而且并不是所有的库都同一个时刻查询慢，完全随机，但是我注意到对于同一台数据库而言，它的查询慢间隔几乎是一分钟左右一次，聪明的小伙伴可能已经猜到是什么原因了，我比较菜，当时没有立刻反应过来，所以后面还做了很多工作，接着看。

日志

看完报表后，还是没有什么思路，因此我只能登陆到线上的机器上看日志了，我们有专门记录性能的日志，它是一分钟刷新一次，打开后惊讶的发现里面每分钟都会有大量的连接数据库的记录，而翻看上线前几天的日志则没有那么多的连接记录，纳尼？我们不是用数据库连接池的吗？我也没改过连接池的代码呀！！正当我困惑的时候，一个词闪现在我脑海里，连接池！！！

罪魁祸首

还好我之前有看过数据库连接池的配置，我记得有一个idle_time的配置，作用是如果一个数据库连接在idle_time时间内没有被使用则会被关闭，有了这个思路后，我就在框架代码里招有关这个配置的地方，果然被我找到，如果我们不提供这个配置的话，框架自动帮我们配置成1分钟。如果数据库连接真的一分钟都没有人使用的情况下，频繁的建立链接是有可能的！！！此刻感觉我找到了救命稻草一般。那真的1分钟都没有被使用吗？线上的qps还是很高的，不应该啊。突然反应过来现在这40个库只有1%的流量，而且有没有注意到，只是查询变慢了，但是写并没有变慢，为什么？前面介绍过，我们业务的写是读的10倍以上，因此就算1%的流量，写操作也有不少，而且写库只有10个，读库却有30个，这么计算，读库平均被访问的几率是写库的1/30！！！难怪连接一分钟都没使用就关了，下次使用的时候还要重新建立连接，而建立连接是比较耗时的，而对于应用而言，它并不感知建立连接的耗时是多少，对它而言，建立连接+查询时间就是它的查询时间，这也能解释为什么查询慢是毛刺，而不是一直有，因为建立好了就正常了，如果哪个时候又闲了，就会毛刺一下。

解决办法

解决办法很简单，我们在代码里手动配置idle_time到10分钟，上线！果然毛刺马上没有了，一切正常，谢天谢地！