[SERVER-24312] Mongo Query Taking Lot of Time Selecting Index Created: 30/May/16  Updated: 08/Dec/17  Resolved: 02/Jun/16

Status: Closed
Project: Core Server
Component/s: Querying
Affects Version/s: 3.0.4
Fix Version/s: None

Type: Bug Priority: Major - P3
Reporter: arpit wanchoo Assignee: David Storch
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Duplicate
duplicates DRIVERS-303 Mongo Query Taking Lot of Time Select... Closed
Related
related to SERVER-31078 Query planning is very slow during mu... Backlog
is related to SERVER-13211 Optimal index not chosen for query pl... Closed
is related to SERVER-24396 Progressive elimination of candidate ... Backlog
Operating System: ALL
Participants:

 Description   

There are two issues happening :
First Issue : Query taking lot of time in deciding which index to use.
Eg: If we run an query X , then it takes a lot of time (more than 5 minutes) )and on checking the log it was using a index Y.
Now if I run the query X with index hint Y, it runs in couple of seconds.
That means the time it was taking is not in query execution but before that. Very strange

Second Issue : In some cases it is not selecting the right index also. If my query is on fields A,B,C and I have indexes A and A_B_C created, then it is choosing the index A instead if A_B_C



 Comments   
Comment by David Storch [ 16/Aug/16 ]

Hi arpit@limeroad.com,

1. The problem is not getting resolved with new version either 3.2.6

That's good to know, thanks for checking on this.

2. With hint we had already tried and the query work fine i.e less than a second. As you can see the query fields are : "order_commit_time" , "suborders.state" , "suborders.transporter" and there is a index comprising exactly these 3 fields. I fail to understand why is the optimser looks for other indexes when the queries fields exactly matches an index. Never seen such behavior on mysql

This is a good point. We have a couple of open SERVER tickets expressing ideas of this nature. In particular, see the discussion on SERVER-13211. The idea here would be to implement some heuristics which prune the set of indices under consideration via planning-time analysis of the query predicate. The exact problem described in SERVER-13211 is a bit different, but I think your problem would benefit from the same code fix.

3. reducing the value internalQueryPlanEvaluationCollFraction to 0.01 did made the same query run faster and further reducing to 0.0001 made it very fast but we are not sure how this can impact other queries. And what is the safe value for this ?

You are in uncharted territory if you change this value, so I can't really say what is "safe" versus "unsafe". The detrimental consequences of messing with this value would be bad plan selection for some queries. If you have a QA environment or QA workload where you can test this change, I would recommend doing so and seeing what the perf looks like. If you don't observe bad plan selection in testing and you are willing to accept the risk that comes with turning undocumented database knobs, then I think this is actually a pretty good solution.

4. exactly same query with different value for "transporter" works fine without hint in 100ms . Query plan for that is as below

MongoDB's empirical query optimizer will continue to evaluate candidate plans until a candidate has either generated all results, or has generated its first batch worth of results. In the explain you posted for a different value of transporter, one of the candidate plans very quickly generated its first batch of results (at which point all of the rejected plans could be thrown out). It appears that the winning plan simply had a much more selective index scan at the beginning of the trial period than any of the candidate plans in the previous, problematic explain output.

Finally, note that we have opened SERVER-24396 to track an improvement which may help the performance of your query. Please watch and vote for this ticket.

Best,
Dave

Comment by arpit wanchoo [ 03/Jun/16 ]

Hi David

Few points to be noted :
1. The problem is not getting resolved with new version either 3.2.6
2. With hint we had already tried and the query work fine i.e less than a second. As you can see the query fields are : "order_commit_time" , "suborders.state" , "suborders.transporter" and there is a index comprising exactly these 3 fields. I fail to understand why is the optimser looks for other indexes when the queries fields exactly matches an index. Never seen such behavior on mysql
3. reducing the value internalQueryPlanEvaluationCollFraction to 0.01 did made the same query run faster and further reducing to 0.0001 made it very fast but we are not sure how this can impact other queries. And what is the safe value for this ?
4. exactly same query with different value for "transporter" works fine without hint in 100ms . Query plan for that is as below

