Uploaded image for project: 'Java Driver'
  1. Java Driver
  2. JAVA-3135

slow log questions, why global lock(timeAcquiringMicros) is large, there is no pressure in my mongo service(I/O is low, and have many free memory),

    • Type: Icon: Task Task
    • Resolution: Duplicate
    • Priority: Icon: Major - P3 Major - P3
    • None
    • Affects Version/s: 3.6.3
    • Labels:
    • Environment:
      Linux daijia-newlbs-mongo07.gz01 3.10.0-514.16.1.el7.x86_64 #1 SMP Wed Apr 12 15:04:24 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux

      32CPU
      SSD

            why global lock(timeAcquiringMicros) is large, there is no pressure in my mongo service(I/O is low, and have many free memory, and command query is low)

           

          slow log as following:

      2019-01-09T18:48:12.300+0800 I COMMAND [conn707992] command liangjian.Driver command: find { find: "Driver", filter: { pos:

      { $near: [ 121.5943918185764, 29.84648735894097 ], $maxDistance: 0.02700683945284377 }

      , uptime: { $gte: new Date(1547030592051) }, status: 1, btype: { $bitsAnySet: 7 } }, limit: 10, shardVersion: [ Timestamp(0, 0), ObjectId('000000000000000000000000') ], $readPreference: { mode: "secondaryPreferred" }, $clusterTime: { clusterTime: Timestamp(1547030892, 231), signature:

      { hash: BinData(0, 35C6E6D602FDFE11307659B12361C9C11B6AB206), keyId: 6639872680583495699 }

      }, $client: { driver:

      { name: "mongo-java-driver", version: "3.4.0" }

      , os: { type: "Linux", name: "Linux", architecture: "amd64", version: "2.6.32-642.6.2.el6.toav3.x86_64" }, platform: "Java/Oracle Corporation/1.7.0_79-mockbuild_2015_07_24_09_26-b00", mongos: { host: "fd-mongos-p01.gz01:27024", client: "100.69.94.23:46954", version: "3.6.3" } }, $configServerState: { opTime:

      { ts: Timestamp(1547030887, 374), t: 2 }

      }, $db: "liangjian" } planSummary: GEO_NEAR_2D { pos: "2d" } keysExamined:131 docsExamined:146 cursorExhausted:1 numYields:1 nreturned:10 reslen:1525 locks:{ Global: { acquireCount:

      { r: 4 }

      , acquireWaitCount: { r: 2 }, timeAcquiringMicros: { r: 243547 } }, Database: { acquireCount:

      { r: 2 }

      }, Collection: { acquireCount:

      { r: 2 }

      } } protocol:op_msg 247ms

          

       

          system.profile as following:

      lbs2_1:SECONDARY> db.system.profile.findOne()
      {
      "op" : "query",
      "ns" : "liangjian.Driver",
      "command" : {
      "find" : "Driver",
      "filter" :

      { "city" : 420100, "_id" : NumberLong("2817439193438706") }

      ,
      "shardVersion" : [
      Timestamp(0, 0),
      ObjectId("000000000000000000000000")
      ],
      "$readPreference" :

      { "mode" : "secondaryPreferred" }

      ,
      "$clusterTime" : {
      "clusterTime" : Timestamp(1547033350, 368),
      "signature" :

      { "hash" : BinData(0,"3M+JVUPxF98AftZMDEvZHL1OUnw="), "keyId" : NumberLong("6639871413568143379") }

      },
      "$client" : {
      "driver" :

      { "name" : "mongo-java-driver", "version" : "3.4.0" }

      ,
      "os" :

      { "type" : "Linux", "name" : "Linux", "architecture" : "amd64", "version" : "2.6.32-573.18.1.el6.toa.x86_64" }

      ,
      "platform" : "Java/Oracle Corporation/1.7.0_75-b13",
      "mongos" :

      { "host" : "fd-mongos-p02.gz01:27023", "client" : "100.69.96.50:37941", "version" : "3.6.3" }

      },
      "$configServerState" : {
      "opTime" :

      { "ts" : Timestamp(1547033345, 579), "t" : NumberLong(2) }

      },
      "$db" : "liangjian"
      },
      "keysExamined" : 1,
      "docsExamined" : 1,
      "cursorExhausted" : true,
      "numYield" : 0,
      "locks" : {
      "Global" : {
      "acquireCount" :

      { "r" : NumberLong(2) }

      ,
      "acquireWaitCount" :

      { "r" : NumberLong(1) }

      ,
      "timeAcquiringMicros" :

      { "r" : NumberLong(324445) }

      },
      "Database" : {
      "acquireCount" :

      { "r" : NumberLong(1) }

      },
      "Collection" : {
      "acquireCount" :

      { "r" : NumberLong(1) }

      }
      },
      "nreturned" : 1,
      "responseLength" : 454,
      "protocol" : "op_msg",
      "millis" : 335,
      "planSummary" : "IXSCAN { _id: 1 }",
      "execStats" : {
      "stage" : "FETCH",
      "filter" : {
      "city" :

      { "$eq" : 420100 }

      },
      "nReturned" : 1,
      "executionTimeMillisEstimate" : 0,
      "works" : 2,
      "advanced" : 1,
      "needTime" : 0,
      "needYield" : 0,
      "saveState" : 0,
      "restoreState" : 0,
      "isEOF" : 1,
      "invalidates" : 0,
      "docsExamined" : 1,
      "alreadyHasObj" : 0,
      "inputStage" : {
      "stage" : "IXSCAN",
      "nReturned" : 1,
      "executionTimeMillisEstimate" : 0,
      "works" : 2,
      "advanced" : 1,
      "needTime" : 0,
      "needYield" : 0,
      "saveState" : 0,
      "restoreState" : 0,
      "isEOF" : 1,
      "invalidates" : 0,
      "keyPattern" :

      { "_id" : 1 }

      ,
      "indexName" : "id",
      "isMultiKey" : false,
      "multiKeyPaths" :

      { "_id" : [ ] }

      ,
      "isUnique" : true,
      "isSparse" : false,
      "isPartial" : false,
      "indexVersion" : 2,
      "direction" : "forward",
      "indexBounds" :

      { "_id" : [ "[2817439193438706, 2817439193438706]" ] }

      ,
      "keysExamined" : 1,
      "seeks" : 1,
      "dupsTested" : 0,
      "dupsDropped" : 0,
      "seenInvalidated" : 0
      }
      },
      "ts" : ISODate("2019-01-09T11:29:10.368Z"),
      "client" : "100.69.186.20",
      "allUsers" : [

      { "user" : "__system", "db" : "local" }

      ],
      "user" : "__system@local"

       

         The problem doesn't come up very often, it comes up once in a while,who can help me, thanks!

            Assignee:
            Unassigned Unassigned
            Reporter:
            wocuocuo yxyxz123456
            Votes:
            0 Vote for this issue
            Watchers:
            3 Start watching this issue

              Created:
              Updated:
              Resolved: