0

We have a MongoDB pod running on CGP Kubernates with 2 replicas. Microservices are written in Java and use Mophia to access MongoDB. The database only has 6 million data. One collection, in particular, has 5 million of data. There is an instance where the service makes 30-40 find queries on the database which is very slow after some time.

Data insertions to the DB happening in long intervals. 40 sensors will be sending data to an Apache NiFi server every one minute and NiFi will ingest data to Mongo in the same frequency.

Query

https://pastebin.com/1uCVyyD5

Observations to consider

  • This slowness is not there when the database pod is restarted. Execution time is around 1-2 seconds at this time
  • After some time, this slowness starts to visible. This can happen within a few hours or within 1-2 days.
  • Once the queries are getting delayed, the execution time is about 10-15 seconds.

Once the queries are slow;

  • Connections stats

    { "current" : 87, "available" : 838773, "totalCreated" : 422342 }

  • Global Lock

enter image description here

enter image description here enter image description here

Please help me on this if you guys have any ideas why this is happening. Thank you.

update:

query:

db.readings.find({ tenant_id: ObjectId('5a2e649c4c174757ee049379'), sensor_id: ObjectId('5a33ab0a4c174757ee1048f1')}).sort({date: -1}).limit(1).explain(true)

here is the explain(true) output:

{
"queryPlanner" : {
    "plannerVersion" : 1,
    "namespace" : "mycol.readings",
    "indexFilterSet" : false,
    "parsedQuery" : {
        "$and" : [ 
            {
                "sensor_id" : {
                    "$eq" : ObjectId("5a33ab0a4c174757ee1048f1")
                }
            }, 
            {
                "tenant_id" : {
                    "$eq" : ObjectId("5a2e649c4c174757ee049379")
                }
            }
        ]
    },
    "winningPlan" : {
        "stage" : "LIMIT",
        "limitAmount" : 1,
        "inputStage" : {
            "stage" : "FETCH",
            "inputStage" : {
                "stage" : "IXSCAN",
                "keyPattern" : {
                    "tenant_id" : 1.0,
                    "sensor_id" : 1.0,
                    "date" : -1.0
                },
                "indexName" : "tenant_id_1_sensor_id_1_date_-1",
                "isMultiKey" : false,
                "multiKeyPaths" : {
                    "tenant_id" : [],
                    "sensor_id" : [],
                    "date" : []
                },
                "isUnique" : false,
                "isSparse" : false,
                "isPartial" : false,
                "indexVersion" : 2,
                "direction" : "forward",
                "indexBounds" : {
                    "tenant_id" : [ 
                        "[ObjectId('5a2e649c4c174757ee049379'), ObjectId('5a2e649c4c174757ee049379')]"
                    ],
                    "sensor_id" : [ 
                        "[ObjectId('5a33ab0a4c174757ee1048f1'), ObjectId('5a33ab0a4c174757ee1048f1')]"
                    ],
                    "date" : [ 
                        "[MaxKey, MinKey]"
                    ]
                }
            }
        }
    },
    "rejectedPlans" : [ 
        {
            "stage" : "SORT",
            "sortPattern" : {
                "date" : -1.0
            },
            "limitAmount" : 1,
            "inputStage" : {
                "stage" : "SORT_KEY_GENERATOR",
                "inputStage" : {
                    "stage" : "FETCH",
                    "inputStage" : {
                        "stage" : "IXSCAN",
                        "keyPattern" : {
                            "tenant_id" : 1.0,
                            "sensor_id" : 1.0,
                            "data_type" : 1.0,
                            "date" : -1.0
                        },
                        "indexName" : "tenant_id_1_sensor_id_1_data_type_1_date_-1",
                        "isMultiKey" : false,
                        "multiKeyPaths" : {
                            "tenant_id" : [],
                            "sensor_id" : [],
                            "data_type" : [],
                            "date" : []
                        },
                        "isUnique" : false,
                        "isSparse" : false,
                        "isPartial" : false,
                        "indexVersion" : 2,
                        "direction" : "forward",
                        "indexBounds" : {
                            "tenant_id" : [ 
                                "[ObjectId('5a2e649c4c174757ee049379'), ObjectId('5a2e649c4c174757ee049379')]"
                            ],
                            "sensor_id" : [ 
                                "[ObjectId('5a33ab0a4c174757ee1048f1'), ObjectId('5a33ab0a4c174757ee1048f1')]"
                            ],
                            "data_type" : [ 
                                "[MinKey, MaxKey]"
                            ],
                            "date" : [ 
                                "[MaxKey, MinKey]"
                            ]
                        }
                    }
                }
            }
        }
    ]
},
"executionStats" : {
    "executionSuccess" : true,
    "nReturned" : 1,
    "executionTimeMillis" : 1,
    "totalKeysExamined" : 1,
    "totalDocsExamined" : 1,
    "executionStages" : {
        "stage" : "LIMIT",
        "nReturned" : 1,
        "executionTimeMillisEstimate" : 0,
        "works" : 2,
        "advanced" : 1,
        "needTime" : 0,
        "needYield" : 0,
        "saveState" : 0,
        "restoreState" : 0,
        "isEOF" : 1,
        "invalidates" : 0,
        "limitAmount" : 1,
        "inputStage" : {
            "stage" : "FETCH",
            "nReturned" : 1,
            "executionTimeMillisEstimate" : 0,
            "works" : 1,
            "advanced" : 1,
            "needTime" : 0,
            "needYield" : 0,
            "saveState" : 0,
            "restoreState" : 0,
            "isEOF" : 0,
            "invalidates" : 0,
            "docsExamined" : 1,
            "alreadyHasObj" : 0,
            "inputStage" : {
                "stage" : "IXSCAN",
                "nReturned" : 1,
                "executionTimeMillisEstimate" : 0,
                "works" : 1,
                "advanced" : 1,
                "needTime" : 0,
                "needYield" : 0,
                "saveState" : 0,
                "restoreState" : 0,
                "isEOF" : 0,
                "invalidates" : 0,
                "keyPattern" : {
                    "tenant_id" : 1.0,
                    "sensor_id" : 1.0,
                    "date" : -1.0
                },
                "indexName" : "tenant_id_1_sensor_id_1_date_-1",
                "isMultiKey" : false,
                "multiKeyPaths" : {
                    "tenant_id" : [],
                    "sensor_id" : [],
                    "date" : []
                },
                "isUnique" : false,
                "isSparse" : false,
                "isPartial" : false,
                "indexVersion" : 2,
                "direction" : "forward",
                "indexBounds" : {
                    "tenant_id" : [ 
                        "[ObjectId('5a2e649c4c174757ee049379'), ObjectId('5a2e649c4c174757ee049379')]"
                    ],
                    "sensor_id" : [ 
                        "[ObjectId('5a33ab0a4c174757ee1048f1'), ObjectId('5a33ab0a4c174757ee1048f1')]"
                    ],
                    "date" : [ 
                        "[MaxKey, MinKey]"
                    ]
                },
                "keysExamined" : 1,
                "seeks" : 1,
                "dupsTested" : 0,
                "dupsDropped" : 0,
                "seenInvalidated" : 0
            }
        }
    },
    "allPlansExecution" : [ 
        {
            "nReturned" : 0,
            "executionTimeMillisEstimate" : 0,
            "totalKeysExamined" : 0,
            "totalDocsExamined" : 0,
            "executionStages" : {
                "stage" : "SORT",
                "nReturned" : 0,
                "executionTimeMillisEstimate" : 0,
                "works" : 1,
                "advanced" : 0,
                "needTime" : 1,
                "needYield" : 0,
                "saveState" : 0,
                "restoreState" : 0,
                "isEOF" : 0,
                "invalidates" : 0,
                "sortPattern" : {
                    "date" : -1.0
                },
                "memUsage" : 0,
                "memLimit" : 33554432,
                "limitAmount" : 1,
                "inputStage" : {
                    "stage" : "SORT_KEY_GENERATOR",
                    "nReturned" : 0,
                    "executionTimeMillisEstimate" : 0,
                    "works" : 1,
                    "advanced" : 0,
                    "needTime" : 1,
                    "needYield" : 0,
                    "saveState" : 0,
                    "restoreState" : 0,
                    "isEOF" : 0,
                    "invalidates" : 0,
                    "inputStage" : {
                        "stage" : "FETCH",
                        "nReturned" : 0,
                        "executionTimeMillisEstimate" : 0,
                        "works" : 0,
                        "advanced" : 0,
                        "needTime" : 0,
                        "needYield" : 0,
                        "saveState" : 0,
                        "restoreState" : 0,
                        "isEOF" : 0,
                        "invalidates" : 0,
                        "docsExamined" : 0,
                        "alreadyHasObj" : 0,
                        "inputStage" : {
                            "stage" : "IXSCAN",
                            "nReturned" : 0,
                            "executionTimeMillisEstimate" : 0,
                            "works" : 0,
                            "advanced" : 0,
                            "needTime" : 0,
                            "needYield" : 0,
                            "saveState" : 0,
                            "restoreState" : 0,
                            "isEOF" : 0,
                            "invalidates" : 0,
                            "keyPattern" : {
                                "tenant_id" : 1.0,
                                "sensor_id" : 1.0,
                                "data_type" : 1.0,
                                "date" : -1.0
                            },
                            "indexName" : "tenant_id_1_sensor_id_1_data_type_1_date_-1",
                            "isMultiKey" : false,
                            "multiKeyPaths" : {
                                "tenant_id" : [],
                                "sensor_id" : [],
                                "data_type" : [],
                                "date" : []
                            },
                            "isUnique" : false,
                            "isSparse" : false,
                            "isPartial" : false,
                            "indexVersion" : 2,
                            "direction" : "forward",
                            "indexBounds" : {
                                "tenant_id" : [ 
                                    "[ObjectId('5a2e649c4c174757ee049379'), ObjectId('5a2e649c4c174757ee049379')]"
                                ],
                                "sensor_id" : [ 
                                    "[ObjectId('5a33ab0a4c174757ee1048f1'), ObjectId('5a33ab0a4c174757ee1048f1')]"
                                ],
                                "data_type" : [ 
                                    "[MinKey, MaxKey]"
                                ],
                                "date" : [ 
                                    "[MaxKey, MinKey]"
                                ]
                            },
                            "keysExamined" : 0,
                            "seeks" : 0,
                            "dupsTested" : 0,
                            "dupsDropped" : 0,
                            "seenInvalidated" : 0
                        }
                    }
                }
            }
        }, 
        {
            "nReturned" : 1,
            "executionTimeMillisEstimate" : 0,
            "totalKeysExamined" : 1,
            "totalDocsExamined" : 1,
            "executionStages" : {
                "stage" : "LIMIT",
                "nReturned" : 1,
                "executionTimeMillisEstimate" : 0,
                "works" : 1,
                "advanced" : 1,
                "needTime" : 0,
                "needYield" : 0,
                "saveState" : 0,
                "restoreState" : 0,
                "isEOF" : 1,
                "invalidates" : 0,
                "limitAmount" : 1,
                "inputStage" : {
                    "stage" : "FETCH",
                    "nReturned" : 1,
                    "executionTimeMillisEstimate" : 0,
                    "works" : 1,
                    "advanced" : 1,
                    "needTime" : 0,
                    "needYield" : 0,
                    "saveState" : 0,
                    "restoreState" : 0,
                    "isEOF" : 0,
                    "invalidates" : 0,
                    "docsExamined" : 1,
                    "alreadyHasObj" : 0,
                    "inputStage" : {
                        "stage" : "IXSCAN",
                        "nReturned" : 1,
                        "executionTimeMillisEstimate" : 0,
                        "works" : 1,
                        "advanced" : 1,
                        "needTime" : 0,
                        "needYield" : 0,
                        "saveState" : 0,
                        "restoreState" : 0,
                        "isEOF" : 0,
                        "invalidates" : 0,
                        "keyPattern" : {
                            "tenant_id" : 1.0,
                            "sensor_id" : 1.0,
                            "date" : -1.0
                        },
                        "indexName" : "tenant_id_1_sensor_id_1_date_-1",
                        "isMultiKey" : false,
                        "multiKeyPaths" : {
                            "tenant_id" : [],
                            "sensor_id" : [],
                            "date" : []
                        },
                        "isUnique" : false,
                        "isSparse" : false,
                        "isPartial" : false,
                        "indexVersion" : 2,
                        "direction" : "forward",
                        "indexBounds" : {
                            "tenant_id" : [ 
                                "[ObjectId('5a2e649c4c174757ee049379'), ObjectId('5a2e649c4c174757ee049379')]"
                            ],
                            "sensor_id" : [ 
                                "[ObjectId('5a33ab0a4c174757ee1048f1'), ObjectId('5a33ab0a4c174757ee1048f1')]"
                            ],
                            "date" : [ 
                                "[MaxKey, MinKey]"
                            ]
                        },
                        "keysExamined" : 1,
                        "seeks" : 1,
                        "dupsTested" : 0,
                        "dupsDropped" : 0,
                        "seenInvalidated" : 0
                    }
                }
            }
        }
    ]
},
"serverInfo" : {
    "host" : "mongo-123",
    "port" : 27017,
    "version" : "3.4.10",
    "gitVersion" : "078f28920cb24de0dd479b5ea6c66c644f6326e9"
},
"ok" : 1.0
}
  • Unfortunately performance questions like this may be tip of the iceberg since there many different factors that could contribute. The details provided so far don't indicate anything obvious, so I would start by looking at the slowest queries. Can you edit your question to include the output of explain(true) for one of your queries that performs slower over time? I would also recommend upgrading to the latest 3.4 maintenance release (currently 3.4.20) in case you are running into an issue that has been resolved since 3.4.10. – Stennie Apr 5 at 5:45
  • Thanks, @Stannie for the answer. I noticed that after cleaning PlanCache of those two collections, the query got fast again. Any clue why? – samma89 Apr 5 at 6:02
  • I added the explain(true) output. – samma89 Apr 5 at 6:03
  • Thanks for adding the query explain output. This confirms my suspicion that there are competing plans for this query shape, although the second plan (with an in-memory sort and extra data_type field) seems unlikely to win. This may be a red herring, but since your problem sounds reproducible I'd suggest saving the output of planCacheListPlans when performance declines to see if suboptimal plans are being cached. – Stennie Apr 5 at 6:19
  • I'd also recommend testing with MongoDB 3.4.20 as there have been many bug fixes & stability improvements and this does not contain any backward-breaking changes for the 3.4 release series. I don't see anything specific to query planning which might relate to the issue you are seeing, but at this point I also don't think there is enough information to be certain about the cause of your performance issue. Improvements to storage and other internals may be beneficial for your use case. – Stennie Apr 5 at 6:27

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Browse other questions tagged or ask your own question.