Please check for more details

 
rs0:SECONDARY> db.orders.find({ order_commit_time: { $gte: new Date(1455369404000) }, suborders: { $elemMatch: { state: {  $in: [ "RETURNED_TO_ORIGIN", "ORDER_DELIVERED", "ORDER_CANCELLED" ] }, transporter: "delhivery" } } }).explain("allPlansExecution")
{
	"queryPlanner" : {
		"plannerVersion" : 1,
		"namespace" : "userDB.orders",
		"indexFilterSet" : false,
		"parsedQuery" : {
			"$and" : [
				{
					"suborders" : {
						"$elemMatch" : {
							"$and" : [
								{
									"transporter" : {
										"$eq" : "delhivery"
									}
								},
								{
									"state" : {
										"$in" : [
											"ORDER_CANCELLED",
											"ORDER_DELIVERED",
											"RETURNED_TO_ORIGIN"
										]
									}
								}
							]
						}
					}
				},
				{
					"order_commit_time" : {
						"$gte" : ISODate("2016-02-13T13:16:44Z")
					}
				}
			]
		},
		"winningPlan" : {
			"stage" : "KEEP_MUTATIONS",
			"inputStage" : {
				"stage" : "FETCH",
				"filter" : {
					"suborders" : {
						"$elemMatch" : {
							"$and" : [
								{
									"transporter" : {
										"$eq" : "delhivery"
									}
								},
								{
									"state" : {
										"$in" : [
											"ORDER_CANCELLED",
											"ORDER_DELIVERED",
											"RETURNED_TO_ORIGIN"
										]
									}
								}
							]
						}
					}
				},
				"inputStage" : {
					"stage" : "IXSCAN",
					"keyPattern" : {
						"order_commit_time" : 1
					},
					"indexName" : "order_commit_time_1",
					"isMultiKey" : false,
					"direction" : "forward",
					"indexBounds" : {
						"order_commit_time" : [
							"[new Date(1455369404000), new Date(9223372036854775807)]"
						]
					}
				}
			}
		},
		"rejectedPlans" : [
			{
				"stage" : "KEEP_MUTATIONS",
				"inputStage" : {
					"stage" : "FETCH",
					"filter" : {
						"suborders" : {
							"$elemMatch" : {
								"$and" : [
									{
										"transporter" : {
											"$eq" : "delhivery"
										}
									},
									{
										"state" : {
											"$in" : [
												"ORDER_CANCELLED",
												"ORDER_DELIVERED",
												"RETURNED_TO_ORIGIN"
											]
										}
									}
								]
							}
						}
					},
					"inputStage" : {
						"stage" : "IXSCAN",
						"keyPattern" : {
							"order_commit_time" : 1,
							"suborders.transporter" : 1,
							"suborders.state" : 1
						},
						"indexName" : "order_commit_time_1_suborders.transporter_1_suborders.state_1",
						"isMultiKey" : true,
						"direction" : "forward",
						"indexBounds" : {
							"order_commit_time" : [
								"[new Date(1455369404000), new Date(9223372036854775807)]"
							],
							"suborders.transporter" : [
								"[\"delhivery\", \"delhivery\"]"
							],
							"suborders.state" : [
								"[\"ORDER_CANCELLED\", \"ORDER_CANCELLED\"]",
								"[\"ORDER_DELIVERED\", \"ORDER_DELIVERED\"]",
								"[\"RETURNED_TO_ORIGIN\", \"RETURNED_TO_ORIGIN\"]"
							]
						}
					}
				}
			},
			{
				"stage" : "KEEP_MUTATIONS",
				"inputStage" : {
					"stage" : "FETCH",
					"filter" : {
						"suborders" : {
							"$elemMatch" : {
								"$and" : [
									{
										"state" : {
											"$in" : [
												"ORDER_CANCELLED",
												"ORDER_DELIVERED",
												"RETURNED_TO_ORIGIN"
											]
										}
									},
									{
										"transporter" : {
											"$eq" : "delhivery"
										}
									}
								]
							}
						}
					},
					"inputStage" : {
						"stage" : "IXSCAN",
						"keyPattern" : {
							"order_commit_time" : 1,
							"suborders.state" : 1,
							"suborders.warehouse_id" : 1
						},
						"indexName" : "order_commit_time_1_suborders.state_1_suborders.warehouse_id_1",
						"isMultiKey" : true,
						"direction" : "forward",
						"indexBounds" : {
							"order_commit_time" : [
								"[new Date(1455369404000), new Date(9223372036854775807)]"
							],
							"suborders.state" : [
								"[\"ORDER_CANCELLED\", \"ORDER_CANCELLED\"]",
								"[\"ORDER_DELIVERED\", \"ORDER_DELIVERED\"]",
								"[\"RETURNED_TO_ORIGIN\", \"RETURNED_TO_ORIGIN\"]"
							],
							"suborders.warehouse_id" : [
								"[MinKey, MaxKey]"
							]
						}
					}
				}
			},
			{
				"stage" : "KEEP_MUTATIONS",
				"inputStage" : {
					"stage" : "FETCH",
					"filter" : {
						"suborders" : {
							"$elemMatch" : {
								"$and" : [
									{
										"transporter" : {
											"$eq" : "delhivery"
										}
									},
									{
										"state" : {
											"$in" : [
												"ORDER_CANCELLED",
												"ORDER_DELIVERED",
												"RETURNED_TO_ORIGIN"
											]
										}
									}
								]
							}
						}
					},
					"inputStage" : {
						"stage" : "IXSCAN",
						"keyPattern" : {
							"order_commit_time" : 1,
							"suborders.transporter" : 1,
							"suborders.warehouse_id" : 1,
							"suborders.state" : 1
						},
						"indexName" : "order_commit_time_1_suborders.transporter_1_suborders.warehouse_id_1_suborders.state_1",
						"isMultiKey" : true,
						"direction" : "forward",
						"indexBounds" : {
							"order_commit_time" : [
								"[new Date(1455369404000), new Date(9223372036854775807)]"
							],
							"suborders.transporter" : [
								"[\"delhivery\", \"delhivery\"]"
							],
							"suborders.warehouse_id" : [
								"[MinKey, MaxKey]"
							],
							"suborders.state" : [
								"[\"ORDER_CANCELLED\", \"ORDER_CANCELLED\"]",
								"[\"ORDER_DELIVERED\", \"ORDER_DELIVERED\"]",
								"[\"RETURNED_TO_ORIGIN\", \"RETURNED_TO_ORIGIN\"]"
							]
						}
					}
				}
			},
			{
				"stage" : "KEEP_MUTATIONS",
				"inputStage" : {
					"stage" : "FETCH",
					"filter" : {
						"$and" : [
							{
								"suborders" : {
									"$elemMatch" : {
										"$and" : [
											{
												"state" : {
													"$in" : [
														"ORDER_CANCELLED",
														"ORDER_DELIVERED",
														"RETURNED_TO_ORIGIN"
													]
												}
											},
											{
												"transporter" : {
													"$eq" : "delhivery"
												}
											}
										]
									}
								}
							},
							{
								"order_commit_time" : {
									"$gte" : ISODate("2016-02-13T13:16:44Z")
								}
							}
						]
					},
					"inputStage" : {
						"stage" : "IXSCAN",
						"keyPattern" : {
							"suborders.state" : 1,
							"suborders.timeline.current_state_time" : 1
						},
						"indexName" : "suborders.state_1_suborders.timeline.current_state_time_1",
						"isMultiKey" : true,
						"direction" : "forward",
						"indexBounds" : {
							"suborders.state" : [
								"[\"ORDER_CANCELLED\", \"ORDER_CANCELLED\"]",
								"[\"ORDER_DELIVERED\", \"ORDER_DELIVERED\"]",
								"[\"RETURNED_TO_ORIGIN\", \"RETURNED_TO_ORIGIN\"]"
							],
							"suborders.timeline.current_state_time" : [
								"[MinKey, MaxKey]"
							]
						}
					}
				}
			},
			{
				"stage" : "KEEP_MUTATIONS",
				"inputStage" : {
					"stage" : "FETCH",
					"filter" : {
						"$and" : [
							{
								"suborders" : {
									"$elemMatch" : {
										"$and" : [
											{
												"state" : {
													"$in" : [
														"ORDER_CANCELLED",
														"ORDER_DELIVERED",
														"RETURNED_TO_ORIGIN"
													]
												}
											},
											{
												"transporter" : {
													"$eq" : "delhivery"
												}
											}
										]
									}
								}
							},
							{
								"order_commit_time" : {
									"$gte" : ISODate("2016-02-13T13:16:44Z")
								}
							}
						]
					},
					"inputStage" : {
						"stage" : "IXSCAN",
						"keyPattern" : {
							"suborders.state" : 1
						},
						"indexName" : "suborders.state_1",
						"isMultiKey" : true,
						"direction" : "forward",
						"indexBounds" : {
							"suborders.state" : [
								"[\"ORDER_CANCELLED\", \"ORDER_CANCELLED\"]",
								"[\"ORDER_DELIVERED\", \"ORDER_DELIVERED\"]",
								"[\"RETURNED_TO_ORIGIN\", \"RETURNED_TO_ORIGIN\"]"
							]
						}
					}
				}
			}
		]
	},
	"executionStats" : {
		"executionSuccess" : true,
		"nReturned" : 117692,
		"executionTimeMillis" : 5583,
		"totalKeysExamined" : 669498,
		"totalDocsExamined" : 669498,
		"executionStages" : {
			"stage" : "KEEP_MUTATIONS",
			"nReturned" : 117692,
			"executionTimeMillisEstimate" : 5257,
			"works" : 669499,
			"advanced" : 117692,
			"needTime" : 551806,
			"needFetch" : 0,
			"saveState" : 5239,
			"restoreState" : 5239,
			"isEOF" : 1,
			"invalidates" : 1,
			"inputStage" : {
				"stage" : "FETCH",
				"filter" : {
					"suborders" : {
						"$elemMatch" : {
							"$and" : [
								{
									"transporter" : {
										"$eq" : "delhivery"
									}
								},
								{
									"state" : {
										"$in" : [
											"ORDER_CANCELLED",
											"ORDER_DELIVERED",
											"RETURNED_TO_ORIGIN"
										]
									}
								}
							]
						}
					}
				},
				"nReturned" : 117692,
				"executionTimeMillisEstimate" : 5257,
				"works" : 669499,
				"advanced" : 117692,
				"needTime" : 551806,
				"needFetch" : 0,
				"saveState" : 5239,
				"restoreState" : 5239,
				"isEOF" : 1,
				"invalidates" : 1,
				"docsExamined" : 669498,
				"alreadyHasObj" : 0,
				"inputStage" : {
					"stage" : "IXSCAN",
					"nReturned" : 669498,
					"executionTimeMillisEstimate" : 420,
					"works" : 669498,
					"advanced" : 669498,
					"needTime" : 0,
					"needFetch" : 0,
					"saveState" : 5239,
					"restoreState" : 5239,
					"isEOF" : 1,
					"invalidates" : 1,
					"keyPattern" : {
						"order_commit_time" : 1
					},
					"indexName" : "order_commit_time_1",
					"isMultiKey" : false,
					"direction" : "forward",
					"indexBounds" : {
						"order_commit_time" : [
							"[new Date(1455369404000), new Date(9223372036854775807)]"
						]
					},
					"keysExamined" : 669498,
					"dupsTested" : 0,
					"dupsDropped" : 0,
					"seenInvalidated" : 0,
					"matchTested" : 0
				}
			}
		},
		"allPlansExecution" : [
			{
				"nReturned" : 91,
				"executionTimeMillisEstimate" : 0,
				"totalKeysExamined" : 220,
				"totalDocsExamined" : 91,
				"executionStages" : {
					"stage" : "KEEP_MUTATIONS",
					"nReturned" : 91,
					"executionTimeMillisEstimate" : 0,
					"works" : 220,
					"advanced" : 91,
					"needTime" : 129,
					"needFetch" : 0,
					"saveState" : 5239,
					"restoreState" : 5239,
					"isEOF" : 0,
					"invalidates" : 0,
					"inputStage" : {
						"stage" : "FETCH",
						"filter" : {
							"suborders" : {
								"$elemMatch" : {
									"$and" : [
										{
											"transporter" : {
												"$eq" : "delhivery"
											}
										},
										{
											"state" : {
												"$in" : [
													"ORDER_CANCELLED",
													"ORDER_DELIVERED",
													"RETURNED_TO_ORIGIN"
												]
											}
										}
									]
								}
							}
						},
						"nReturned" : 91,
						"executionTimeMillisEstimate" : 0,
						"works" : 220,
						"advanced" : 91,
						"needTime" : 129,
						"needFetch" : 0,
						"saveState" : 5239,
						"restoreState" : 5239,
						"isEOF" : 0,
						"invalidates" : 0,
						"docsExamined" : 91,
						"alreadyHasObj" : 0,
						"inputStage" : {
							"stage" : "IXSCAN",
							"nReturned" : 91,
							"executionTimeMillisEstimate" : 0,
							"works" : 220,
							"advanced" : 91,
							"needTime" : 129,
							"needFetch" : 0,
							"saveState" : 5239,
							"restoreState" : 5239,
							"isEOF" : 0,
							"invalidates" : 0,
							"keyPattern" : {
								"order_commit_time" : 1,
								"suborders.transporter" : 1,
								"suborders.state" : 1
							},
							"indexName" : "order_commit_time_1_suborders.transporter_1_suborders.state_1",
							"isMultiKey" : true,
							"direction" : "forward",
							"indexBounds" : {
								"order_commit_time" : [
									"[new Date(1455369404000), new Date(9223372036854775807)]"
								],
								"suborders.transporter" : [
									"[\"delhivery\", \"delhivery\"]"
								],
								"suborders.state" : [
									"[\"ORDER_CANCELLED\", \"ORDER_CANCELLED\"]",
									"[\"ORDER_DELIVERED\", \"ORDER_DELIVERED\"]",
									"[\"RETURNED_TO_ORIGIN\", \"RETURNED_TO_ORIGIN\"]"
								]
							},
							"keysExamined" : 220,
							"dupsTested" : 92,
							"dupsDropped" : 1,
							"seenInvalidated" : 0,
							"matchTested" : 0
						}
					}
				}
			},
			{
				"nReturned" : 71,
				"executionTimeMillisEstimate" : 0,
				"totalKeysExamined" : 220,
				"totalDocsExamined" : 155,
				"executionStages" : {
					"stage" : "KEEP_MUTATIONS",
					"nReturned" : 71,
					"executionTimeMillisEstimate" : 0,
					"works" : 220,
					"advanced" : 71,
					"needTime" : 149,
					"needFetch" : 0,
					"saveState" : 5239,
					"restoreState" : 5239,
					"isEOF" : 0,
					"invalidates" : 0,
					"inputStage" : {
						"stage" : "FETCH",
						"filter" : {
							"suborders" : {
								"$elemMatch" : {
									"$and" : [
										{
											"state" : {
												"$in" : [
													"ORDER_CANCELLED",
													"ORDER_DELIVERED",
													"RETURNED_TO_ORIGIN"
												]
											}
										},
										{
											"transporter" : {
												"$eq" : "delhivery"
											}
										}
									]
								}
							}
						},
						"nReturned" : 71,
						"executionTimeMillisEstimate" : 0,
						"works" : 220,
						"advanced" : 71,
						"needTime" : 149,
						"needFetch" : 0,
						"saveState" : 5239,
						"restoreState" : 5239,
						"isEOF" : 0,
						"invalidates" : 0,
						"docsExamined" : 155,
						"alreadyHasObj" : 0,
						"inputStage" : {
							"stage" : "IXSCAN",
							"nReturned" : 155,
							"executionTimeMillisEstimate" : 0,
							"works" : 220,
							"advanced" : 155,
							"needTime" : 65,
							"needFetch" : 0,
							"saveState" : 5239,
							"restoreState" : 5239,
							"isEOF" : 0,
							"invalidates" : 0,
							"keyPattern" : {
								"order_commit_time" : 1,
								"suborders.state" : 1,
								"suborders.warehouse_id" : 1
							},
							"indexName" : "order_commit_time_1_suborders.state_1_suborders.warehouse_id_1",
							"isMultiKey" : true,
							"direction" : "forward",
							"indexBounds" : {
								"order_commit_time" : [
									"[new Date(1455369404000), new Date(9223372036854775807)]"
								],
								"suborders.state" : [
									"[\"ORDER_CANCELLED\", \"ORDER_CANCELLED\"]",
									"[\"ORDER_DELIVERED\", \"ORDER_DELIVERED\"]",
									"[\"RETURNED_TO_ORIGIN\", \"RETURNED_TO_ORIGIN\"]"
								],
								"suborders.warehouse_id" : [
									"[MinKey, MaxKey]"
								]
							},
							"keysExamined" : 220,
							"dupsTested" : 220,
							"dupsDropped" : 65,
							"seenInvalidated" : 0,
							"matchTested" : 0
						}
					}
				}
			},
			{
				"nReturned" : 78,
				"executionTimeMillisEstimate" : 0,
				"totalKeysExamined" : 220,
				"totalDocsExamined" : 78,
				"executionStages" : {
					"stage" : "KEEP_MUTATIONS",
					"nReturned" : 78,
					"executionTimeMillisEstimate" : 0,
					"works" : 220,
					"advanced" : 78,
					"needTime" : 142,
					"needFetch" : 0,
					"saveState" : 5239,
					"restoreState" : 5239,
					"isEOF" : 0,
					"invalidates" : 0,
					"inputStage" : {
						"stage" : "FETCH",
						"filter" : {
							"suborders" : {
								"$elemMatch" : {
									"$and" : [
										{
											"transporter" : {
												"$eq" : "delhivery"
											}
										},
										{
											"state" : {
												"$in" : [
													"ORDER_CANCELLED",
													"ORDER_DELIVERED",
													"RETURNED_TO_ORIGIN"
												]
											}
										}
									]
								}
							}
						},
						"nReturned" : 78,
						"executionTimeMillisEstimate" : 0,
						"works" : 220,
						"advanced" : 78,
						"needTime" : 142,
						"needFetch" : 0,
						"saveState" : 5239,
						"restoreState" : 5239,
						"isEOF" : 0,
						"invalidates" : 0,
						"docsExamined" : 78,
						"alreadyHasObj" : 0,
						"inputStage" : {
							"stage" : "IXSCAN",
							"nReturned" : 78,
							"executionTimeMillisEstimate" : 0,
							"works" : 220,
							"advanced" : 78,
							"needTime" : 142,
							"needFetch" : 0,
							"saveState" : 5239,
							"restoreState" : 5239,
							"isEOF" : 0,
							"invalidates" : 0,
							"keyPattern" : {
								"order_commit_time" : 1,
								"suborders.transporter" : 1,
								"suborders.warehouse_id" : 1,
								"suborders.state" : 1
							},
							"indexName" : "order_commit_time_1_suborders.transporter_1_suborders.warehouse_id_1_suborders.state_1",
							"isMultiKey" : true,
							"direction" : "forward",
							"indexBounds" : {
								"order_commit_time" : [
									"[new Date(1455369404000), new Date(9223372036854775807)]"
								],
								"suborders.transporter" : [
									"[\"delhivery\", \"delhivery\"]"
								],
								"suborders.warehouse_id" : [
									"[MinKey, MaxKey]"
								],
								"suborders.state" : [
									"[\"ORDER_CANCELLED\", \"ORDER_CANCELLED\"]",
									"[\"ORDER_DELIVERED\", \"ORDER_DELIVERED\"]",
									"[\"RETURNED_TO_ORIGIN\", \"RETURNED_TO_ORIGIN\"]"
								]
							},
							"keysExamined" : 220,
							"dupsTested" : 115,
							"dupsDropped" : 37,
							"seenInvalidated" : 0,
							"matchTested" : 0
						}
					}
				}
			},
			{
				"nReturned" : 0,
				"executionTimeMillisEstimate" : 0,
				"totalKeysExamined" : 220,
				"totalDocsExamined" : 214,
				"executionStages" : {
					"stage" : "KEEP_MUTATIONS",
					"nReturned" : 0,
					"executionTimeMillisEstimate" : 0,
					"works" : 220,
					"advanced" : 0,
					"needTime" : 220,
					"needFetch" : 0,
					"saveState" : 5239,
					"restoreState" : 5239,
					"isEOF" : 0,
					"invalidates" : 0,
					"inputStage" : {
						"stage" : "FETCH",
						"filter" : {
							"$and" : [
								{
									"suborders" : {
										"$elemMatch" : {
											"$and" : [
												{
													"state" : {
														"$in" : [
															"ORDER_CANCELLED",
															"ORDER_DELIVERED",
															"RETURNED_TO_ORIGIN"
														]
													}
												},
												{
													"transporter" : {
														"$eq" : "delhivery"
													}
												}
											]
										}
									}
								},
								{
									"order_commit_time" : {
										"$gte" : ISODate("2016-02-13T13:16:44Z")
									}
								}
							]
						},
						"nReturned" : 0,
						"executionTimeMillisEstimate" : 0,
						"works" : 220,
						"advanced" : 0,
						"needTime" : 220,
						"needFetch" : 0,
						"saveState" : 5239,
						"restoreState" : 5239,
						"isEOF" : 0,
						"invalidates" : 0,
						"docsExamined" : 214,
						"alreadyHasObj" : 0,
						"inputStage" : {
							"stage" : "IXSCAN",
							"nReturned" : 214,
							"executionTimeMillisEstimate" : 0,
							"works" : 220,
							"advanced" : 214,
							"needTime" : 6,
							"needFetch" : 0,
							"saveState" : 5239,
							"restoreState" : 5239,
							"isEOF" : 0,
							"invalidates" : 0,
							"keyPattern" : {
								"suborders.state" : 1,
								"suborders.timeline.current_state_time" : 1
							},
							"indexName" : "suborders.state_1_suborders.timeline.current_state_time_1",
							"isMultiKey" : true,
							"direction" : "forward",
							"indexBounds" : {
								"suborders.state" : [
									"[\"ORDER_CANCELLED\", \"ORDER_CANCELLED\"]",
									"[\"ORDER_DELIVERED\", \"ORDER_DELIVERED\"]",
									"[\"RETURNED_TO_ORIGIN\", \"RETURNED_TO_ORIGIN\"]"
								],
								"suborders.timeline.current_state_time" : [
									"[MinKey, MaxKey]"
								]
							},
							"keysExamined" : 220,
							"dupsTested" : 220,
							"dupsDropped" : 6,
							"seenInvalidated" : 0,
							"matchTested" : 0
						}
					}
				}
			},
			{
				"nReturned" : 0,
				"executionTimeMillisEstimate" : 10,
				"totalKeysExamined" : 220,
				"totalDocsExamined" : 220,
				"executionStages" : {
					"stage" : "KEEP_MUTATIONS",
					"nReturned" : 0,
					"executionTimeMillisEstimate" : 10,
					"works" : 220,
					"advanced" : 0,
					"needTime" : 220,
					"needFetch" : 0,
					"saveState" : 5239,
					"restoreState" : 5239,
					"isEOF" : 0,
					"invalidates" : 0,
					"inputStage" : {
						"stage" : "FETCH",
						"filter" : {
							"$and" : [
								{
									"suborders" : {
										"$elemMatch" : {
											"$and" : [
												{
													"state" : {
														"$in" : [
															"ORDER_CANCELLED",
															"ORDER_DELIVERED",
															"RETURNED_TO_ORIGIN"
														]
													}
												},
												{
													"transporter" : {
														"$eq" : "delhivery"
													}
												}
											]
										}
									}
								},
								{
									"order_commit_time" : {
										"$gte" : ISODate("2016-02-13T13:16:44Z")
									}
								}
							]
						},
						"nReturned" : 0,
						"executionTimeMillisEstimate" : 10,
						"works" : 220,
						"advanced" : 0,
						"needTime" : 220,
						"needFetch" : 0,
						"saveState" : 5239,
						"restoreState" : 5239,
						"isEOF" : 0,
						"invalidates" : 0,
						"docsExamined" : 220,
						"alreadyHasObj" : 0,
						"inputStage" : {
							"stage" : "IXSCAN",
							"nReturned" : 220,
							"executionTimeMillisEstimate" : 0,
							"works" : 220,
							"advanced" : 220,
							"needTime" : 0,
							"needFetch" : 0,
							"saveState" : 5239,
							"restoreState" : 5239,
							"isEOF" : 0,
							"invalidates" : 0,
							"keyPattern" : {
								"suborders.state" : 1
							},
							"indexName" : "suborders.state_1",
							"isMultiKey" : true,
							"direction" : "forward",
							"indexBounds" : {
								"suborders.state" : [
									"[\"ORDER_CANCELLED\", \"ORDER_CANCELLED\"]",
									"[\"ORDER_DELIVERED\", \"ORDER_DELIVERED\"]",
									"[\"RETURNED_TO_ORIGIN\", \"RETURNED_TO_ORIGIN\"]"
								]
							},
							"keysExamined" : 220,
							"dupsTested" : 220,
							"dupsDropped" : 0,
							"seenInvalidated" : 0,
							"matchTested" : 0
						}
					}
				}
			},
			{
				"nReturned" : 101,
				"executionTimeMillisEstimate" : 0,
				"totalKeysExamined" : 220,
				"totalDocsExamined" : 220,
				"executionStages" : {
					"stage" : "KEEP_MUTATIONS",
					"nReturned" : 101,
					"executionTimeMillisEstimate" : 0,
					"works" : 220,
					"advanced" : 101,
					"needTime" : 119,
					"needFetch" : 0,
					"saveState" : 10,
					"restoreState" : 10,
					"isEOF" : 0,
					"invalidates" : 0,
					"inputStage" : {
						"stage" : "FETCH",
						"filter" : {
							"suborders" : {
								"$elemMatch" : {
									"$and" : [
										{
											"transporter" : {
												"$eq" : "delhivery"
											}
										},
										{
											"state" : {
												"$in" : [
													"ORDER_CANCELLED",
													"ORDER_DELIVERED",
													"RETURNED_TO_ORIGIN"
												]
											}
										}
									]
								}
							}
						},
						"nReturned" : 101,
						"executionTimeMillisEstimate" : 0,
						"works" : 220,
						"advanced" : 101,
						"needTime" : 119,
						"needFetch" : 0,
						"saveState" : 10,
						"restoreState" : 10,
						"isEOF" : 0,
						"invalidates" : 0,
						"docsExamined" : 220,
						"alreadyHasObj" : 0,
						"inputStage" : {
							"stage" : "IXSCAN",
							"nReturned" : 220,
							"executionTimeMillisEstimate" : 0,
							"works" : 220,
							"advanced" : 220,
							"needTime" : 0,
							"needFetch" : 0,
							"saveState" : 10,
							"restoreState" : 10,
							"isEOF" : 0,
							"invalidates" : 0,
							"keyPattern" : {
								"order_commit_time" : 1
							},
							"indexName" : "order_commit_time_1",
							"isMultiKey" : false,
							"direction" : "forward",
							"indexBounds" : {
								"order_commit_time" : [
									"[new Date(1455369404000), new Date(9223372036854775807)]"
								]
							},
							"keysExamined" : 220,
							"dupsTested" : 0,
							"dupsDropped" : 0,
							"seenInvalidated" : 0,
							"matchTested" : 0
						}
					}
				}
			}
		]
	},
	"serverInfo" : {
		"host" : "ip-10-0-25-14",
		"port" : 27017,
		"version" : "3.0.4",
		"gitVersion" : "0481c958daeb2969800511e7475dc66986fa9ed5"
	},
	"ok" : 1
}

