免费注册 查看新帖 |

Chinaunix

  平台 论坛 博客 文库
最近访问板块 发新帖
查看: 1545 | 回复: 0
打印 上一主题 下一主题

[MongoDB] Secondary节点为何阻塞请求近一个小时? [复制链接]

求职 : Linux运维
论坛徽章:
203
拜羊年徽章
日期:2015-03-03 16:15:432015年辞旧岁徽章
日期:2015-03-03 16:54:152015年迎新春徽章
日期:2015-03-04 09:57:092015小元宵徽章
日期:2015-03-06 15:58:182015年亚洲杯之约旦
日期:2015-04-05 20:08:292015年亚洲杯之澳大利亚
日期:2015-04-09 09:25:552015年亚洲杯之约旦
日期:2015-04-10 17:34:102015年亚洲杯之巴勒斯坦
日期:2015-04-10 17:35:342015年亚洲杯之日本
日期:2015-04-16 16:28:552015年亚洲杯纪念徽章
日期:2015-04-27 23:29:17操作系统版块每日发帖之星
日期:2015-06-06 22:20:00操作系统版块每日发帖之星
日期:2015-06-09 22:20:00
跳转到指定楼层
1 [收藏(0)] [报告]
发表于 2016-06-25 19:06 |只看该作者 |倒序浏览
本帖最后由 lyhabc 于 2016-06-25 19:10 编辑

看到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 } } } protocolp_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 } } } protocolp_query 2416390ms
经过调查,引发备节点阻塞近1个小时主要是对一个很大的集合『后台建立索引 + 删除索引』2个动作导致。

背景知识

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

在集合创建的时候,就建立好索引,此时因为集合为空,建索引的开销很小。(以后每次写入,同时会更新索引)
如果建索引时,集合内已经写入了很多文档,尽量使用后台模式,避免『主节点上影响某个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结束,开始应答阻塞的请求
15:07:00 Primary上发起后台建索引,创建索引的过程耗费近1.5小时
16:32:25 创建索引完成,Primary上记录oplog,Secondary拉取到oplog并重放该动作,由于是后台建索引,Secondary会启动一个单独的线程来建索引,建索引的过程会对DB加意向锁,所以重放动作只会阻塞reader很短的时间(毫秒级别)。
16:54:53 用户在同一个DB下发起了一个删除索引的动作,删除动作在主上很快结束,备拉取到oplog开始重放,删除索引的动作需要对DB加互斥锁,而此时Secondary后台建索引还在进行中,已经对DB加了意向锁,导致这个互斥锁需要等待后台建索引结束,而重放oplog时,Secondary占用的特殊锁会阻塞所有的reader,所以从这个时间点开始,所有的reader都阻塞等待了。
17:54:53 Secondary后台建索引结束,删除索引获得互斥锁并完成删除动作,重放结束,阻塞的reader加锁成功并得到处理。
总结

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

锁粒度太大,不是document级别的锁粒度,也不是collection级别的锁粒度,而是DB级别的锁粒度,并发很差
所以mongodb也是有很多坑的
您需要登录后才可以回帖 登录 | 注册

本版积分规则 发表回复

  

北京盛拓优讯信息技术有限公司. 版权所有 京ICP备16024965号-6 北京市公安局海淀分局网监中心备案编号:11010802020122 niuxiaotong@pcpop.com 17352615567
未成年举报专区
中国互联网协会会员  联系我们:huangweiwei@itpub.net
感谢所有关心和支持过ChinaUnix的朋友们 转载本站内容请注明原作者名及出处

清除 Cookies - ChinaUnix - Archiver - WAP - TOP