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

Performance issue: Query Plan Cache is always empty

    XMLWordPrintableJSON

Details

    • ALL
    • Hide

      mongodb standalone configuration

      systemLog:
      		 
         destination: file
      		 
         path: "test.log"
      		 
         quiet: true
      		 
         logAppend: true
      		 
      storage:
      		 
         journal:
      		 
            enabled: true
      		 
         dbPath: "d:\\dbpath\\test"
      		 
         directoryPerDB: false
      		 
       
      		 
      net:
      		 
         bindIp: 127.0.0.1
      		 
         port: 27017
      		 
         http:
      		 
            RESTInterfaceEnabled: true

      create some documents

      for (i = 0; i < 100000; i++) {
      		 
      db.test26.insert(
      		 
          {"_id" : new ObjectId, 
              "user" : "mario", "removed" : false, "objId" : i, "created" : new Date(),
      		 
              "p" : { "id" : ["content"+i,"content"+(i+1),"content"+(i+2)]   }, 
              "a" : "attributea"+i,"b" : "attributeb"+i,"c" : "attributec"+i}   );
      		 
          }

      create some index

      db.test26.ensureIndex({ "user" : 1,"removed":1,"a" : 1 });
      		 
      db.test26.ensureIndex({ "user" : 1,"removed":1,"b" : 1 });
      		 
      db.test26.ensureIndex({ "user" : 1,"removed":1,"c" : 1 });
      		 
      db.test26.ensureIndex({ "user" : 1,"removed":1,"p.id" : 1 });

      Show
      mongodb standalone configuration systemLog: destination: file path: "test.log" quiet: true logAppend: true storage: journal: enabled: true dbPath: "d:\\dbpath\\test" directoryPerDB: false   net: bindIp: 127.0.0.1 port: 27017 http: RESTInterfaceEnabled: true create some documents for (i = 0; i < 100000; i++) { db.test26.insert( {"_id" : new ObjectId, "user" : "mario", "removed" : false, "objId" : i, "created" : new Date(), "p" : { "id" : ["content"+i,"content"+(i+1),"content"+(i+2)] }, "a" : "attributea"+i,"b" : "attributeb"+i,"c" : "attributec"+i} ); } create some index db.test26.ensureIndex({ "user" : 1,"removed":1,"a" : 1 }); db.test26.ensureIndex({ "user" : 1,"removed":1,"b" : 1 }); db.test26.ensureIndex({ "user" : 1,"removed":1,"c" : 1 }); db.test26.ensureIndex({ "user" : 1,"removed":1,"p.id" : 1 });

    Description

      I found really bad performance on mongodb 2.6.4 (... 2.6.latest, 2.7.latest)..
      It seams that Query Plan Cache is always empty, and for each single query (not working over a specific index), mongodb performs a Query Plan.
      Performance are good only if hint() operator is specified with the query. I tested the same scenario on mongodb 2.4.3 but everything works fine.

      the test query

      db.test26.find({"user":"mario","removed":false,"objId":3}).explain()
      		 
       
      		 
      Explain result:
      		 
       
      		 
      {
      		 
          "cursor" : "BtreeCursor user_1_removed_1_a_1",
      		 
          "isMultiKey" : false,
      		 
          "n" : 2,
      		 
          "nscannedObjects" : 210000,
      		 
          "nscanned" : 210000,
      		 
          "nscannedObjectsAllPlans" : 482615,
      		 
          "nscannedAllPlans" : 524601,
      		 
          "scanAndOrder" : false,
      		 
          "indexOnly" : false,
      		 
          "nYields" : 5158,
      		 
          "nChunkSkips" : 0,
      		 
          "millis" : 1072,
      		 
          "filterSet" : false
      		 
      }

      I tried to run these commands:

      db.test26.find({"user":"mario","removed":false,"objId":3}).explain()
      		 
      db.test26.find({"user":"mario","removed":false,"objId":3})
      		 
      db.test26.find({"user":"mario","removed":false,"objId":3}).hint("user_1_removed_1_a_1")

      getting the following log output:

      # log for query with explain true: [conn11] query test.test26 query: { query: { user: "mario", removed: false, objId: 3.0 }, $explain: true } planSummary: IXSCAN { user: 1.0, removed: 1.0, a: 1.0 } ntoreturn:0 ntoskip:0 nscanned:210000 nscannedObjects:210000 keyUpdates:0 numYields:1685 locks(micros) r:2127426 nreturned:1 reslen:3291 1072ms
      		 
      # log for query without explain: [conn11] query test.test26 query: { user: "mario", removed: false, objId: 3.0 } planSummary: IXSCAN { user: 1.0, removed: 1.0, a: 1.0 } ntoreturn:0 ntoskip:0 nscanned:210000 nscannedObjects:210000 keyUpdates:0 numYields:1 locks(micros) r:1298548 nreturned:2 reslen:424 981ms
      		 
      # log for query with hint: [conn11] query test.test26 query: { query: { user: "mario", removed: false, objId: 3.0 }, $hint: "user_1_removed_1_a_1" } planSummary: IXSCAN { user: 1.0, removed: 1.0, a: 1.0 } ntoreturn:0 ntoskip:0 nscanned:210000 nscannedObjects:210000 keyUpdates:0 numYields:1 locks(micros) r:777390 nreturned:2 reslen:424 390ms

      The query number 2 has the same performance of the query with the explain command, and I suppose that every time the query runs the mongodb server perform a full query plan!!! After the execution of the query, the Query Plan Cache seams to be empty

      db.collection.getPlanCache().listQueryShapes() = []

      Additional notes

      If I declare other indexes on the same collection the performance of query downgrade!

      mongodb 2.4.3 log for the same test:

      1st run of the query:  [conn2] query test.test26 query: { user: "mario", removed: false, objId: 3.0 } ntoreturn:0 ntoskip:0 nscanned:1470000 keyUpdates:0 numYields: 5 locks(micros) W:5252 r:8464649 nreturned:2 reslen:424 4381ms
      		 
      2nd run of the query:  [conn2] query test.test26 query: { user: "mario", removed: false, objId: 3.0 } ntoreturn:0 ntoskip:0 nscanned:210000 keyUpdates:0 locks(micros) r:652975 nreturned:2 reslen:424 652ms

      Attachments

        Issue Links

          related to

          Bug - A problem which impairs or prevents the functions of the product. SERVER-13675 Plans with differing performance can tie during plan ranking

          • Critical - P2 - Crashes, loss of data, severe memory leak.
          • Closed

          Bug - A problem which impairs or prevents the functions of the product. SERVER-14525 Perf regression in 2.6.2 caused by not caching plans that tie during plan ranking

          • Critical - P2 - Crashes, loss of data, severe memory leak.
          • Closed

          Activity

            People

              ramon.fernandez@mongodb.com Ramon Fernandez Marina
              flavio@alicubi.net flavio alberti
              Votes:
              0 Vote for this issue
              Watchers:
              6 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: