Uploaded image for project: 'Core Server'
  1. Core Server
  2. SERVER-20632

Query execute time not include some LOCK acquire time

    • Type: Icon: Bug Bug
    • Resolution: Duplicate
    • Priority: Icon: Major - P3 Major - P3
    • None
    • Affects Version/s: 3.0.4
    • Component/s: Diagnostics, Querying
    • Labels:
      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.

            Assignee:
            Unassigned Unassigned
            Reporter:
            ych.tiger@gmail.com YANG Chenghu
            Votes:
            0 Vote for this issue
            Watchers:
            4 Start watching this issue

              Created:
              Updated:
              Resolved: