-
Type: Bug
-
Resolution: Duplicate
-
Priority: Major - P3
-
None
-
Affects Version/s: 3.0.4
-
Component/s: Diagnostics, Logging
-
None
-
ALL
Please see below example from my mongo server log. My server was going through high load resulting in slow updates. While debugging the issue I found following in log :
.............update: { $set: { inactive: { $date : { $numberLong : "1441696817446"} } } } nscanned:13 nscannedObjects:7 nmoved:1 nMatched:7 nModified:7 keyUpdates:2 writeConflicts:0 numYields:12 locks:{ Global: { acquireCount: { r: 20, w: 20 } }, MMAPV1Journal: { acquireCount: { w: 33 }, acquireWaitCount: { w: 14 }, timeAcquiringMicros: { w: 209519 } }, Database: { acquireCount: { w: 20 } }, Collection: { acquireCount: { W: 13 }, acquireWaitCount: { W: 13 }, timeAcquiringMicros: { W: 43560607112 } }, oplog: { acquireCount: { w: 7 }, acquireWaitCount: { w: 6 }, timeAcquiringMicros: { w: 172644 } } } 392356ms
The timeAcquiringMicros is very large compared to overall query time.
While I was under the impression that millis time includes all the lock times spend during an update operation. Am I correct on this ?
- duplicates
-
SERVER-21305 Lock 'timeAcquiringMicros' value is much higher than the actual time spent
- Closed