[SERVER-26978] Query Optimizer not using index correctly Created: 10/Nov/16  Updated: 18/Nov/16  Resolved: 18/Nov/16

Status: Closed
Project: Core Server
Component/s: Aggregation Framework
Affects Version/s: 3.2.10
Fix Version/s: None

Type: Bug Priority: Major - P3
Reporter: Stephane Marquis Assignee: Kelsey Schubert
Resolution: Duplicate Votes: 3
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Duplicate
duplicates SERVER-15086 Allow for efficient range queries ove... Closed
Operating System: ALL
Participants:

 Description   

Hi !

We have a collection which is roughly based on a schema similar to :

{
  _id : GUID
  StartTime: DateTime
  // Other Information
  Counters: [  
    {
         Name : string,
        // Others informations...
    }
   ]
}

The majority of our aggregate query starts with a $match phase which is always similar to:

db.collections.aggregate([
{
  $match : 
  {
      "Counters.Name" : 'Name',
      "StartTime": {$gte : ISODate(....), $lte: ISODate(....)}
  }
}
])

And I have the two following indexes on the collection :

{'StartTime: 1}
{'Counters.Name' : 1, 'StartTime' : 1}

I've noticed two different behavior depending on the filters that are applied to the date.

1) If I'm only using $gte: ISODate() the Counters.Name_1_StartTime_1 index gets used.
2) If I'm using the $gte and $lte the StartTime_1 index get used.

Logically, it should use the Counters.Name_1_StartTime_1 one as it would restrict much more the scope of documents.

I've also tried with an $elemMatch and can't get the bounded query to use the one containing the Counters.Name and StartDate



 Comments   
Comment by Kelsey Schubert [ 18/Nov/16 ]

Hi smarquis,

Thanks for providing the output, which identifies that Counters.Name_1_StartTime_1 is multikey. This explains the behavior you are observing. Since MongoDB 3.2 does not track which field is multikey it cannot intersect the greater than and less than bounds using the Counters.Name_1_StartTime_1 index. As you can see in the explain output the index bounds for StartTime are ["(true, new Date(1462924799000)]"].

This is the expected behavior in MongoDB 3.2 and below. For additional details, please see SERVER-15086, which allows efficient range queries over non-array fields in multikey indices in MongoDB 3.4 with WiredTiger.

Kind regards,
Thomas

Comment by Stephane Marquis [ 10/Nov/16 ]

Hi Thomas !

Sure,

For the whole aggregation pipeline it is :

