Secondary节点为何阻塞请求近一个小时?-阿里云开发者社区

开发者社区> 阿里云数据库> 正文
登录阅读全文

Secondary节点为何阻塞请求近一个小时?

简介: 看到Secondary节点上的日志,我的内心的崩溃的,鉴权请求居然耗时2977790ms(约50分钟),经详细统计,这个Secondary节点上,所有16:54之后发起的用户请求,都阻塞到17:54左右才返回,处理时间最长的请求约1个小时。 2016-06-17T17:54:57.575+0800

看到Secondary节点上的日志,我的内心的崩溃的,鉴权请求居然耗时2977790ms(约50分钟),经详细统计,这个Secondary节点上,所有16:54之后发起的用户请求,都阻塞到17:54左右才返回,处理时间最长的请求约1个小时。

2016-06-17T17:54:57.575+0800 I COMMAND  [conn2581] command admin.system.users command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx" } keyUpdates:0 writeConflicts:0 numYields:0 reslen:171 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 2977790ms
2016-06-17T17:54:57.575+0800 I COMMAND  [conn2740] command admin.system.users command: saslStart { saslStart: 1, mechanism: "SCRAM-SHA-1", payload: "xxx" } keyUpdates:0 writeConflicts:0 numYields:0 reslen:171 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_query 2416390ms

经过调查,引发备节点阻塞近1个小时主要是对一个很大的集合『后台建立索引 + 删除索引』2个动作导致。

背景知识

  1. Secondary从Primary拉取到一批oplog后,重放oplog的过程会加一把特殊的锁,这个锁会阻塞所有的reader,这么做的原因我个人理解是避免让reader看到中间状态,只有等一批oplog全部应用成功才让客户端可读,避免出现脏读的问题。
  2. 建索引有前台(foreground)和后台(background)2种模式,前台建索引会加在整个过程中对DB加互斥写锁,同一个DB下的读写操作均会阻塞至索引建立结束;后台建索引只会对DB加意向写锁,对DB下的读写无影响。
  3. Secondary重放建立索引的命令时,如果是前台模式,则整个重放建索引的过程都会阻塞所有的reader;如果是后台模式,重放时建索引的动作会放到后台线程里做,只会阻塞reader很短的时间。

为了尽量避免建索引影响业务,通常

  1. 在集合创建的时候,就建立好索引,此时因为集合为空,建索引的开销很小。(以后每次写入,同时会更新索引)
  2. 如果建索引时,集合内已经写入了很多文档,尽量使用后台模式,避免『主节点上影响某个DB的所有读写』以及『备节点上影响所有的读』。

问题分析

在我们遇到的问题里,创建索引使用的后台模式,最终仍然导致Secondary阻塞读reader近1个小时,接下来分析下问题产生的原因,主要事件的过程如下所示。

| time | Primary | Secondary |
| --- | --- | --- |
| 15:07:00| db.coll 开始后台创建索引 |
| 16:32:35 | db.coll 创建索引结束| 从oplog拉取到createIndex的操作,并开始重放|
| 16:54:53 | 删除db数据库下某个索引 | 从oplog拉取到dropIndex的请求并开始重放,此时所有的请求开始阻塞 |
| 17:54:53 | | 重放createIndex结束,开始应答阻塞的请求|

  1. 15:07:00 Primary上发起后台建索引,创建索引的过程耗费近1.5小时
  2. 16:32:25 创建索引完成,Primary上记录oplog,Secondary拉取到oplog并重放该动作,由于是后台建索引,Secondary会启动一个单独的线程来建索引,建索引的过程会对DB加意向锁,所以重放动作只会阻塞reader很短的时间(毫秒级别)。
  3. 16:54:53 用户在同一个DB下发起了一个删除索引的动作,删除动作在主上很快结束,备拉取到oplog开始重放,删除索引的动作需要对DB加互斥锁,而此时Secondary后台建索引还在进行中,已经对DB加了意向锁,导致这个互斥锁需要等待后台建索引结束,而重放oplog时,Secondary占用的特殊锁会阻塞所有的reader,所以从这个时间点开始,所有的reader都阻塞等待了。
  4. 17:54:53 Secondary后台建索引结束,删除索引获得互斥锁并完成删除动作,重放结束,阻塞的reader加锁成功并得到处理。

总结

上述问题主要因为MongoDB的设计机制导致,Secondary节点重放oplog时的锁粒度太大,会阻塞所有的读请求;但如果降低锁粒度,就可能会出现脏读的问题,这对于某些业务场景是不可接受的。目前来说,只要不把『耗时长并且需要同步到备节点』的操作放到业务逻辑里,影响是完全可以忽略的,如果实在无法避免,最终出现了Secondary长时间阻塞的情况,就直接使用默认的readPreference,只从Primary上读数据。

参考资料

版权声明:本文内容由阿里云实名注册用户自发贡献,版权归原作者所有,阿里云开发者社区不拥有其著作权,亦不承担相应法律责任。具体规则请查看《阿里云开发者社区用户服务协议》和《阿里云开发者社区知识产权保护指引》。如果您发现本社区中有涉嫌抄袭的内容,填写侵权投诉表单进行举报,一经查实,本社区将立刻删除涉嫌侵权内容。

分享:
阿里云数据库
使用钉钉扫一扫加入圈子
+ 订阅

帮用户承担一切数据库风险,给您何止是安心!

官方博客
最新文章
相关文章
链接