Slow queries using wrong Index

Rexcily_Rijo_R1 · 2024-06-07T06:00:47.547Z

Hi Team,

I have query and when it is fired form application side it is using one type of index which is present in that collection(I have checked this system.profile collection).

When I execute the same query manually in the database it is picking the another index.

Please explain why this is happening and how it is picking different index for the same query

Output from system.profile:

rs0:SECONDARY> db.system.profile.findOne()
{
        "op" : "query",
        "ns" : "penguin-consumer.notification_mail_response_logs",
        "command" : {
                "find" : "notification_mail_response_logs",
                "filter" : {
                        "userId" : NumberLong(91149349),
                        "profileId" : NumberLong(107020334),
                        "notificationType" : "recommendedjobs",
                        "emailStatus" : "SUCCESS"
                },
                "sort" : {
                        "createdAt" : -1
                },
                "projection" : {
                        "notificationUuid" : 1,
                        "mailedJobIds" : 1
                },
                "limit" : 1,
        "planSummary" : "IXSCAN { userId: 1, profileId: 1, notificationType: 1, emailStatus: 1 }",

Output of explain plan:

rs0:SECONDARY> db.notification_mail_response_logs.find(
...     {
...         "userId": NumberLong(33965519),
...         "profileId": NumberLong(26164350),
...         "notificationType": "recommendedjobs",
...         "emailStatus": "SUCCESS"
...     },
...     {
...         "notificationUuid": 1,
...         "mailedJobIds": 1
...     }
... ).sort(
...     {
...         "createdAt": -1
...     }
... ).limit(1).explain("executionStats").executionStats
{
        "executionSuccess" : true,
        "nReturned" : 1,
        "executionTimeMillis" : 6,
        "totalKeysExamined" : 1,
        "totalDocsExamined" : 1,
        "inputStage" : {
                                        "stage" : "IXSCAN",
                                        "nReturned" : 1,
        "keyPattern" : {
                                                "userId" : 1,
                                                "profileId" : 1,
                                                "createdAt" : -1
                                        },
                                        "indexName" : "userId_1_profileId_1_createdAt_-1",

Gareth_Furnell · 2024-06-07T07:50:47.276Z

Hi

On the Output from system.profile:

it mentions that it is a findOne() query/command - this removes the need for a limit if it is specified on the application side

this could be due to where the projection stage is set as mongodb interprets it from the application, it places the step as last for the data you want after it is sorted, whereas in your manual query it is forced to project the data and then sort - mongodb might be more strict to follow your stages from the application but be more lenient from the manual because the 1 document scanned could have already been returned from the “userId” and “profileId” find and then sort that single document(because the index exists)

Based on the version of your Deployment, please take the SBE into account: https://www.mongodb.com/docs/v7.1/reference/sbe/#:~:text=Starting%20in%20MongoDB%206.2%2C%20slow,execution%20engine%20executed%20the%20query.

hope this helps but the different findOne() and find().limit(1) might be why -
lastly I’m not sure you specified which one is the slow query?