Comment by David Storch [ 02/Jun/16 ]

Hi arpit@limeroad.com,

After reviewing the .explain() output, I can confirm that your original hypothesis is correct—the query is taking a long time to perform plan selection. MongoDB uses an empirical evaluation strategy to select a winning query plan, as outlined in the following documentation: https://docs.mongodb.com/v3.2/core/query-plans/. The explain output shows that there are six candidate plans being evaluated during the plan selection trial period. Each of them is performing lots of work in order to produce just a handful of results, as indicated by the table below:

Candidate Plan nReturned keysExamined docsExamined executionTimeMillisEstimate
#1 74 665772 487117 3860
#2 78 665768 78 2100
#3 78 611667 611667 21281
#4 7 577754 508583 35598
#5 65 635920 629094 77596
#6 78 665768 78 2750

As you can see from this table, during the trial period each candidate plan examined more than 500,000 keys. Many of these plans also fetched more than 500,000 documents from the collection and took upwards of 20 seconds. The explain output is indicating that the vast majority of time for this query is being spent fetching hundreds of thousands of documents from the collection during the trial period (i.e. the time is spent in the FETCH stage).

This analysis suggests that the root of the problem is that there are no good indices for the query. The system is spending a long time in plan selection since none of the indices are particularly selective. Short of building new indices (possibly to supercede old ones) or changing your query/schema patterns, you have a few options for how to get around this issue:

  • Apply a hint to the query.
  • Set an index filter.
  • There is an internal knob which tunes how long the system is willing to stay inside the query optimization trial period called internalQueryPlanEvaluationCollFraction. This is a number between 0 and 1 which has a default of 0.3. You can experiment with setting this value lower. 0.1 or even 0.01 may work better for your application. Use db.adminCommand({setParameter: 1, internalQueryPlanEvaluationCollFraction: x}) to set the value to x in the shell. Please keep in mind that this is an internal knob and you should be cautious when setting it. Test in staging or QA first to make sure that this will improve the problem query as well as not result in unexpected performance regressions for other queries.