{ 
    "waitedMS" : NumberLong(0), 
    "stages" : [
        {
            "$cursor" : {
                "query" : {
                    "Counters.Name" : "ClusterManager.Retrieve", 
                    "StartTime" : {
                        "$gte" : ISODate("2016-05-03T00:00:00.000+0000"), 
                        "$lte" : ISODate("2016-05-10T23:59:59.000+0000")
                    }
                }, 
                "queryPlanner" : {
                    "plannerVersion" : NumberInt(1), 
                    "namespace" : "telemetry.sessions", 
                    "indexFilterSet" : false, 
                    "parsedQuery" : {
                        "$and" : [
                            {
                                "Counters.Name" : {
                                    "$eq" : "ClusterManager.Retrieve"
                                }
                            }, 
                            {
                                "StartTime" : {
                                    "$lte" : ISODate("2016-05-10T23:59:59.000+0000")
                                }
                            }, 
                            {
                                "StartTime" : {
                                    "$gte" : ISODate("2016-05-03T00:00:00.000+0000")
                                }
                            }
                        ]
                    }, 
                    "winningPlan" : {
                        "stage" : "CACHED_PLAN", 
                        "inputStage" : {
                            "stage" : "FETCH", 
                            "filter" : {
                                "Counters.Name" : {
                                    "$eq" : "ClusterManager.Retrieve"
                                }
                            }, 
                            "inputStage" : {
                                "stage" : "IXSCAN", 
                                "keyPattern" : {
                                    "StartTime" : 1.0
                                }, 
                                "indexName" : "StartTime_1", 
                                "isMultiKey" : false, 
                                "isUnique" : false, 
                                "isSparse" : false, 
                                "isPartial" : false, 
                                "indexVersion" : NumberInt(1), 
                                "direction" : "forward", 
                                "indexBounds" : {
                                    "StartTime" : [
                                        "[new Date(1462233600000), new Date(1462924799000)]"
                                    ]
                                }
                            }
                        }
                    }, 
                    "rejectedPlans" : [
 
                    ]
                }
            }
        }, 
        {
            "$unwind" : {
                "path" : "$Counters"
            }
        }, 
        {
            "$match" : {
                "Counters.Name" : "ClusterManager.Retrieve", 
                "Counters.Size" : {
                    "$gt" : NumberInt(524288000)
                }, 
                "Counters.Time" : {
                    "$gt" : NumberInt(0)
                }
            }
        }, 
        {
            "$project" : {
                "Username" : true, 
                "Computer" : true, 
                "speed" : {
                    "$divide" : [
                        "$Counters.Size", 
                        "$Counters.Time"
                    ]
                }
            }
        }, 
        {
            "$group" : {
                "_id" : {
                    "Username" : "$Username", 
                    "Computer" : "$Computer"
                }, 
                "max_speed" : {
                    "$max" : "$speed"
                }
            }
        }, 
        {
            "$match" : {
                "max_speed" : {
                    "$gt" : NumberInt(11), 
                    "$lt" : NumberInt(12)
                }
            }
        }
    ], 
    "ok" : 1.0
}

For the find command :

