-
Type:
Question
-
Resolution: Done
-
Priority:
Major - P3
-
None
-
Affects Version/s: 3.0.15
-
Component/s: None
-
Labels:None
Hello.
I'm dealing with an update, always over the same collection, that usually takes around 5ms and in certain ocassions it grows up until 2500ms.
I use the MongoDB 3.0.15 version.
This is a little part of the log (I attach the log file):
2018-02-28T16:16:48.219+0100 D REPL [conn1593794] received notification that node with RID 5a5e7bf033574643f3dbf66a has reached optime: 5a96c7de:5
2018-02-28T16:16:48.219+0100 D REPL [conn1593794] Node with RID 5a5e7bf033574643f3dbf66a and memberId 3 currently has optime 5a96c7de:4; updating to 5a96c7de:5
2018-02-28T16:16:48.219+0100 I COMMAND [conn1593794] command admin.$cmd command: replSetUpdatePosition { replSetUpdatePosition: 1, optimes: [ { _id: ObjectId('59c650db4399f8e73f242483'), optime: Timestamp 1517423916000|2, memberId: 0, cfgver: 6, config: { _id: 0, host: "gaming01:27017", arbiterOnly: false, buildIndexes: true, hidden: false, priority: 2.0, tags: { client: "B2B01" }, slaveDelay: 0, votes: 1 } }, { _id: ObjectId('59c651496a3fc2ba430fe203'), optime: Timestamp 1519831006000|5, memberId: 1, cfgver: 6, config: { _id: 1, host: "gaming02:27017", arbiterOnly: false, buildIndexes: true, hidden: false, priority: 1.5, tags: { client: "B2B02" }, slaveDelay: 0, votes: 1 } }, { _id: ObjectId('59c6515d06ee67c2b33c8ce3'), optime: Timestamp 1519831006000|4, memberId: 2, cfgver: 6, config: { _id: 2, host: "gaming03:27017", arbiterOnly: false, buildIndexes: true, hidden: false, priority: 1.0, tags: { client: "MURANO" }, slaveDelay: 0, votes: 1 } }, { _id: ObjectId('5a5e7bf033574643f3dbf66a'), optime: Timestamp 1519831006000|5, memberId: 3, cfgver: 6, config: { _id: 3, host: "gaming04:27017", arbiterOnly: false, buildIndexes: true, hidden: false, priority: 1.3, tags: { client: "B2B04" }, slaveDelay: 0, votes: 1 } } ] } ntoreturn:1 keyUpdates:0 writeConflicts:0 numYields:0 reslen:37 locks:{} 0ms
2018-02-28T16:16:48.219+0100 I COMMAND [conn1592412] command b2bgaming.$cmd command: update { update: "user_scores", updates: [ { q: { _id: ObjectId('59d2519ee26b64e4728b4575') }, u: { $set: { hits: 7717 } }, multi: false, upsert: false } ], writeConcern: { j: true, w: 2 } } keyUpdates:0 writeConflicts:0 numYields:0 reslen:95 locks:{ Global: { acquireCount: { r: 3, w: 3 } }, Database: { acquireCount: { w: 3 } }, Collection: { acquireCount: { w: 2 } }, Metadata: { acquireCount: { W: 1 } }, oplog: { acquireCount: { w: 1 } } } 2016ms
Example of normal operation:
2018-02-28T13:09:04.298+0100 I COMMAND [conn1579312] command b2bgaming.$cmd command: update { update: "user_scores", updates: [ { q: { _id: ObjectId('59d3a0ade26b648d6c8b4599') }, u: { $set: { hits: 7110 } }, multi: false, upsert: false } ], writeConcern: { j: true, w: 2 } } keyUpdates:0 writeConflicts:0 numYields:0 reslen:95 locks:{ Global: { acquireCount: { r: 3, w: 3 } }, Database: { acquireCount: { w: 3 } }, Collection: { acquireCount: { w: 2 } }, Metadata: { acquireCount: { W: 1 } }, oplog: { acquireCount: { w: 1 } } } 2ms
Thanks!