Finally, I would recommend an upgrade to the latest version of 3.0 (or to the latest version of 3.2, if possible). Among many other improvements, versions since 3.0.7 benefit from SERVER-20139, which I suspect could help the performance of these queries.

I don't see any evidence of a defect in the SERVER, so I am closing this issue as Works as Designed. For further support or support-related discussion, please post on the mongodb-user group or Stack Overflow with the mongodb tag, where your question will reach a larger audience.

Best,
Dave

Comment by arpit wanchoo [ 02/Jun/16 ]

rs0:SECONDARY> db.orders.find({ order_commit_time: { $gte: new Date(1455369404000) }, suborders: { $elemMatch: { state: {  $in: [ "RETURNED_TO_ORIGIN", "ORDER_DELIVERED", "ORDER_CANCELLED" ] }, transporter: "fedex" } } }).explain("allPlansExecution")
{
	"queryPlanner" : {
		"plannerVersion" : 1,
		"namespace" : "userDB.orders",
		"indexFilterSet" : false,
		"parsedQuery" : {
			"$and" : [
				{
					"suborders" : {
						"$elemMatch" : {
							"$and" : [
								{
									"transporter" : {
										"$eq" : "fedex"
									}
								},
								{
									"state" : {
										"$in" : [
											"ORDER_CANCELLED",
											"ORDER_DELIVERED",
											"RETURNED_TO_ORIGIN"
										]
									}
								}
							]
						}
					}
				},
				{
					"order_commit_time" : {
						"$gte" : ISODate("2016-02-13T13:16:44Z")
					}
				}
			]
		},
		"winningPlan" : {
			"stage" : "KEEP_MUTATIONS",
			"inputStage" : {
				"stage" : "FETCH",
				"filter" : {
					"suborders" : {
						"$elemMatch" : {
							"$and" : [
								{
									"transporter" : {
										"$eq" : "fedex"
									}
								},
								{
									"state" : {
										"$in" : [
											"ORDER_CANCELLED",
											"ORDER_DELIVERED",
											"RETURNED_TO_ORIGIN"
										]
									}
								}
							]
						}
					}
				},
				"inputStage" : {
					"stage" : "IXSCAN",
					"keyPattern" : {
						"order_commit_time" : 1,
						"suborders.transporter" : 1,
						"suborders.state" : 1
					},
					"indexName" : "order_commit_time_1_suborders.transporter_1_suborders.state_1",
					"isMultiKey" : true,
					"direction" : "forward",
					"indexBounds" : {
						"order_commit_time" : [
							"[new Date(1455369404000), new Date(9223372036854775807)]"
						],
						"suborders.transporter" : [
							"[\"fedex\", \"fedex\"]"
						],
						"suborders.state" : [
							"[\"ORDER_CANCELLED\", \"ORDER_CANCELLED\"]",
							"[\"ORDER_DELIVERED\", \"ORDER_DELIVERED\"]",
							"[\"RETURNED_TO_ORIGIN\", \"RETURNED_TO_ORIGIN\"]"
						]
					}
				}
			}
		},
		"rejectedPlans" : [
			{
				"stage" : "KEEP_MUTATIONS",
				"inputStage" : {
					"stage" : "FETCH",
					"filter" : {
						"suborders" : {
							"$elemMatch" : {
								"$and" : [
									{
										"state" : {
											"$in" : [
												"ORDER_CANCELLED",
												"ORDER_DELIVERED",
												"RETURNED_TO_ORIGIN"
											]
										}
									},
									{
										"transporter" : {
											"$eq" : "fedex"
										}
									}
								]
							}
						}
					},
					"inputStage" : {
						"stage" : "IXSCAN",
						"keyPattern" : {
							"order_commit_time" : 1,
							"suborders.state" : 1,
							"suborders.warehouse_id" : 1
						},
						"indexName" : "order_commit_time_1_suborders.state_1_suborders.warehouse_id_1",
						"isMultiKey" : true,
						"direction" : "forward",
						"indexBounds" : {
							"order_commit_time" : [
								"[new Date(1455369404000), new Date(9223372036854775807)]"
							],
							"suborders.state" : [
								"[\"ORDER_CANCELLED\", \"ORDER_CANCELLED\"]",
								"[\"ORDER_DELIVERED\", \"ORDER_DELIVERED\"]",
								"[\"RETURNED_TO_ORIGIN\", \"RETURNED_TO_ORIGIN\"]"
							],
							"suborders.warehouse_id" : [
								"[MinKey, MaxKey]"
							]
						}
					}
				}
			},
			{
				"stage" : "KEEP_MUTATIONS",
				"inputStage" : {
					"stage" : "FETCH",
					"filter" : {
						"suborders" : {
							"$elemMatch" : {
								"$and" : [
									{
										"transporter" : {
											"$eq" : "fedex"
										}
									},
									{
										"state" : {
											"$in" : [
												"ORDER_CANCELLED",
												"ORDER_DELIVERED",
												"RETURNED_TO_ORIGIN"
											]
										}
									}
								]
							}
						}
					},
					"inputStage" : {
						"stage" : "IXSCAN",
						"keyPattern" : {
							"order_commit_time" : 1,
							"suborders.transporter" : 1,
							"suborders.warehouse_id" : 1,
							"suborders.state" : 1
						},
						"indexName" : "order_commit_time_1_suborders.transporter_1_suborders.warehouse_id_1_suborders.state_1",
						"isMultiKey" : true,
						"direction" : "forward",
						"indexBounds" : {
							"order_commit_time" : [
								"[new Date(1455369404000), new Date(9223372036854775807)]"
							],
							"suborders.transporter" : [
								"[\"fedex\", \"fedex\"]"
							],
							"suborders.warehouse_id" : [
								"[MinKey, MaxKey]"
							],
							"suborders.state" : [
								"[\"ORDER_CANCELLED\", \"ORDER_CANCELLED\"]",
								"[\"ORDER_DELIVERED\", \"ORDER_DELIVERED\"]",
								"[\"RETURNED_TO_ORIGIN\", \"RETURNED_TO_ORIGIN\"]"
							]
						}
					}
				}
			},
			{
				"stage" : "KEEP_MUTATIONS",
				"inputStage" : {
					"stage" : "FETCH",
					"filter" : {
						"suborders" : {
							"$elemMatch" : {
								"$and" : [
									{
										"transporter" : {
											"$eq" : "fedex"
										}
									},
									{
										"state" : {
											"$in" : [
												"ORDER_CANCELLED",
												"ORDER_DELIVERED",
												"RETURNED_TO_ORIGIN"
											]
										}
									}
								]
							}
						}
					},
					"inputStage" : {
						"stage" : "IXSCAN",
						"keyPattern" : {
							"order_commit_time" : 1
						},
						"indexName" : "order_commit_time_1",
						"isMultiKey" : false,
						"direction" : "forward",
						"indexBounds" : {
							"order_commit_time" : [
								"[new Date(1455369404000), new Date(9223372036854775807)]"
							]
						}
					}
				}
			},
			{
				"stage" : "KEEP_MUTATIONS",
				"inputStage" : {
					"stage" : "FETCH",
					"filter" : {
						"$and" : [
							{
								"suborders" : {
									"$elemMatch" : {
										"$and" : [
											{
												"state" : {
													"$in" : [
														"ORDER_CANCELLED",
														"ORDER_DELIVERED",
														"RETURNED_TO_ORIGIN"
													]
												}
											},
											{
												"transporter" : {
													"$eq" : "fedex"
												}
											}
										]
									}
								}
							},
							{
								"order_commit_time" : {
									"$gte" : ISODate("2016-02-13T13:16:44Z")
								}
							}
						]
					},
					"inputStage" : {
						"stage" : "IXSCAN",
						"keyPattern" : {
							"suborders.state" : 1,
							"suborders.timeline.current_state_time" : 1
						},
						"indexName" : "suborders.state_1_suborders.timeline.current_state_time_1",
						"isMultiKey" : true,
						"direction" : "forward",
						"indexBounds" : {
							"suborders.state" : [
								"[\"ORDER_CANCELLED\", \"ORDER_CANCELLED\"]",
								"[\"ORDER_DELIVERED\", \"ORDER_DELIVERED\"]",
								"[\"RETURNED_TO_ORIGIN\", \"RETURNED_TO_ORIGIN\"]"
							],
							"suborders.timeline.current_state_time" : [
								"[MinKey, MaxKey]"
							]
						}
					}
				}
			},
			{
				"stage" : "KEEP_MUTATIONS",
				"inputStage" : {
					"stage" : "FETCH",
					"filter" : {
						"$and" : [
							{
								"suborders" : {
									"$elemMatch" : {
										"$and" : [
											{
												"state" : {
													"$in" : [
														"ORDER_CANCELLED",
														"ORDER_DELIVERED",
														"RETURNED_TO_ORIGIN"
													]
												}
											},
											{
												"transporter" : {
													"$eq" : "fedex"
												}
											}
										]
									}
								}
							},
							{
								"order_commit_time" : {
									"$gte" : ISODate("2016-02-13T13:16:44Z")
								}
							}
						]
					},
					"inputStage" : {
						"stage" : "IXSCAN",
						"keyPattern" : {
							"suborders.state" : 1
						},
						"indexName" : "suborders.state_1",
						"isMultiKey" : true,
						"direction" : "forward",
						"indexBounds" : {
							"suborders.state" : [
								"[\"ORDER_CANCELLED\", \"ORDER_CANCELLED\"]",
								"[\"ORDER_DELIVERED\", \"ORDER_DELIVERED\"]",
								"[\"RETURNED_TO_ORIGIN\", \"RETURNED_TO_ORIGIN\"]"
							]
						}
					}
				}
			}
		]
	},
	"executionStats" : {
		"executionSuccess" : true,
		"nReturned" : 78,
		"executionTimeMillis" : 439066,
		"totalKeysExamined" : 665768,
		"totalDocsExamined" : 78,
		"executionStages" : {
			"stage" : "KEEP_MUTATIONS",
			"nReturned" : 78,
			"executionTimeMillisEstimate" : 2750,
			"works" : 665777,
			"advanced" : 78,
			"needTime" : 665689,
			"needFetch" : 8,
			"saveState" : 177159,
			"restoreState" : 177159,
			"isEOF" : 1,
			"invalidates" : 1967,
			"inputStage" : {
				"stage" : "FETCH",
				"filter" : {
					"suborders" : {
						"$elemMatch" : {
							"$and" : [
								{
									"transporter" : {
										"$eq" : "fedex"
									}
								},
								{
									"state" : {
										"$in" : [
											"ORDER_CANCELLED",
											"ORDER_DELIVERED",
											"RETURNED_TO_ORIGIN"
										]
									}
								}
							]
						}
					}
				},
				"nReturned" : 78,
				"executionTimeMillisEstimate" : 2740,
				"works" : 665776,
				"advanced" : 78,
				"needTime" : 665689,
				"needFetch" : 8,
				"saveState" : 177159,
				"restoreState" : 177159,
				"isEOF" : 1,
				"invalidates" : 1967,
				"docsExamined" : 78,
				"alreadyHasObj" : 0,
				"inputStage" : {
					"stage" : "IXSCAN",
					"nReturned" : 78,
					"executionTimeMillisEstimate" : 2630,
					"works" : 665768,
					"advanced" : 78,
					"needTime" : 665689,
					"needFetch" : 0,
					"saveState" : 177159,
					"restoreState" : 177159,
					"isEOF" : 1,
					"invalidates" : 1967,
					"keyPattern" : {
						"order_commit_time" : 1,
						"suborders.transporter" : 1,
						"suborders.state" : 1
					},
					"indexName" : "order_commit_time_1_suborders.transporter_1_suborders.state_1",
					"isMultiKey" : true,
					"direction" : "forward",
					"indexBounds" : {
						"order_commit_time" : [
							"[new Date(1455369404000), new Date(9223372036854775807)]"
						],
						"suborders.transporter" : [
							"[\"fedex\", \"fedex\"]"
						],
						"suborders.state" : [
							"[\"ORDER_CANCELLED\", \"ORDER_CANCELLED\"]",
							"[\"ORDER_DELIVERED\", \"ORDER_DELIVERED\"]",
							"[\"RETURNED_TO_ORIGIN\", \"RETURNED_TO_ORIGIN\"]"
						]
					},
					"keysExamined" : 665768,
					"dupsTested" : 78,
					"dupsDropped" : 0,
					"seenInvalidated" : 0,
					"matchTested" : 0
				}
			}
		},
		"allPlansExecution" : [
			{
				"nReturned" : 74,
				"executionTimeMillisEstimate" : 3860,
				"totalKeysExamined" : 665772,
				"totalDocsExamined" : 487117,
				"executionStages" : {
					"stage" : "KEEP_MUTATIONS",
					"nReturned" : 74,
					"executionTimeMillisEstimate" : 3860,
					"works" : 665776,
					"advanced" : 74,
					"needTime" : 665698,
					"needFetch" : 4,
					"saveState" : 177159,
					"restoreState" : 177159,
					"isEOF" : 0,
					"invalidates" : 1967,
					"inputStage" : {
						"stage" : "FETCH",
						"filter" : {
							"suborders" : {
								"$elemMatch" : {
									"$and" : [
										{
											"state" : {
												"$in" : [
													"ORDER_CANCELLED",
													"ORDER_DELIVERED",
													"RETURNED_TO_ORIGIN"
												]
											}
										},
										{
											"transporter" : {
												"$eq" : "fedex"
											}
										}
									]
								}
							}
						},
						"nReturned" : 74,
						"executionTimeMillisEstimate" : 3840,
						"works" : 665776,
						"advanced" : 74,
						"needTime" : 665698,
						"needFetch" : 4,
						"saveState" : 177159,
						"restoreState" : 177159,
						"isEOF" : 0,
						"invalidates" : 1967,
						"docsExamined" : 487117,
						"alreadyHasObj" : 0,
						"inputStage" : {
							"stage" : "IXSCAN",
							"nReturned" : 487117,
							"executionTimeMillisEstimate" : 1610,
							"works" : 665772,
							"advanced" : 487117,
							"needTime" : 178655,
							"needFetch" : 0,
							"saveState" : 177159,
							"restoreState" : 177159,
							"isEOF" : 0,
							"invalidates" : 1967,
							"keyPattern" : {
								"order_commit_time" : 1,
								"suborders.state" : 1,
								"suborders.warehouse_id" : 1
							},
							"indexName" : "order_commit_time_1_suborders.state_1_suborders.warehouse_id_1",
							"isMultiKey" : true,
							"direction" : "forward",
							"indexBounds" : {
								"order_commit_time" : [
									"[new Date(1455369404000), new Date(9223372036854775807)]"
								],
								"suborders.state" : [
									"[\"ORDER_CANCELLED\", \"ORDER_CANCELLED\"]",
									"[\"ORDER_DELIVERED\", \"ORDER_DELIVERED\"]",
									"[\"RETURNED_TO_ORIGIN\", \"RETURNED_TO_ORIGIN\"]"
								],
								"suborders.warehouse_id" : [
									"[MinKey, MaxKey]"
								]
							},
							"keysExamined" : 665772,
							"dupsTested" : 665249,
							"dupsDropped" : 178132,
							"seenInvalidated" : 0,
							"matchTested" : 0
						}
					}
				}
			},
			{
				"nReturned" : 78,
				"executionTimeMillisEstimate" : 2100,
				"totalKeysExamined" : 665768,
				"totalDocsExamined" : 78,
				"executionStages" : {
					"stage" : "KEEP_MUTATIONS",
					"nReturned" : 78,
					"executionTimeMillisEstimate" : 2100,
					"works" : 665776,
					"advanced" : 78,
					"needTime" : 665690,
					"needFetch" : 8,
					"saveState" : 177159,
					"restoreState" : 177159,
					"isEOF" : 0,
					"invalidates" : 1967,
					"inputStage" : {
						"stage" : "FETCH",
						"filter" : {
							"suborders" : {
								"$elemMatch" : {
									"$and" : [
										{
											"transporter" : {
												"$eq" : "fedex"
											}
										},
										{
											"state" : {
												"$in" : [
													"ORDER_CANCELLED",
													"ORDER_DELIVERED",
													"RETURNED_TO_ORIGIN"
												]
											}
										}
									]
								}
							}
						},
						"nReturned" : 78,
						"executionTimeMillisEstimate" : 2070,
						"works" : 665776,
						"advanced" : 78,
						"needTime" : 665690,
						"needFetch" : 8,
						"saveState" : 177159,
						"restoreState" : 177159,
						"isEOF" : 0,
						"invalidates" : 1967,
						"docsExamined" : 78,
						"alreadyHasObj" : 0,
						"inputStage" : {
							"stage" : "IXSCAN",
							"nReturned" : 78,
							"executionTimeMillisEstimate" : 2050,
							"works" : 665768,
							"advanced" : 78,
							"needTime" : 665690,
							"needFetch" : 0,
							"saveState" : 177159,
							"restoreState" : 177159,
							"isEOF" : 0,
							"invalidates" : 1967,
							"keyPattern" : {
								"order_commit_time" : 1,
								"suborders.transporter" : 1,
								"suborders.warehouse_id" : 1,
								"suborders.state" : 1
							},
							"indexName" : "order_commit_time_1_suborders.transporter_1_suborders.warehouse_id_1_suborders.state_1",
							"isMultiKey" : true,
							"direction" : "forward",
							"indexBounds" : {
								"order_commit_time" : [
									"[new Date(1455369404000), new Date(9223372036854775807)]"
								],
								"suborders.transporter" : [
									"[\"fedex\", \"fedex\"]"
								],
								"suborders.warehouse_id" : [
									"[MinKey, MaxKey]"
								],
								"suborders.state" : [
									"[\"ORDER_CANCELLED\", \"ORDER_CANCELLED\"]",
									"[\"ORDER_DELIVERED\", \"ORDER_DELIVERED\"]",
									"[\"RETURNED_TO_ORIGIN\", \"RETURNED_TO_ORIGIN\"]"
								]
							},
							"keysExamined" : 665768,
							"dupsTested" : 78,
							"dupsDropped" : 0,
							"seenInvalidated" : 0,
							"matchTested" : 0
						}
					}
				}
			},
			{
				"nReturned" : 78,
				"executionTimeMillisEstimate" : 21281,
				"totalKeysExamined" : 611667,
				"totalDocsExamined" : 611667,
				"executionStages" : {
					"stage" : "KEEP_MUTATIONS",
					"nReturned" : 78,
					"executionTimeMillisEstimate" : 21281,
					"works" : 665776,
					"advanced" : 78,
					"needTime" : 611589,
					"needFetch" : 54109,
					"saveState" : 177159,
					"restoreState" : 177159,
					"isEOF" : 0,
					"invalidates" : 1967,
					"inputStage" : {
						"stage" : "FETCH",
						"filter" : {
							"suborders" : {
								"$elemMatch" : {
									"$and" : [
										{
											"transporter" : {
												"$eq" : "fedex"
											}
										},
										{
											"state" : {
												"$in" : [
													"ORDER_CANCELLED",
													"ORDER_DELIVERED",
													"RETURNED_TO_ORIGIN"
												]
											}
										}
									]
								}
							}
						},
						"nReturned" : 78,
						"executionTimeMillisEstimate" : 21271,
						"works" : 665776,
						"advanced" : 78,
						"needTime" : 611589,
						"needFetch" : 54109,
						"saveState" : 177159,
						"restoreState" : 177159,
						"isEOF" : 0,
						"invalidates" : 1967,
						"docsExamined" : 611667,
						"alreadyHasObj" : 0,
						"inputStage" : {
							"stage" : "IXSCAN",
							"nReturned" : 611667,
							"executionTimeMillisEstimate" : 530,
							"works" : 611667,
							"advanced" : 611667,
							"needTime" : 0,
							"needFetch" : 0,
							"saveState" : 177159,
							"restoreState" : 177159,
							"isEOF" : 0,
							"invalidates" : 1967,
							"keyPattern" : {
								"order_commit_time" : 1
							},
							"indexName" : "order_commit_time_1",
							"isMultiKey" : false,
							"direction" : "forward",
							"indexBounds" : {
								"order_commit_time" : [
									"[new Date(1455369404000), new Date(9223372036854775807)]"
								]
							},
							"keysExamined" : 611667,
							"dupsTested" : 0,
							"dupsDropped" : 0,
							"seenInvalidated" : 0,
							"matchTested" : 0
						}
					}
				}
			},
			{
				"nReturned" : 7,
				"executionTimeMillisEstimate" : 35598,
				"totalKeysExamined" : 577754,
				"totalDocsExamined" : 508583,
				"executionStages" : {
					"stage" : "KEEP_MUTATIONS",
					"nReturned" : 7,
					"executionTimeMillisEstimate" : 35598,
					"works" : 665776,
					"advanced" : 7,
					"needTime" : 577747,
					"needFetch" : 88022,
					"saveState" : 177159,
					"restoreState" : 177159,
					"isEOF" : 0,
					"invalidates" : 1967,
					"inputStage" : {
						"stage" : "FETCH",
						"filter" : {
							"$and" : [
								{
									"suborders" : {
										"$elemMatch" : {
											"$and" : [
												{
													"state" : {
														"$in" : [
															"ORDER_CANCELLED",
															"ORDER_DELIVERED",
															"RETURNED_TO_ORIGIN"
														]
													}
												},
												{
													"transporter" : {
														"$eq" : "fedex"
													}
												}
											]
										}
									}
								},
								{
									"order_commit_time" : {
										"$gte" : ISODate("2016-02-13T13:16:44Z")
									}
								}
							]
						},
						"nReturned" : 7,
						"executionTimeMillisEstimate" : 35588,
						"works" : 665776,
						"advanced" : 7,
						"needTime" : 577747,
						"needFetch" : 88022,
						"saveState" : 177159,
						"restoreState" : 177159,
						"isEOF" : 0,
						"invalidates" : 1967,
						"docsExamined" : 508583,
						"alreadyHasObj" : 0,
						"inputStage" : {
							"stage" : "IXSCAN",
							"nReturned" : 508583,
							"executionTimeMillisEstimate" : 4003,
							"works" : 577754,
							"advanced" : 508583,
							"needTime" : 69171,
							"needFetch" : 0,
							"saveState" : 177159,
							"restoreState" : 177159,
							"isEOF" : 0,
							"invalidates" : 1967,
							"keyPattern" : {
								"suborders.state" : 1,
								"suborders.timeline.current_state_time" : 1
							},
							"indexName" : "suborders.state_1_suborders.timeline.current_state_time_1",
							"isMultiKey" : true,
							"direction" : "forward",
							"indexBounds" : {
								"suborders.state" : [
									"[\"ORDER_CANCELLED\", \"ORDER_CANCELLED\"]",
									"[\"ORDER_DELIVERED\", \"ORDER_DELIVERED\"]",
									"[\"RETURNED_TO_ORIGIN\", \"RETURNED_TO_ORIGIN\"]"
								],
								"suborders.timeline.current_state_time" : [
									"[MinKey, MaxKey]"
								]
							},
							"keysExamined" : 577754,
							"dupsTested" : 577754,
							"dupsDropped" : 69171,
							"seenInvalidated" : 0,
							"matchTested" : 0
						}
					}
				}
			},
			{
				"nReturned" : 65,
				"executionTimeMillisEstimate" : 77596,
				"totalKeysExamined" : 635920,
				"totalDocsExamined" : 629094,
				"executionStages" : {
					"stage" : "KEEP_MUTATIONS",
					"nReturned" : 65,
					"executionTimeMillisEstimate" : 77596,
					"works" : 665776,
					"advanced" : 65,
					"needTime" : 635855,
					"needFetch" : 29856,
					"saveState" : 177159,
					"restoreState" : 177159,
					"isEOF" : 0,
					"invalidates" : 1967,
					"inputStage" : {
						"stage" : "FETCH",
						"filter" : {
							"$and" : [
								{
									"suborders" : {
										"$elemMatch" : {
											"$and" : [
												{
													"state" : {
														"$in" : [
															"ORDER_CANCELLED",
															"ORDER_DELIVERED",
															"RETURNED_TO_ORIGIN"
														]
													}
												},
												{
													"transporter" : {
														"$eq" : "fedex"
													}
												}
											]
										}
									}
								},
								{
									"order_commit_time" : {
										"$gte" : ISODate("2016-02-13T13:16:44Z")
									}
								}
							]
						},
						"nReturned" : 65,
						"executionTimeMillisEstimate" : 77516,
						"works" : 665776,
						"advanced" : 65,
						"needTime" : 635855,
						"needFetch" : 29856,
						"saveState" : 177159,
						"restoreState" : 177159,
						"isEOF" : 0,
						"invalidates" : 1967,
						"docsExamined" : 629094,
						"alreadyHasObj" : 0,
						"inputStage" : {
							"stage" : "IXSCAN",
							"nReturned" : 629094,
							"executionTimeMillisEstimate" : 3730,
							"works" : 635920,
							"advanced" : 629094,
							"needTime" : 6826,
							"needFetch" : 0,
							"saveState" : 177159,
							"restoreState" : 177159,
							"isEOF" : 0,
							"invalidates" : 1967,
							"keyPattern" : {
								"suborders.state" : 1
							},
							"indexName" : "suborders.state_1",
							"isMultiKey" : true,
							"direction" : "forward",
							"indexBounds" : {
								"suborders.state" : [
									"[\"ORDER_CANCELLED\", \"ORDER_CANCELLED\"]",
									"[\"ORDER_DELIVERED\", \"ORDER_DELIVERED\"]",
									"[\"RETURNED_TO_ORIGIN\", \"RETURNED_TO_ORIGIN\"]"
								]
							},
							"keysExamined" : 635920,
							"dupsTested" : 635920,
							"dupsDropped" : 6826,
							"seenInvalidated" : 0,
							"matchTested" : 0
						}
					}
				}
			},
			{
				"nReturned" : 78,
				"executionTimeMillisEstimate" : 2750,
				"totalKeysExamined" : 665768,
				"totalDocsExamined" : 78,
				"executionStages" : {
					"stage" : "KEEP_MUTATIONS",
					"nReturned" : 78,
					"executionTimeMillisEstimate" : 2750,
					"works" : 665776,
					"advanced" : 78,
					"needTime" : 665689,
					"needFetch" : 8,
					"saveState" : 177158,
					"restoreState" : 177158,
					"isEOF" : 1,
					"invalidates" : 1967,
					"inputStage" : {
						"stage" : "FETCH",
						"filter" : {
							"suborders" : {
								"$elemMatch" : {
									"$and" : [
										{
											"transporter" : {
												"$eq" : "fedex"
											}
										},
										{
											"state" : {
												"$in" : [
													"ORDER_CANCELLED",
													"ORDER_DELIVERED",
													"RETURNED_TO_ORIGIN"
												]
											}
										}
									]
								}
							}
						},
						"nReturned" : 78,
						"executionTimeMillisEstimate" : 2740,
						"works" : 665776,
						"advanced" : 78,
						"needTime" : 665689,
						"needFetch" : 8,
						"saveState" : 177158,
						"restoreState" : 177158,
						"isEOF" : 1,
						"invalidates" : 1967,
						"docsExamined" : 78,
						"alreadyHasObj" : 0,
						"inputStage" : {
							"stage" : "IXSCAN",
							"nReturned" : 78,
							"executionTimeMillisEstimate" : 2630,
							"works" : 665768,
							"advanced" : 78,
							"needTime" : 665689,
							"needFetch" : 0,
							"saveState" : 177158,
							"restoreState" : 177158,
							"isEOF" : 1,
							"invalidates" : 1967,
							"keyPattern" : {
								"order_commit_time" : 1,
								"suborders.transporter" : 1,
								"suborders.state" : 1
							},
							"indexName" : "order_commit_time_1_suborders.transporter_1_suborders.state_1",
							"isMultiKey" : true,
							"direction" : "forward",
							"indexBounds" : {
								"order_commit_time" : [
									"[new Date(1455369404000), new Date(9223372036854775807)]"
								],
								"suborders.transporter" : [
									"[\"fedex\", \"fedex\"]"
								],
								"suborders.state" : [
									"[\"ORDER_CANCELLED\", \"ORDER_CANCELLED\"]",
									"[\"ORDER_DELIVERED\", \"ORDER_DELIVERED\"]",
									"[\"RETURNED_TO_ORIGIN\", \"RETURNED_TO_ORIGIN\"]"
								]
							},
							"keysExamined" : 665768,
							"dupsTested" : 78,
							"dupsDropped" : 0,
							"seenInvalidated" : 0,
							"matchTested" : 0
						}
					}
				}
			}
		]
	},
	"serverInfo" : {
		"host" : "ip-10-0-25-14",
		"port" : 27017,
		"version" : "3.0.4",
		"gitVersion" : "0481c958daeb2969800511e7475dc66986fa9ed5"
	},
	"ok" : 1
}
rs0:SECONDARY> 
 
 
 
