是什么形成了数据库的卡顿

目录

• 1、背景
• 2、问题定界
• 3、找出元凶
• 4、解决思路

声明：本文同步发表于 MongoDB 中文社区，传送门：
http://www.mongoing.com/archives/26201

1、背景

MongoDB 提供了很是强大的性能分析及监控的命令，诸如 mongostat、mongotop 可让咱们对数据库的运行态性能了如指掌。
然而，此次咱们在性能环境上就遇到一个很是棘手的问题：

某服务接口在 1-5分钟内偶现超时致使业务失败！

在接口调用上返回超时属于前端的判断，一般是设置的一个阈值(好比 3s)。
因为问题是偶现，且没办法发现有明显的规律，很难直接判断出缘由。
而平台在作了微服务拆分以后，问题定位的难度加大了很多，且当前的调用链功能也不够完善。

2、问题定界

业务诊断

在一番分析后，梳理出接口调用的关系图以下：

其中，服务A 经过 RPC调用服务B的接口，而服务B 又经过 MongoDB 进行数据读写。
MongoManager 是 用于管理 MongoDB 的一个代理服务，主要是实现一些数据备份、监控的任务。

在采集了一些数据以后，咱们基本把问题范围锁定到了 MongoDB 数据库上面，这些手段包括：

• 经过对服务A、服务B的接口监控进行观测
• 经过wiredshark 抓包，分析 DB读写上的响应包时延
• 经过CommandListener，将1s 以上的慢操做指标进行输出

从接口监控及 wiredshark 抓包结果中确认到，DB 操做的响应时间都出现了偶现的超长(3s以上)。
而经过 CommandListener 将慢操做输出统计后，获得的图表以下：

其中典型的慢操做语句如：

update app.BussinessData query: { snId: "c1190522-6b6f-9192-b40a-6665ba2b2tta" } update: { $set: { taskInfo.state: "Running", lastModifiedTime: new Date(1531857361579) } } 

然而，这些慢操做并无明显的问题嫌疑，除了以写操做为主以外，索引的命中也没有问题。

数据库诊断

接下来，咱们将焦点集中到了数据库上，检查了 cpu、内存、网络、磁盘这些常规指标后并无发现什么异常。
经过 mongostat 观察到的以下图：

图- mongostat

其中的一个异常点是 netout 会有偶现的积压状况。
而后是尝试经过 db.currentOp() 这个命令来看看能不能揪出慢操做背后的元凶。

currentOp 仍是比较好用的，尤为是在定位一些长时间慢操做问题上

然而，个人想法落空了，这个办法并无任何发现！ 由于问题属于偶现，因此执行currentOp 须要一些好的运气..
尽管如此，咱们仍是大概能断定，在出现慢操做的时候，数据库出现了命令积压(卡顿)的状况

基于上面的这些诊断信息，咱们仍是没办法直接得出结论，可是你们都作出来一致的猜想：

"可能存在某个定时器的锁，对业务操做产生了阻塞！"

那么，锁从哪里来？ 咱们将目光移向了 MongoManager，的确这个程序承载了许多管理上的功能，包括监控、备份、升级这些杂事..
其中，执行数据库信息采集的监控定时器存在最大的嫌疑！，那么问题又来了，

"若是是定时器致使的卡顿，为何慢操做却没有定时产生的规律呢？"

这个问题在前面也对咱们产生了很大的困扰，但一个比较合理的解释是：

"MongoManager 是多节点的，而其中定时器是按照 时间间隔来运做的，而不是整点触发。"
这样就能解释，为何慢操做一般都是在1-5分钟内不规律的出现了。
为了证明这个想法，咱们直接将 MongoManager 逐个关闭到仅剩下一个，最终经过CommandListener收集到的慢操做图表以下：

看，此次的慢操做很是的规律，基本每5分钟就会出现一次卡顿！
而后咱们将所有的 MongoManager 关闭，业务的慢操做彻底消失了。