{ 
    "queryPlanner" : {
        "plannerVersion" : NumberInt(1), 
        "namespace" : "telemetry.sessions", 
        "indexFilterSet" : false, 
        "parsedQuery" : {
            "$and" : [
                {
                    "Counters.Name" : {
                        "$eq" : "ClusterManager.Retrieve"
                    }
                }, 
                {
                    "StartTime" : {
                        "$lte" : ISODate("2016-05-10T23:59:59.000+0000")
                    }
                }, 
                {
                    "StartTime" : {
                        "$gte" : ISODate("2016-05-03T00:00:00.000+0000")
                    }
                }
            ]
        }, 
        "winningPlan" : {
            "stage" : "FETCH", 
            "filter" : {
                "Counters.Name" : {
                    "$eq" : "ClusterManager.Retrieve"
                }
            }, 
            "inputStage" : {
                "stage" : "IXSCAN", 
                "keyPattern" : {
                    "StartTime" : NumberInt(1)
                }, 
                "indexName" : "StartTime_1", 
                "isMultiKey" : false, 
                "isUnique" : false, 
                "isSparse" : false, 
                "isPartial" : false, 
                "indexVersion" : NumberInt(1), 
                "direction" : "forward", 
                "indexBounds" : {
                    "StartTime" : [
                        "[new Date(1462233600000), new Date(1462924799000)]"
                    ]
                }
            }
        }, 
        "rejectedPlans" : [
            {
                "stage" : "FETCH", 
                "filter" : {
                    "StartTime" : {
                        "$gte" : ISODate("2016-05-03T00:00:00.000+0000")
                    }
                }, 
                "inputStage" : {
                    "stage" : "IXSCAN", 
                    "keyPattern" : {
                        "Counters.Name" : NumberInt(1), 
                        "StartTime" : NumberInt(1)
                    }, 
                    "indexName" : "Counters.Name_1_StartTime_1", 
                    "isMultiKey" : true, 
                    "isUnique" : false, 
                    "isSparse" : false, 
                    "isPartial" : false, 
                    "indexVersion" : NumberInt(1), 
                    "direction" : "forward", 
                    "indexBounds" : {
                        "Counters.Name" : [
                            "[\"ClusterManager.Retrieve\", \"ClusterManager.Retrieve\"]"
                        ], 
                        "StartTime" : [
                            "(true, new Date(1462924799000)]"
                        ]
                    }
                }
            }
        ]
    }, 
    "executionStats" : {
        "executionSuccess" : true, 
        "nReturned" : NumberInt(43683), 
        "executionTimeMillis" : NumberInt(7107), 
        "totalKeysExamined" : NumberInt(308232), 
        "totalDocsExamined" : NumberInt(308232), 
        "executionStages" : {
            "stage" : "FETCH", 
            "filter" : {
                "Counters.Name" : {
                    "$eq" : "ClusterManager.Retrieve"
                }
            }, 
            "nReturned" : NumberInt(43683), 
            "executionTimeMillisEstimate" : NumberInt(6660), 
            "works" : NumberInt(308233), 
            "advanced" : NumberInt(43683), 
            "needTime" : NumberInt(264549), 
            "needYield" : NumberInt(0), 
            "saveState" : NumberInt(2413), 
            "restoreState" : NumberInt(2413), 
            "isEOF" : NumberInt(1), 
            "invalidates" : NumberInt(0), 
            "docsExamined" : NumberInt(308232), 
            "alreadyHasObj" : NumberInt(0), 
            "inputStage" : {
                "stage" : "IXSCAN", 
                "nReturned" : NumberInt(308232), 
                "executionTimeMillisEstimate" : NumberInt(170), 
                "works" : NumberInt(308233), 
                "advanced" : NumberInt(308232), 
                "needTime" : NumberInt(0), 
                "needYield" : NumberInt(0), 
                "saveState" : NumberInt(2413), 
                "restoreState" : NumberInt(2413), 
                "isEOF" : NumberInt(1), 
                "invalidates" : NumberInt(0), 
                "keyPattern" : {
                    "StartTime" : NumberInt(1)
                }, 
                "indexName" : "StartTime_1", 
                "isMultiKey" : false, 
                "isUnique" : false, 
                "isSparse" : false, 
                "isPartial" : false, 
                "indexVersion" : NumberInt(1), 
                "direction" : "forward", 
                "indexBounds" : {
                    "StartTime" : [
                        "[new Date(1462233600000), new Date(1462924799000)]"
                    ]
                }, 
                "keysExamined" : NumberInt(308232), 
                "dupsTested" : NumberInt(0), 
                "dupsDropped" : NumberInt(0), 
                "seenInvalidated" : NumberInt(0)
            }
        }, 
        "allPlansExecution" : [
            {
                "nReturned" : NumberInt(0), 
                "executionTimeMillisEstimate" : NumberInt(20), 
                "totalKeysExamined" : NumberInt(578), 
                "totalDocsExamined" : NumberInt(578), 
                "executionStages" : {
                    "stage" : "FETCH", 
                    "filter" : {
                        "StartTime" : {
                            "$gte" : ISODate("2016-05-03T00:00:00.000+0000")
                        }
                    }, 
                    "nReturned" : NumberInt(0), 
                    "executionTimeMillisEstimate" : NumberInt(20), 
                    "works" : NumberInt(578), 
                    "advanced" : NumberInt(0), 
                    "needTime" : NumberInt(578), 
                    "needYield" : NumberInt(0), 
                    "saveState" : NumberInt(2413), 
                    "restoreState" : NumberInt(2413), 
                    "isEOF" : NumberInt(0), 
                    "invalidates" : NumberInt(0), 
                    "docsExamined" : NumberInt(578), 
                    "alreadyHasObj" : NumberInt(0), 
                    "inputStage" : {
                        "stage" : "IXSCAN", 
                        "nReturned" : NumberInt(578), 
                        "executionTimeMillisEstimate" : NumberInt(0), 
                        "works" : NumberInt(578), 
                        "advanced" : NumberInt(578), 
                        "needTime" : NumberInt(0), 
                        "needYield" : NumberInt(0), 
                        "saveState" : NumberInt(2413), 
                        "restoreState" : NumberInt(2413), 
                        "isEOF" : NumberInt(0), 
                        "invalidates" : NumberInt(0), 
                        "keyPattern" : {
                            "Counters.Name" : NumberInt(1), 
                            "StartTime" : NumberInt(1)
                        }, 
                        "indexName" : "Counters.Name_1_StartTime_1", 
                        "isMultiKey" : true, 
                        "isUnique" : false, 
                        "isSparse" : false, 
                        "isPartial" : false, 
                        "indexVersion" : NumberInt(1), 
                        "direction" : "forward", 
                        "indexBounds" : {
                            "Counters.Name" : [
                                "[\"ClusterManager.Retrieve\", \"ClusterManager.Retrieve\"]"
                            ], 
                            "StartTime" : [
                                "(true, new Date(1462924799000)]"
                            ]
                        }, 
                        "keysExamined" : NumberInt(578), 
                        "dupsTested" : NumberInt(578), 
                        "dupsDropped" : NumberInt(0), 
                        "seenInvalidated" : NumberInt(0)
                    }
                }
            }, 
            {
                "nReturned" : NumberInt(101), 
                "executionTimeMillisEstimate" : NumberInt(40), 
                "totalKeysExamined" : NumberInt(578), 
                "totalDocsExamined" : NumberInt(578), 
                "executionStages" : {
                    "stage" : "FETCH", 
                    "filter" : {
                        "Counters.Name" : {
                            "$eq" : "ClusterManager.Retrieve"
                        }
                    }, 
                    "nReturned" : NumberInt(101), 
                    "executionTimeMillisEstimate" : NumberInt(40), 
                    "works" : NumberInt(578), 
                    "advanced" : NumberInt(101), 
                    "needTime" : NumberInt(477), 
                    "needYield" : NumberInt(0), 
                    "saveState" : NumberInt(9), 
                    "restoreState" : NumberInt(9), 
                    "isEOF" : NumberInt(0), 
                    "invalidates" : NumberInt(0), 
                    "docsExamined" : NumberInt(578), 
                    "alreadyHasObj" : NumberInt(0), 
                    "inputStage" : {
                        "stage" : "IXSCAN", 
                        "nReturned" : NumberInt(578), 
                        "executionTimeMillisEstimate" : NumberInt(0), 
                        "works" : NumberInt(578), 
                        "advanced" : NumberInt(578), 
                        "needTime" : NumberInt(0), 
                        "needYield" : NumberInt(0), 
                        "saveState" : NumberInt(9), 
                        "restoreState" : NumberInt(9), 
                        "isEOF" : NumberInt(0), 
                        "invalidates" : NumberInt(0), 
                        "keyPattern" : {
                            "StartTime" : NumberInt(1)
                        }, 
                        "indexName" : "StartTime_1", 
                        "isMultiKey" : false, 
                        "isUnique" : false, 
                        "isSparse" : false, 
                        "isPartial" : false, 
                        "indexVersion" : NumberInt(1), 
                        "direction" : "forward", 
                        "indexBounds" : {
                            "StartTime" : [
                                "[new Date(1462233600000), new Date(1462924799000)]"
                            ]
                        }, 
                        "keysExamined" : NumberInt(578), 
                        "dupsTested" : NumberInt(0), 
                        "dupsDropped" : NumberInt(0), 
                        "seenInvalidated" : NumberInt(0)
                    }
                }
            }
        ]
    }, 
    "serverInfo" : {
        "host" : "telemetry-mongodb-3", 
        "port" : NumberInt(27017), 
        "version" : "3.2.10", 
        "gitVersion" : "79d9b3ab5ce20f51c272b4411202710a082d0317"
    }, 
    "ok" : NumberInt(1)
}

Let me know if you need anything else

Comment by Kelsey Schubert [ 10/Nov/16 ]

Hi smarquis,

Thank you for reporting this behavior. Would you please clarify what other aggregation stages are included in the pipeline? Can you provide the explain output for one of your aggregations?

Would you please provide the output of the following command?

db.collections.find({"Counters.Name" : 'Name', "StartTime": {$gte : ISODate(....), $lte: ISODate(....)} }).explain(true)

Thanks again,
Thomas

Generated at Thu Feb 08 04:13:46 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.