-
Type: Bug
-
Resolution: Duplicate
-
Priority: Major - P3
-
None
-
Affects Version/s: 3.0.4
-
Component/s: Diagnostics, Querying
-
None
-
ALL
slowlog info:
2015-09-22T04:53:10.248+0800 I QUERY [conn1664530] query external.dianping query: { flag: { $ne: "d" }, data.poiid: { $in: [ "aaaaa", "xxxxx", "yyyyy" ] } } planSummary: IXSCAN { data.poiid: 1.0 } ntoreturn:0 ntoskip:0 nscanned:2 nscannedObjects:0 keyUpdates:0 writeConflicts:0 numYields:2 nreturned:0 reslen:20 locks:{ Global: { acquireCount: { r: 6 }, acquireWaitCount: { r: 1 }, timeAcquiringMicros: { r: 195093 } }, Database: { acquireCount: { r: 3 } }, Collection: { acquireCount: { r: 3 } } } 52ms
execute time is 52ms,but Global timeAcquiringMicros is 195ms.
AutoGetCollectionForRead::AutoGetCollectionForRead(OperationContext* txn ,
const std::string& ns )
: _txn(txn),
_transaction(txn, MODE_IS),
_db(_txn, nsToDatabaseSubstring(ns), MODE_IS),
_collLock(_txn->lockState(), ns, MODE_IS),
_coll(NULL) {
_init(ns, nsToCollectionSubstring(ns));
}
_db and _collLock will acquire lock, may spend a lot time. but query started time is in _init set.
- duplicates
-
SERVER-18637 Measure initial lock time in operation latency
- Closed