rs0:SECONDARY> db.orders.getIndexKeys()
[
	{
		"_id" : 1
	},
	{
		"user_id" : 1
	},
	{
		"email_id" : 1
	},
	{
		"last_modified" : 1
	},
	{
		"suborders.state" : 1
	},
	{
		"suborders.warehouse_id" : 1
	},
	{
		"order_id" : 1
	},
	{
		"address.mobile" : 1
	},
	{
		"order_commit_time" : 1
	},
	{
		"is_cod" : 1
	},
	{
		"cod_confirm_time" : 1
	},
	{
		"suborders.invoices_print_time" : 1
	},
	{
		"current_transaction_id" : 1
	},
	{
		"suborders.awb" : 1
	},
	{
		"suborders.warehouse_id" : 1,
		"suborders.state" : 1
	},
	{
		"email_id" : 1,
		"address.pincode" : 1,
		"state" : 1
	},
	{
		"order_commit_time" : 1,
		"suborders.transporter" : 1,
		"suborders.warehouse_id" : 1,
		"suborders.state" : 1
	},
	{
		"warehouse_id" : 1,
		"state" : 1,
		"manifest_time" : -1
	},
	{
		"suborders.warehouse_id" : 1,
		"suborders.state" : 1,
		"suborders.manifest_time" : -1
	},
	{
		"order_commit_time" : 1,
		"suborders.state" : 1,
		"suborders.warehouse_id" : 1
	},
	{
		"is_operated" : 1
	},
	{
		"suborders.manifest_id" : 1
	},
	{
		"suborders.delivery_time" : -1
	},
	{
		"email_id" : 1,
		"order_commit_time" : 1
	},
	{
		"suborders.awb_activated_time" : 1
	},
	{
		"suborders.state" : 1,
		"suborders.timeline.current_state_time" : 1
	},
	{
		"suborders.warehouse_id" : 1,
		"suborders.state" : 1,
		"suborders.confirm_time" : 1
	},
	{
		"order_commit_time" : 1,
		"suborders.transporter" : 1,
		"suborders.state" : 1
	},
	{
		"operations.date" : 1
	},
	{
		"suborders.last_modified" : 1
	}
]

