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

COUNT_SCAN plans are not generated properly from the plan cache

    • Type: Icon: Bug Bug
    • Resolution: Done
    • Priority: Icon: Critical - P2 Critical - P2
    • 3.3.2
    • Affects Version/s: 3.0.8
    • Component/s: Querying
    • Labels:
      None
    • Fully Compatible
    • ALL
    • v3.2
    • Query F (02/01/16)

      We are using WiredTiger on 3.0.8 version of MongoDB. The server in question is a SECONDARY which has been setup to support our read-only/query clients.

      We have observed that after a heavy activity of inserts into MASTER (which are then replicated to the SECONDARY), the queries which used to run fairly fast become unusable with response times of over a minute.

      Here is an example of inconsistencies that we are seeing. The problem has already occurred and performance of queries has degraded.

      The following query runs fairly fast:

      db.getCollection('events-qos-loadstart').count({"vd.ple.vd.pid": "57de9139-cc7e-4b5c-51fd-aaa8517028f0","vd.ple.vd.acc": "EY"})
      Jan 11 18:25:28 ec2-52-23-180-212 mongod.27000[29049]: [conn11450] command cdc.$cmd command: count { count: "events-qos-loadstart", query: { vd.ple.vd.pid: "57de9139-cc7e-4b5c-51fd-aaa8517028f0", vd.ple.vd.acc: "EY" }, fields: {} } planSummary: COUNT_SCAN { vd.ple.vd.acc: 1, vd.ple.vd.pid: 1, vd.pec: 1, vd.ts: 1 } keyUpdates:0 writeConflicts:0 numYields:1817 reslen:44 locks:{ Global: { acquireCount: { r: 3636 }, acquireWaitCount: { r: 37 }, timeAcquiringMicros: { r: 134261 } }, Database: { acquireCount: { r: 1818 } }, Collection: { acquireCount: { r: 1818 } } } 218ms
      Count: 232691
      

      A similar query with just additional parameter is taking an incredibly longer time to run:

      db.getCollection('events-qos-loadstart').count({"vd.ple.vd.pid": "57de9139-cc7e-4b5c-51fd-aaa8517028f0","vd.ple.vd.acc": "EY", "vd.pec": {"$gte": 2}})
      Jan 11 18:32:33 ec2-52-23-180-212 mongod.27000[29049]: [conn11450] command cdc.$cmd command: count { count: "events-qos-loadstart", query: { vd.ple.vd.pid: "57de9139-cc7e-4b5c-51fd-aaa8517028f0", vd.ple.vd.acc: "EY", vd.pec: { $gte: 2.0 } }, fields: {} } planSummary: IXSCAN { vd.ple.vd.acc: 1, vd.ple.vd.pid: 1, vd.pec: 1, vd.ts: 1 } keyUpdates:0 writeConflicts:0 numYields:3444 reslen:44 locks:{ Global: { acquireCount: { r: 6890 }, acquireWaitCount: { r: 2074 }, timeAcquiringMicros: { r: 29318135 } }, Database: { acquireCount: { r: 3445 } }, Collection: { acquireCount: { r: 3445 } } } 85835ms
      Count: 231445
      

      Here are the indexes which are defined on this collection:

      [
      	{
      		"v" : 1,
      		"key" : {
      			"_id" : 1
      		},
      		"name" : "_id_",
      		"ns" : "cdc.events-qos-loadstart"
      	},
      	{
      		"v" : 1,
      		"key" : {
      			"vd.ple.vd.acc" : 1,
      			"vd.ts" : 1,
      			"vd.pec" : 1
      		},
      		"name" : "vd.ple.vd.acc_1_vd.ts_1_vd.pec_1",
      		"ns" : "cdc.events-qos-loadstart"
      	},
      	{
      		"v" : 1,
      		"key" : {
      			"vd.ts" : 1,
      			"vd.pec" : 1
      		},
      		"name" : "vd.ts_1_vd.pec_1",
      		"ns" : "cdc.events-qos-loadstart"
      	},
      	{
      		"v" : 1,
      		"key" : {
      			"vd.ple.vd.acc" : 1,
      			"vd.ple.vd.pid" : 1,
      			"vd.pec" : 1,
      			"vd.ts" : 1
      		},
      		"name" : "vd.ple.vd.acc_1_vd.ple.vd.pid_1_vd.pec_1_vd.ts_1",
      		"ns" : "cdc.events-qos-loadstart"
      	}
      ]
      

      Note that all the fields are in an index.

      If I restart the server, both of these queries will return in milliseconds.

            Assignee:
            david.storch@mongodb.com David Storch
            Reporter:
            apara Alex Paransky
            Votes:
            0 Vote for this issue
            Watchers:
            12 Start watching this issue

              Created:
              Updated:
              Resolved: