[SERVER-46092] Broken index after mongodb version upgrade to 3.6 Created: 12/Feb/20  Updated: 14/Feb/20  Resolved: 14/Feb/20

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

Type: Bug Priority: Major - P3
Reporter: Jackie Chu Assignee: Eric Sedor
Resolution: Duplicate Votes: 0
Labels: index, multikeyIndex
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Heroku with mlab add-on.
Upgraded from mongodb v3.4.20 -> v3.6.12


Issue Links:
Duplicate
duplicates SERVER-19402 Change semantics of sorting by array ... Closed
Participants:

 Description   

Problem

After upgrading mongodb from v3.4.20 -> v3.6.12 (on mlab add-on for heroku), we have sudden dramatic performance regression on the mongodb. CPU usage went from <10% to 99%, Disk IOPS significantly increased and all burst credits are used up within minutes, which brought down our service (application on heroku). 

Investigation

Our investigation found that the existing index (multi-key) seems to be broken/corrupted after the mongodb upgrade, which caused inefficient query execution plan to be generated & huge # of document examined for all queries.

Resolution / Workaround

We dropped the index and re-created the same index. The issue seems to be resolved afterward.

Question

  1. Is it specific problem for multi-key index?
  2. Any indicators for broken/corrupted index?
  3. Are we expected/required to rebuild index after certain operation (such as db version upgrade)?

 


Collection: "runs"

  1. of documents: 1.8M
    Size: 130GB, Storage Size: 28GB

 

Index:

{ 
 "tags" : 1, 
 "startTS" : -1
 }

Note: "tags" = array of text (huge amount of distant values)

 

Query:

 db.getCollection('runs')
.find({"tags":{"$all":["approval-approved"]}})
.sort({startTS: -1})
.limit(100)

 

Execution Plan (problematic)

12 mins - 1M keys examined & 1M docs examined.

"executionStats" : {
       "executionSuccess" : true, 
       "nReturned" : 100.0, 
       "executionTimeMillis" : 725879.0, 
       "totalKeysExamined" : 1081144.0, 
       "totalDocsExamined" : 1081144.0, 
       "executionStages" : {
           "stage" : "SORT", 
           "nReturned" : 100.0, 
           "executionTimeMillisEstimate" : 722927.0, 
           "works" : 1081247.0, 
           "advanced" : 100.0, 
           "needTime" : 1081146.0, 
           "needYield" : 0.0, 
           "saveState" : 35987.0, 
           "restoreState" : 35987.0, 
           "isEOF" : 1.0, 
           "invalidates" : 0.0, 
           "sortPattern" : {
               "startTS" : -1.0
           }, 
           "memUsage" : 8236467.0, 
           "memLimit" : 33554432.0, 
           "limitAmount" : 100.0, 
           "inputStage" : {
               "stage" : "SORT_KEY_GENERATOR", 
               "nReturned" : 1081144.0, 
               "executionTimeMillisEstimate" : 721437.0, 
               "works" : 1081146.0, 
               "advanced" : 1081144.0, 
               "needTime" : 1.0, 
               "needYield" : 0.0, 
               "saveState" : 35987.0, 
               "restoreState" : 35987.0, 
               "isEOF" : 1.0, 
               "invalidates" : 0.0, 
               "inputStage" : {
                   "stage" : "FETCH", 
                   "nReturned" : 1081144.0, 
                   "executionTimeMillisEstimate" : 719697.0, 
                   "works" : 1081145.0, 
                   "advanced" : 1081144.0, 
                   "needTime" : 0.0, 
                   "needYield" : 0.0, 
                   "saveState" : 35987.0, 
                   "restoreState" : 35987.0, 
                   "isEOF" : 1.0, 
                   "invalidates" : 0.0, 
                   "docsExamined" : 1081144.0, 
                   "alreadyHasObj" : 0.0, 
                   "inputStage" : {
                       "stage" : "IXSCAN", 
                       "nReturned" : 1081144.0, 
                       "executionTimeMillisEstimate" : 2644.0, 
                       "works" : 1081145.0, 
                       "advanced" : 1081144.0, 
                       "needTime" : 0.0, 
                       "needYield" : 0.0, 
                       "saveState" : 35987.0, 
                       "restoreState" : 35987.0, 
                       "isEOF" : 1.0, 
                       "invalidates" : 0.0, 
                       "keyPattern" : {
                           "tags" : 1.0, 
                           "startTS" : -1.0
                       }, 
                       "indexName" : "tags_1_startTS_-1", 
                       "isMultiKey" : true, 
                       "isUnique" : false, 
                       "isSparse" : false, 
                       "isPartial" : false, 
                       "indexVersion" : 1.0, 
                       "direction" : "forward", 
                       "indexBounds" : {
                           "tags" : [
                               "[\"approval-approved\", \"approval-approved\"]"
                           ], 
                           "startTS" : [
                               "[MaxKey, MinKey]"
                           ]
                       }, 
                       "keysExamined" : 1081144.0, 
                       "seeks" : 1.0, 
                       "dupsTested" : 1081144.0, 
                       "dupsDropped" : 0.0, 
                       "seenInvalidated" : 0.0                   }
               }
           }
       }
   }

 

