为什么local.oplog.rs上每隔几分钟的活动就会锁定mongo客户端
为什么local.oplog.rs上每隔几分钟的活动就会锁定mongo客户端
提问于 2015-07-07 21:50:21
问题是：
每隔一到两分钟，mongo客户端就会暂停大约3秒。更新的正常操作时间约为1或2毫秒。当这种缓慢出现时，我们有一堆持续1到3秒的更新。
慢查询日志不会显示与此相关的任何内容。调试mongo客户端(mongo-php- client )也不需要。
目前的架构在副本集中有1个master、1个slave和1个仲裁器。
执行的查询总是相同的排序(upsert by _id，insert with new MongoId)。没有“每隔几分钟我们就运行一次非常昂贵的更新”。
阻塞似乎是由local.oplog.rs引起的。至少，下面的mongotop输出显示了这一点。我没有发现任何迹象表明第二个命令导致了这个问题，因为下面所有命令的输出似乎都是稳定的。我也没有发现任何信息表明速度慢是由特定的查询引起的。
我们存储数据的方式背后的想法是预聚合报告。我们有很多更新(每秒几百次)，但查询率非常低。索引是有日期限制的(除了_id，它是根据记录包含的所有维度通过组合键计算得出的。我的意思是，与ObjectId索引不同，_id不是增量的)。仅给出一个概念，最大集合中的索引是( Mb)：
"indexSizes" : {
"_id_" : 1967,
"owner_date" : 230,
"flow_date" : 231,
"date" : 170
},大多数其他集合的索引大小为100Mb或更小。在所有的集合中，_id索引是最大的一个。值得注意的是，此Is是手动生成的(基于元数据，因此插入是作为upsert完成的，而不是递增的)
FollowUp：
Edit1:经过进一步挖掘，在刷新到磁盘时，锁定似乎与日志的rsync过程相关。日志与数据文件位于相同的文件系统中，但由于磁盘是快速ssd设备，因此速度慢是意想不到的。
Edit2:经过测试，磁盘的写入能力不是问题。我们通常以每秒几兆字节的速率写入数据。在磁盘上运行一些测试，它可以接受150mb/s，没有问题
预期的答案是：
为什么会发生这种停机？
- 指向可能的原因，以便根据
的相似案例调查案例
问题说明：
以下命令在主节点中运行
每次出现速度缓慢时，我们都会在mongostat中看到以下内容(两个示例)
insert query update delete getmore command % dirty % used flushes vsize res qr|qw ar|aw netIn netOut conn set repl time
10 *0 141 *0 93 120|0 0.4 80.0 0 11.5G 9.4G 0|1 1|0 110k 71k 274 rs0 PRI 13:15:44
12 *0 178 *0 72 105|0 0.2 80.0 1 11.5G 9.4G 0|0 1|0 111k 79k 274 rs0 PRI 13:15:45
47 *0 7 *0 0 159|0 0.1 80.0 0 11.5G 9.4G 0|0 2|1 15k 44k 274 rs0 PRI 13:15:49 !!!!HERE
14 *0 929 *0 99 170|0 0.2 80.0 0 11.5G 9.4G 0|0 1|0 419k 417k 274 rs0 PRI 13:15:50
21 *0 287 *0 124 181|0 0.2 80.0 0 11.5G 9.4G 0|0 1|0 187k 122k 274 rs0 PRI 13:15:51
insert query update delete getmore command % dirty % used flushes vsize res qr|qw ar|aw netIn netOut conn set repl time
10 *0 145 *0 70 108|0 0.3 79.9 0 11.5G 9.4G 0|0 1|0 98k 71k 274 rs0 PRI 13:16:48
11 *0 155 *0 72 111|0 0.2 79.9 1 11.5G 9.4G 0|0 1|0 103k 75k 274 rs0 PRI 13:16:49
44 *0 3 *0 0 144|0 0.0 79.9 0 11.5G 9.4G 0|2 1|0 11k 75k 274 rs0 PRI 13:16:53 !!!!HERE
11 *0 837 *0 94 134|0 0.2 79.9 0 11.5G 9.4G 0|0 1|0 377k 348k 274 rs0 PRI 13:16:54
12 *0 180 *0 86 139|0 0.2 79.9 0 11.5G 9.4G 0|0 1|0 122k 85k 274 rs0 PRI 13:16:55
14 *0 195 *0 83 124|0 0.2 79.9 0 11.5G 9.4G 0|0 2|0 125k 89k 274 rs0 PRI 13:16:56update列有一个drop，下面的列有更多的更新。还要注意的是，我们使用的是具有1秒延迟的mongostat。当速度变慢时，mongostat会停止响应几秒钟。停止只存在于主服务器中，而不存在于从服务器中
这是这个问题发生时mongotop的输出(在2015-07-07T13:29:38)：
(可以在here中找到更多上下文的示例)
ns total read write 2015-07-07T13:29:33+02:00
database_name.d_date_flow_owner 555ms 550ms 4ms
local.oplog.rs 61ms 53ms 7ms
database_name.client_context_bbbbbbb 15ms 0ms 15ms
database_name.d_date_landing_owner 15ms 0ms 15ms
database_name.d_date_billing_owner 10ms 0ms 10ms
database_name.w_bl_carrier_country_date_device_flow_landing_manager_op1_os_owner_prod_site 7ms 0ms 7ms
database_name.d_carrier_country_date_device_flow_landing_op1_os_owner_site 5ms 0ms 5ms
database_name.d_country_date_owner 5ms 0ms 5ms
database_name.d_date_device_owner 5ms 0ms 5ms
database_name.d_date_os_owner 5ms 0ms 5ms
ns total read write 2015-07-07T13:29:37+02:00
database_name.client_context_bbbbbbb 2ms 0ms 2ms
database_name.client_context_aaaaaaaaa 1ms 0ms 1ms
admin.system.backup_users 0ms 0ms 0ms
admin.system.namespaces 0ms 0ms 0ms
admin.system.new_users 0ms 0ms 0ms
admin.system.profile 0ms 0ms 0ms
admin.system.roles 0ms 0ms 0ms
admin.system.users 0ms 0ms 0ms
admin.system.version 0ms 0ms 0ms
database_name 0ms 0ms 0ms
ns total read write 2015-07-07T13:29:38+02:00
local.oplog.rs 8171ms 4470ms 3701ms
database_name.d_date_op1_owner 45ms 0ms 45ms
database_name.d_date_device_owner 39ms 0ms 39ms
database_name.m_date_owner 34ms 0ms 34ms
database_name.d_date_owner 32ms 0ms 32ms
database_name.d_date_owner_site 31ms 0ms 31ms
database_name.d_carrier_date_owner 30ms 0ms 30ms
database_name.d_date_flow_owner 30ms 0ms 30ms
database_name.d_date_owner_product 28ms 0ms 28ms
database_name.d_carrier_country_date_device_flow_landing_op1_os_owner_site 27ms 0ms 27ms
ns total read write 2015-07-07T13:29:39+02:00
database_name.d_date_flow_owner 558ms 552ms 6ms
local.oplog.rs 62ms 61ms 1ms
database_name.d_carrier_date_owner 17ms 0ms 17ms
database_name.d_date_owner 16ms 0ms 16ms
database_name.w_bl_carrier_country_date_device_flow_landing_manager_op1_os_owner_prod_site 7ms 0ms 7ms
database_name.d_date_billing_owner 6ms 0ms 6ms
database_name.d_carrier_country_date_device_flow_landing_op1_os_owner_site 5ms 0ms 5ms
database_name.d_country_date_owner 5ms 0ms 5ms
database_name.d_date_device_owner 5ms 0ms 5ms
database_name.d_date_op1_owner 5ms 0ms 5ms 显示问题的php mongo客户端的调试(最后两行"PhpMongoClient调试“行)：
(可以在here中找到更多上下文的示例)
Update duration: 2ms
Update duration: 1ms
Update duration: 1ms
Update duration: 4006ms
PhpMongoClient debug: 2015-07-07 10:40:26 - PARSE (INFO): Parsing mongodb://primary_host.lan,secondary_host.lan
PhpMongoClient debug: 2015-07-07 10:40:26 - PARSE (INFO): - Found node: primary_host.lan:27017
[....]
PhpMongoClient debug: 2015-07-07 10:40:26 - REPLSET (FINE): limiting by credentials: done
PhpMongoClient debug: 2015-07-07 10:40:26 - REPLSET (FINE): sorting servers by priority and ping time
PhpMongoClient debug: 2015-07-07 10:40:26 - REPLSET (FINE): - connection: type: PRIMARY, socket: 42, ping: 0, hash: primary_host.lan:27017;rs0;database_name/user/5ca571e7db198eeee3abee35857bfd53;30751
PhpMongoClient debug: 2015-07-07 10:40:26 - REPLSET (FINE): sorting servers: done
PhpMongoClient debug: 2015-07-07 10:40:26 - REPLSET (FINE): selecting near servers
PhpMongoClient debug: 2015-07-07 10:40:26 - REPLSET (FINE): selecting near servers: nearest is 0ms
PhpMongoClient debug: 2015-07-07 10:40:26 - REPLSET (FINE): - connection: type: PRIMARY, socket: 42, ping: 0, hash: primary_host.lan:27017;rs0;database_name/user/5ca571e7db198eeee3abee35857bfd53;30751
PhpMongoClient debug: 2015-07-07 10:40:26 - REPLSET (FINE): selecting near server: done
PhpMongoClient debug: 2015-07-07 10:40:26 - REPLSET (INFO): pick server: random element 0
PhpMongoClient debug: 2015-07-07 10:40:26 - REPLSET (INFO): - connection: type: PRIMARY, socket: 42, ping: 0, hash: primary_host.lan:27017;rs0;database_name/user/5ca571e7db198eeee3abee35857bfd53;30751
PhpMongoClient debug: 2015-07-07 10:40:26 - CON (FINE): No timeout changes for primary_host.lan:27017;rs0;database_name/user/5ca571e7db198eeee3abee35857bfd53;30751
PhpMongoClient debug: 2015-07-07 10:40:30 - CON (FINE): No timeout changes for primary_host.lan:27017;rs0;database_name/user/5ca571e7db198eeee3abee35857bfd53;30751
Update duration: 3943ms
Update duration: 3476ms
Update duration: 2008ms
Update duration: 961ms
Update duration: 956ms
Update duration: 20ms
Update duration: 20ms
Update duration: 3ms
Update duration: 42ms
Update duration: 24ms
Update duration: 25ms
Update duration: 56ms
Update duration: 24ms
Update duration: 11ms
Update duration: 11ms
Update duration: 3ms
Update duration: 2ms
Update duration: 3ms
Update duration: 1ms
Update duration: 1ms
Update duration: 1ms
Update duration: 2msMongo信息：
Linux Mongo版本:带有1个从服务器和1个arbiter
- Replication延迟的3.0.3
- Replica设置在0到4个seconds
- Engine: WiredTiger
- Filesystem: XFS
- Operative系统之间变化: Red Hat Enterprise
- 版本7.1
- 内存:24 7.1。htop报告为40%的使用率，60%的缓存
回答 1
Stack Overflow用户
回答已采纳
发布于 2015-10-01 01:03:41
这个问题现在已经消失了。采取了两项行动：
- 修改了预聚合报告系统。mongo的工作负载减少了10倍。
- 将mongo的版本更新到3.0.6
不幸的是，这两个变化在没有太多时间的情况下被放到了网上。我怀疑减少工作量确实起到了作用(这可能与@steve-brisk指出的问题有关，也可能没有关联)，至少现在是这样(我们将看到何时再次达到以前的工作量水平)。但是，由于版本也在更新，因此即使使用以前的工作负载级别，我们也可能不会再次遇到此问题
我没有证据表明只有两种解决方案中的一种。但是，在同时使用这两种方法之后，问题就解决了。
页面原文内容由Stack Overflow提供。腾讯云小微IT领域专用引擎提供翻译支持
原文链接：
https://stackoverflow.com/questions/31270464
复制相关文章
相似问题