3、找出元凶

通过前面的问题定位，咱们已经能肯定是MongoManager的定时器搞的鬼了。
接下来走读代码，发现有下面这样的一段实现：

public void testDbOperation() { try { MongoClient client = getClient(); MongoDatabase database = client.getDatabase("thisdb"); List<String> allCollections = new ArrayList<>(); //get all collections MongoCursor<String> iCollection = database.listCollectionNames().iterator(); while (iCollection.hasNext()) { allCollections.add(iCollection.next()); } if (allCollections.isEmpty()) { return; } //test a random collection String randomCollection = allCollections.get((int) (allCollections.size() * Math.random())); //issue find operation database.getCollection(randomCollection).find().first(); } catch (Exception e) { throw new DBMonitException("the db find test failed..", e); } }

为了便于理解，上述的代码作了比较多的简化，大体的步骤是：

• 经过 listCollections 获取数据库的所有集合；
• 随机选取一个集合，执行findOne操做；
• 一旦发现操做失败，产生异常(告警)

上述的代码由定时器在5分钟触发一次，跟出现慢操做的条件是吻合的。
其中 listCollections 会获取到一个集合的列表，咱们猜想，这个操做可能会阻塞数据库的操做。

经过搜索官方文档，咱们发现该操做使用了一个共享读锁(S)：

图-listCollection锁

MongoDB 锁机制

为了说明阻塞的产生，这里须要解释下MongoDB的锁机制：

在数据库内部有下面这几种锁：

• 写锁(X)，对某个文档或数据库对象进行写时加锁
• 读锁(S)，对某个文档或数据库对象进行读取时加锁
• 意向写锁(IX)，对文档写操做时，对集合及数据库产生意向写锁
• 意向读锁(IS)，对文档读操做时，对集合及数据库产生意向读锁

意向锁提供了数据库系统的"多粒度锁"的能力，是提高并发能力的关键手段， WiredTiger 也是基于此来实现行级锁的。
几种锁的互斥关系以下表所示：

锁类型	S	X	IS	IX
S	T	F	T	F
X	F	F	F	F
IS	T	F	T	T
IX	F	F	T	T

基于此，咱们能够得出这样的结论：

由定时器产生 的 listCollections 操做会对数据库产生读锁(S)，从而对文档写操做(数据库的意向写锁IX)产生了阻塞。

那么，listCollections 从监控的意义上来看是不该该对数据库产生阻塞的。
咱们认为这应该是 MongoDB 3.4 版本一个Bug，而SERVER-34243 这里提交的一个Issue已经获得解决。
在最新的 4.x版本文档中，能够发现 listCollections 的权限已经变动成了 意向读锁(IS)。

经过 4.0 版本的 ReleaseNotes 能够确认这点：

The command listCollections takes Intent Shared lock on the database. In previous versions, the command takes Shared lock on the database.

连接： https://docs.mongodb.com/manual/release-notes/4.0/index.html

4、解决思路

在了解了事情的前因后果以后，咱们能够肯定这是 MongoDB 3.4 版本的一个不严谨的实现致使的问题。
因为没法直接升级整个数据库版本(代价太大), 咱们在监控程序上作了优化，即将 listCollections 结果进行了缓存，避免定时器每次都去操做这个命令，而问题最终获得了解决。

"监控不是银弹，滥用也会有坑"，至少从此次的事件中，咱们获得了一个教训！
而要在这个问题上触类旁通的话，那就是须要警戒一些数据库操做潜在的锁问题了，好比：

• 建立索引(默认Foreground模式)，会对数据库产生写锁(X)，因此必定要用Background模式
• 删除集合，dropCollection，会对数据库产生写锁(X)，谨慎！
• MapReduce操做，会对数据库产生读锁(S)和写锁(X)，谨慎！
• 链接鉴权，db.auth()，会对admin库产生读锁，而admin是库级锁。

以上的这些事情，你 Get 到了吗？