Comment by David Storch [ 01/Jun/16 ]

Hi arpit@limeroad.com,

Thanks for the explain output. In order to further diagnose this issue, we would like to take a look at a more verbose form of this output. Please re-run the explain command above in allPlansExecution mode and provide its complete output. Specifically, this will look like the below:

db.orders.find({ order_commit_time: { $gte: new Date(1455369404000) }, suborders: { $elemMatch: { state: {  $in: [ "RETURNED_TO_ORIGIN", "ORDER_DELIVERED", "ORDER_CANCELLED" ] }, transporter: "fedex" } } }).explain("allPlansExecution");

I hope this will help us make forward progress in identifying the root cause of this issue!

Best,
Dave

Comment by arpit wanchoo [ 01/Jun/16 ]

Following is the query and its explain output which took 20min to give the explain output :

rs0:SECONDARY> db.orders.find({ order_commit_time: { $gte: new Date(1455369404000) }, suborders: { $elemMatch: { state: {  $in: [ "RETURNED_TO_ORIGIN", "ORDER_DELIVERED", "ORDER_CANCELLED" ] }, transporter: "fedex" } } }).explain()
{
	"queryPlanner" : {
		"plannerVersion" : 1,
		"namespace" : "userDB.orders",
		"indexFilterSet" : false,
		"parsedQuery" : {
			"$and" : [
				{
					"suborders" : {
						"$elemMatch" : {
							"$and" : [
								{
									"transporter" : {
										"$eq" : "fedex"
									}
								},
								{
									"state" : {
										"$in" : [
											"ORDER_CANCELLED",
											"ORDER_DELIVERED",
											"RETURNED_TO_ORIGIN"
										]
									}
								}
							]
						}
					}
				},
				{
					"order_commit_time" : {
						"$gte" : ISODate("2016-02-13T13:16:44Z")
					}
				}
			]
		},
		"winningPlan" : {
			"stage" : "KEEP_MUTATIONS",
			"inputStage" : {
				"stage" : "FETCH",
				"filter" : {
					"suborders" : {
						"$elemMatch" : {
							"$and" : [
								{
									"transporter" : {
										"$eq" : "fedex"
									}
								},
								{
									"state" : {
										"$in" : [
											"ORDER_CANCELLED",
											"ORDER_DELIVERED",
											"RETURNED_TO_ORIGIN"
										]
									}
								}
							]
						}
					}
				},
				"inputStage" : {
					"stage" : "IXSCAN",
					"keyPattern" : {
						"order_commit_time" : 1,
						"suborders.transporter" : 1,
						"suborders.state" : 1
					},
					"indexName" : "order_commit_time_1_suborders.transporter_1_suborders.state_1",
					"isMultiKey" : true,
					"direction" : "forward",
					"indexBounds" : {
						"order_commit_time" : [
							"[new Date(1455369404000), new Date(9223372036854775807)]"
						],
						"suborders.transporter" : [
							"[\"fedex\", \"fedex\"]"
						],
						"suborders.state" : [
							"[\"ORDER_CANCELLED\", \"ORDER_CANCELLED\"]",
							"[\"ORDER_DELIVERED\", \"ORDER_DELIVERED\"]",
							"[\"RETURNED_TO_ORIGIN\", \"RETURNED_TO_ORIGIN\"]"
						]
					}
				}
			}
		},
		"rejectedPlans" : [
			{
				"stage" : "KEEP_MUTATIONS",
				"inputStage" : {
					"stage" : "FETCH",
					"filter" : {
						"suborders" : {
							"$elemMatch" : {
								"$and" : [
									{
										"state" : {
											"$in" : [
												"ORDER_CANCELLED",
												"ORDER_DELIVERED",
												"RETURNED_TO_ORIGIN"
											]
										}
									},
									{
										"transporter" : {
											"$eq" : "fedex"
										}
									}
								]
							}
						}
					},
					"inputStage" : {
						"stage" : "IXSCAN",
						"keyPattern" : {
							"order_commit_time" : 1,
							"suborders.state" : 1,
							"suborders.warehouse_id" : 1
						},
						"indexName" : "order_commit_time_1_suborders.state_1_suborders.warehouse_id_1",
						"isMultiKey" : true,
						"direction" : "forward",
						"indexBounds" : {
							"order_commit_time" : [
								"[new Date(1455369404000), new Date(9223372036854775807)]"
							],
							"suborders.state" : [
								"[\"ORDER_CANCELLED\", \"ORDER_CANCELLED\"]",
								"[\"ORDER_DELIVERED\", \"ORDER_DELIVERED\"]",
								"[\"RETURNED_TO_ORIGIN\", \"RETURNED_TO_ORIGIN\"]"
							],
							"suborders.warehouse_id" : [
								"[MinKey, MaxKey]"
							]
						}
					}
				}
			},
			{
				"stage" : "KEEP_MUTATIONS",
				"inputStage" : {
					"stage" : "FETCH",
					"filter" : {
						"suborders" : {
							"$elemMatch" : {
								"$and" : [
									{
										"transporter" : {
											"$eq" : "fedex"
										}
									},
									{
										"state" : {
											"$in" : [
												"ORDER_CANCELLED",
												"ORDER_DELIVERED",
												"RETURNED_TO_ORIGIN"
											]
										}
									}
								]
							}
						}
					},
					"inputStage" : {
						"stage" : "IXSCAN",
						"keyPattern" : {
							"order_commit_time" : 1,
							"suborders.transporter" : 1,
							"suborders.warehouse_id" : 1,
							"suborders.state" : 1
						},
						"indexName" : "order_commit_time_1_suborders.transporter_1_suborders.warehouse_id_1_suborders.state_1",
						"isMultiKey" : true,
						"direction" : "forward",
						"indexBounds" : {
							"order_commit_time" : [
								"[new Date(1455369404000), new Date(9223372036854775807)]"
							],
							"suborders.transporter" : [
								"[\"fedex\", \"fedex\"]"
							],
							"suborders.warehouse_id" : [
								"[MinKey, MaxKey]"
							],
							"suborders.state" : [
								"[\"ORDER_CANCELLED\", \"ORDER_CANCELLED\"]",
								"[\"ORDER_DELIVERED\", \"ORDER_DELIVERED\"]",
								"[\"RETURNED_TO_ORIGIN\", \"RETURNED_TO_ORIGIN\"]"
							]
						}
					}
				}
			},
			{
				"stage" : "KEEP_MUTATIONS",
				"inputStage" : {
					"stage" : "FETCH",
					"filter" : {
						"suborders" : {
							"$elemMatch" : {
								"$and" : [
									{
										"transporter" : {
											"$eq" : "fedex"
										}
									},
									{
										"state" : {
											"$in" : [
												"ORDER_CANCELLED",
												"ORDER_DELIVERED",
												"RETURNED_TO_ORIGIN"
											]
										}
									}
								]
							}
						}
					},
					"inputStage" : {
						"stage" : "IXSCAN",
						"keyPattern" : {
							"order_commit_time" : 1
						},
						"indexName" : "order_commit_time_1",
						"isMultiKey" : false,
						"direction" : "forward",
						"indexBounds" : {
							"order_commit_time" : [
								"[new Date(1455369404000), new Date(9223372036854775807)]"
							]
						}
					}
				}
			},
			{
				"stage" : "KEEP_MUTATIONS",
				"inputStage" : {
					"stage" : "FETCH",
					"filter" : {
						"$and" : [
							{
								"suborders" : {
									"$elemMatch" : {
										"$and" : [
											{
												"state" : {
													"$in" : [
														"ORDER_CANCELLED",
														"ORDER_DELIVERED",
														"RETURNED_TO_ORIGIN"
													]
												}
											},
											{
												"transporter" : {
													"$eq" : "fedex"
												}
											}
										]
									}
								}
							},
							{
								"order_commit_time" : {
									"$gte" : ISODate("2016-02-13T13:16:44Z")
								}
							}
						]
					},
					"inputStage" : {
						"stage" : "IXSCAN",
						"keyPattern" : {
							"suborders.state" : 1,
							"suborders.timeline.current_state_time" : 1
						},
						"indexName" : "suborders.state_1_suborders.timeline.current_state_time_1",
						"isMultiKey" : true,
						"direction" : "forward",
						"indexBounds" : {
							"suborders.state" : [
								"[\"ORDER_CANCELLED\", \"ORDER_CANCELLED\"]",
								"[\"ORDER_DELIVERED\", \"ORDER_DELIVERED\"]",
								"[\"RETURNED_TO_ORIGIN\", \"RETURNED_TO_ORIGIN\"]"
							],
							"suborders.timeline.current_state_time" : [
								"[MinKey, MaxKey]"
							]
						}
					}
				}
			},
			{
				"stage" : "KEEP_MUTATIONS",
				"inputStage" : {
					"stage" : "FETCH",
					"filter" : {
						"$and" : [
							{
								"suborders" : {
									"$elemMatch" : {
										"$and" : [
											{
												"state" : {
													"$in" : [
														"ORDER_CANCELLED",
														"ORDER_DELIVERED",
														"RETURNED_TO_ORIGIN"
													]
												}
											},
											{
												"transporter" : {
													"$eq" : "fedex"
												}
											}
										]
									}
								}
							},
							{
								"order_commit_time" : {
									"$gte" : ISODate("2016-02-13T13:16:44Z")
								}
							}
						]
					},
					"inputStage" : {
						"stage" : "IXSCAN",
						"keyPattern" : {
							"suborders.state" : 1
						},
						"indexName" : "suborders.state_1",
						"isMultiKey" : true,
						"direction" : "forward",
						"indexBounds" : {
							"suborders.state" : [
								"[\"ORDER_CANCELLED\", \"ORDER_CANCELLED\"]",
								"[\"ORDER_DELIVERED\", \"ORDER_DELIVERED\"]",
								"[\"RETURNED_TO_ORIGIN\", \"RETURNED_TO_ORIGIN\"]"
							]
						}
					}
				}
			}
		]
	},
	"serverInfo" : {
		"host" : "ip-10-0-25-14",
		"port" : 27017,
		"version" : "3.0.4",
		"gitVersion" : "0481c958daeb2969800511e7475dc66986fa9ed5"
	},
	"ok" : 1
}