Execution Plan (After re-creating same index) 

5 ms - 100 keys examined & 100 docs examined. And I noticed that multiKeyPaths is present in this executionStats, but not in the problematic one above.

"executionStats" : {
        "executionSuccess" : true, 
        "nReturned" : 100.0, 
        "executionTimeMillis" : 5.0, 
        "totalKeysExamined" : 100.0, 
        "totalDocsExamined" : 100.0, 
        "executionStages" : {
            "stage" : "LIMIT", 
            "nReturned" : 100.0, 
            "executionTimeMillisEstimate" : 0.0, 
            "works" : 101.0, 
            "advanced" : 100.0, 
            "needTime" : 0.0, 
            "needYield" : 0.0, 
            "saveState" : 2.0, 
            "restoreState" : 2.0, 
            "isEOF" : 1.0, 
            "invalidates" : 0.0, 
            "limitAmount" : 100.0, 
            "inputStage" : {
                "stage" : "FETCH", 
                "nReturned" : 100.0, 
                "executionTimeMillisEstimate" : 0.0, 
                "works" : 100.0, 
                "advanced" : 100.0, 
                "needTime" : 0.0, 
                "needYield" : 0.0, 
                "saveState" : 2.0, 
                "restoreState" : 2.0, 
                "isEOF" : 0.0, 
                "invalidates" : 0.0, 
                "docsExamined" : 100.0, 
                "alreadyHasObj" : 0.0, 
                "inputStage" : {
                    "stage" : "IXSCAN", 
                    "nReturned" : 100.0, 
                    "executionTimeMillisEstimate" : 0.0, 
                    "works" : 100.0, 
                    "advanced" : 100.0, 
                    "needTime" : 0.0, 
                    "needYield" : 0.0, 
                    "saveState" : 2.0, 
                    "restoreState" : 2.0, 
                    "isEOF" : 0.0, 
                    "invalidates" : 0.0, 
                    "keyPattern" : {
                        "tags" : 1.0, 
                        "startTS" : -1.0
                    }, 
                    "indexName" : "tags_1_startTS_-1", 
                    "isMultiKey" : true, 
                    "multiKeyPaths" : {
                        "tags" : [
                            "tags"
                        ], 
                        "startTS" : [
 
                        ]
                    }, 
                    "isUnique" : false, 
                    "isSparse" : false, 
                    "isPartial" : false, 
                    "indexVersion" : 2.0, 
                    "direction" : "forward", 
                    "indexBounds" : {
                        "tags" : [
                            "[\"approval-approved\", \"approval-approved\"]"
                        ], 
                        "startTS" : [
                            "[MaxKey, MinKey]"
                        ]
                    }, 
                    "keysExamined" : 100.0, 
                    "seeks" : 1.0, 
                    "dupsTested" : 100.0, 
                    "dupsDropped" : 0.0, 
                    "seenInvalidated" : 0.0
                }
            }
        }
    }

 



 Comments   
Comment by Jackie Chu [ 14/Feb/20 ]

Great. Thank you for your promptly response, Eric. 

Comment by Eric Sedor [ 14/Feb/20 ]

Of course Jackie,

Some features of v:2 indexes are indicated here, and you can check index version by index in the output of db.collection.getIndexes() in the shell.

The SERVER project is for reporting bugs and feature requests, so for further guidance I must encourage you to reach out to support@mlab.com, or to ask our community by posting on the mongodb-user group or on Stack Overflow with the mongodb tag.

Sincerely,
Eric

Comment by Jackie Chu [ 14/Feb/20 ]

Hi Eric,

Thank you for looking into it and it's great for us to learn the cause of that.

  • If we still have some indices (not multikey index though) in version 1, do we need to rebuild the indices? (Is anything else that would not be working efficiently/properly in index version 1, other than multikey path?)
  • As a mongodb user, is there any way to know that if the index version is outdated and an index rebuilt is needed? (e.g. how do we know what the latest index version should be? Any warning/indicator when outdated index version is used?)

Thanks,

Jackie

Comment by Eric Sedor [ 13/Feb/20 ]

Hi chujacky1128@gmail.com,

The behavior you are seeing is related to SERVER-19402 and SERVER-33387. In short, version 1 indexes (created in MongoDB 3.2 and earlier) do not contain that multikey path information. Starting in MongoDB 3.6, that information is necessary to provide non-blocking sorts in certain cases. Re-creating the index causes it to be created as a version 2 index, which contains the information you observe in the later explain plan.

It's worth noting that you can email support@mlab.com for questions about issues with mLab deployments.

Sincerely,
Eric

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