Now if I give the hint for using index then the query gives output within a second

db.orders.find({ order_commit_time: { $gte: new Date(1455369404000) }, suborders: { $elemMatch: { state: {  $in: [ "RETURNED_TO_ORIGIN", "ORDER_DELIVERED", "ORDER_CANCELLED" ] }, transporter: "fedex" } } }).hint( { "order_commit_time" :1 , "suborders.transporter" :1 , "suborders.state" : 1})

The other problem I am referring to is that the sometimes for the same query , even the correct index is not selected in the winning plan

Comment by Ramon Fernandez Marina [ 31/May/16 ]

arpit@limeroad.com, unfortunately there's not information in this ticket for us to investigate the issue. As Dan requested above, please provide the explain() output for all the queries you mention, as well as the list of indexes in the affected collections.

Note also that, in general, is better to open a separate ticket for each individual issue so they can be investigated in parallel. Once we have more information we'll be able to determine if the two issues you reported have the same root cause or if one of them needs a separate ticket.

Finally, please note that 3.0.4 is almost 1 year old, so I'd encourage you to upgrade to 3.0.12 or 3.2.6 – both of which include SERVER-20139 in them, a feature that may help your use case.

Thanks,
Ramón.

Comment by Daniel Pasette (Inactive) [ 30/May/16 ]

Please include the output of explain.

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