[SERVER-54710] Large number of $or clauses can create profiling entry exceeding max BSON size, causing the query to fail when it should not Created: 22/Feb/21  Updated: 29/Oct/23  Resolved: 11/Mar/21

Status: Closed
Project: Core Server
Component/s: Querying
Affects Version/s: None
Fix Version/s: 4.9.0, 4.4.5, 4.0.24, 4.2.14

Type: Bug Priority: Major - P3
Reporter: Jennifer Huang (Inactive) Assignee: David Storch
Resolution: Fixed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Backports
Related
is related to SERVER-14123 some operations can create BSON objec... Closed
Backwards Compatibility: Fully Compatible
Backport Requested:
v4.4, v4.2, v4.0
Sprint: Query Execution 2021-03-22
Participants:

 Description   

Each clause in a $or expression can use its own index so when a query has a lot $or and each $or has a lot of clause it can create a very large profiler entry when profiler is enabled.

{
        "op" : "query",
        "ns" : "database.collection",
        "command" : {
                "find" : "collection",
                "filter" : {
                        "$or" : [
                                {
                                        "$and" : [
                                                {
                                                        "$or" : [
                                                                {
                                                                        "field1" : "1163"
                                                                },
                                                                {
                                                                        "field2" : "1163"
                                                                }
                                                        ]
                                                },
                                                {
                                                        "field3" : "G3"
                                                },
                                                {
                                                        "field4" : "GYN"
                                                }
                                        ]
                                },
                                {
                                        "$and" : [
                                                {
                                                        "$or" : [
                                                                {
                                                                        "field1" : "3402"
                                                                },
                                                                {
                                                                        "field2" : "3402"
                                                                }
                                                        ]
                                                },
                                                {
                                                        "field3" : "IB"
                                                },
                                                {
                                                        "field4" : "MAD"
                                                }
                                        ]
                                }
                        ]
                },
                "lsid" : {
                        "id" : UUID("d7f6df2a-1941-4463-9e85-91e050c35f38")
                },
                "$clusterTime" : {
                        "clusterTime" : Timestamp(1614021369, 1),
                        "signature" : {
                                "hash" : BinData(0,"AAAAAAAAAAAAAAAAAAAAAAAAAAA="),
                                "keyId" : NumberLong(0)
                        }
                },
                "$db" : "database"
        },
        "keysExamined" : 25,
        "docsExamined" : 8,
        "cursorExhausted" : true,
        "numYield" : 0,
        "nreturned" : 8,
        "locks" : {
                "Global" : {
                        "acquireCount" : {
                                "r" : NumberLong(1)
                        }
                },
                "Database" : {
                        "acquireCount" : {
                                "r" : NumberLong(1)
                        }
                },
                "Collection" : {
                        "acquireCount" : {
                                "r" : NumberLong(1)
                        }
                }
        },
        "responseLength" : 53607,
        "protocol" : "op_msg",
        "millis" : 0,
        "planSummary" : "IXSCAN { field3: 1, field1: 1, field5: 1, field6: 1 }, IXSCAN { field2: 1, field5: 1, field7: 1, field3: 1, field4: 1 }, IXSCAN { field3: 1, field1: 1, field5: 1, field6: 1 }, IXSCAN { field2: 1, field5: 1, field7: 1, field3: 1, field4: 1 }",
        "execStats" : {
                "stage" : "SUBPLAN",
                "nReturned" : 8,
                "executionTimeMillisEstimate" : 0,
                "works" : 27,
                "advanced" : 8,
                "needTime" : 18,
                "needYield" : 0,
                "saveState" : 0,
                "restoreState" : 0,
                "isEOF" : 1,
                "invalidates" : 0,
                "inputStage" : {
                        "stage" : "OR",
                        "nReturned" : 8,
                        "executionTimeMillisEstimate" : 0,
                        "works" : 27,
                        "advanced" : 8,
                        "needTime" : 18,
                        "needYield" : 0,
                        "saveState" : 0,
                        "restoreState" : 0,
                        "isEOF" : 1,
                        "invalidates" : 0,
                        "dupsTested" : 8,
                        "dupsDropped" : 0,
                        "recordIdsForgotten" : 0,
                        "inputStages" : [
                                {
                                        "stage" : "FETCH",
                                        "filter" : {
                                                "field4" : {
                                                        "$eq" : "GYN"
                                                }
                                        },
                                        "nReturned" : 3,
                                        "executionTimeMillisEstimate" : 0,
                                        "works" : 14,
                                        "advanced" : 3,
                                        "needTime" : 10,
                                        "needYield" : 0,
                                        "saveState" : 0,
                                        "restoreState" : 0,
                                        "isEOF" : 1,
                                        "invalidates" : 0,
                                        "docsExamined" : 3,
                                        "alreadyHasObj" : 0,
                                        "inputStage" : {
                                                "stage" : "OR",
                                                "nReturned" : 3,
                                                "executionTimeMillisEstimate" : 0,
                                                "works" : 14,
                                                "advanced" : 3,
                                                "needTime" : 10,
                                                "needYield" : 0,
                                                "saveState" : 0,
                                                "restoreState" : 0,
                                                "isEOF" : 1,
                                                "invalidates" : 0,
                                                "dupsTested" : 6,
                                                "dupsDropped" : 3,
                                                "recordIdsForgotten" : 0,
                                                "inputStages" : [
                                                        {
                                                                "stage" : "IXSCAN",
                                                                "nReturned" : 3,
                                                                "executionTimeMillisEstimate" : 0,
                                                                "works" : 4,
                                                                "advanced" : 3,
                                                                "needTime" : 0,
                                                                "needYield" : 0,
                                                                "saveState" : 0,
                                                                "restoreState" : 0,
                                                                "isEOF" : 1,
                                                                "invalidates" : 0,
                                                                "keyPattern" : {
                                                                        "field3" : 1,
                                                                        "field1" : 1,
                                                                        "field5" : 1,
                                                                        "field6" : 1
                                                                },
                                                                "indexName" : "index_1",
                                                                "isMultiKey" : false,
                                                                "multiKeyPaths" : {
                                                                        "field3" : [ ],
                                                                        "field1" : [ ],
                                                                        "field5" : [ ],
                                                                        "field6" : [ ]
                                                                },
                                                                "isUnique" : false,
                                                                "isSparse" : false,
                                                                "isPartial" : false,
                                                                "indexVersion" : 2,
                                                                "direction" : "forward",
                                                                "indexBounds" : {
                                                                        "field3" : [
                                                                                "[\"G3\", \"G3\"]"
                                                                        ],
                                                                        "field1" : [
                                                                                "[\"1163\", \"1163\"]"
                                                                        ],
                                                                        "field5" : [
                                                                                "[MinKey, MaxKey]"
                                                                        ],
                                                                        "field6" : [
                                                                                "[MinKey, MaxKey]"
                                                                        ]
                                                                },
                                                                "keysExamined" : 3,
                                                                "seeks" : 1,
                                                                "dupsTested" : 0,
                                                                "dupsDropped" : 0,
                                                                "seenInvalidated" : 0
                                                        },
                                                        {
                                                                "stage" : "IXSCAN",
                                                                "nReturned" : 3,
                                                                "executionTimeMillisEstimate" : 0,
                                                                "works" : 10,
                                                                "advanced" : 3,
                                                                "needTime" : 6,
                                                                "needYield" : 0,
                                                                "saveState" : 0,
                                                                "restoreState" : 0,
                                                                "isEOF" : 1,
                                                                "invalidates" : 0,
                                                                "keyPattern" : {
                                                                        "field2" : 1,
                                                                        "field5" : 1,
                                                                        "field7" : 1,
                                                                        "field3" : 1,
                                                                        "field4" : 1
                                                                },
                                                                "indexName" : "index_2",
                                                                "isMultiKey" : false,
                                                                "multiKeyPaths" : {
                                                                        "field2" : [ ],
                                                                        "field5" : [ ],
                                                                        "field7" : [ ],
                                                                        "field3" : [ ],
                                                                        "field4" : [ ]
                                                                },
                                                                "isUnique" : false,
                                                                "isSparse" : false,
                                                                "isPartial" : false,
                                                                "indexVersion" : 2,
                                                                "direction" : "forward",
                                                                "indexBounds" : {
                                                                        "field2" : [
                                                                                "[\"1163\", \"1163\"]"
                                                                        ],
                                                                        "field5" : [
                                                                                "[MinKey, MaxKey]"
                                                                        ],
                                                                        "field7" : [
                                                                                "[MinKey, MaxKey]"
                                                                        ],
                                                                        "field3" : [
                                                                                "[\"G3\", \"G3\"]"
                                                                        ],
                                                                        "field4" : [
                                                                                "[\"GYN\", \"GYN\"]"
                                                                        ]
                                                                },
                                                                "keysExamined" : 10,
                                                                "seeks" : 7,
                                                                "dupsTested" : 0,
                                                                "dupsDropped" : 0,
                                                                "seenInvalidated" : 0
                                                        }
                                                ]
                                        }
                                },
                                {
                                        "stage" : "FETCH",
                                        "filter" : {
                                                "field4" : {
                                                        "$eq" : "MAD"
                                                }
                                        },
                                        "nReturned" : 5,
                                        "executionTimeMillisEstimate" : 0,
                                        "works" : 13,
                                        "advanced" : 5,
                                        "needTime" : 7,
                                        "needYield" : 0,
                                        "saveState" : 0,
                                        "restoreState" : 0,
                                        "isEOF" : 1,
                                        "invalidates" : 0,
                                        "docsExamined" : 5,
                                        "alreadyHasObj" : 0,
                                        "inputStage" : {
                                                "stage" : "OR",
                                                "nReturned" : 5,
                                                "executionTimeMillisEstimate" : 0,
                                                "works" : 13,
                                                "advanced" : 5,
                                                "needTime" : 7,
                                                "needYield" : 0,
                                                "saveState" : 0,
                                                "restoreState" : 0,
                                                "isEOF" : 1,
                                                "invalidates" : 0,
                                                "dupsTested" : 10,
                                                "dupsDropped" : 5,
                                                "recordIdsForgotten" : 0,
                                                "inputStages" : [
                                                        {
                                                                "stage" : "IXSCAN",
                                                                "nReturned" : 5,
                                                                "executionTimeMillisEstimate" : 0,
                                                                "works" : 6,
                                                                "advanced" : 5,
                                                                "needTime" : 0,
                                                                "needYield" : 0,
                                                                "saveState" : 0,
                                                                "restoreState" : 0,
                                                                "isEOF" : 1,
                                                                "invalidates" : 0,
                                                                "keyPattern" : {
                                                                        "field3" : 1,
                                                                        "field1" : 1,
                                                                        "field5" : 1,
                                                                        "field6" : 1
                                                                },
                                                                "indexName" : "index_1",
                                                                "isMultiKey" : false,
                                                                "multiKeyPaths" : {
                                                                        "field3" : [ ],
                                                                        "field1" : [ ],
                                                                        "field5" : [ ],
                                                                        "field6" : [ ]
                                                                },
                                                                "isUnique" : false,
                                                                "isSparse" : false,
                                                                "isPartial" : false,
                                                                "indexVersion" : 2,
                                                                "direction" : "forward",
                                                                "indexBounds" : {
                                                                        "field3" : [
                                                                                "[\"IB\", \"IB\"]"
                                                                        ],
                                                                        "field1" : [
                                                                                "[\"3402\", \"3402\"]"
                                                                        ],
                                                                        "field5" : [
                                                                                "[MinKey, MaxKey]"
                                                                        ],
                                                                        "field6" : [
                                                                                "[MinKey, MaxKey]"
                                                                        ]
                                                                },
                                                                "keysExamined" : 5,
                                                                "seeks" : 1,
                                                                "dupsTested" : 0,
                                                                "dupsDropped" : 0,
                                                                "seenInvalidated" : 0
                                                        },
                                                        {
                                                                "stage" : "IXSCAN",
                                                                "nReturned" : 5,
                                                                "executionTimeMillisEstimate" : 0,
                                                                "works" : 7,
                                                                "advanced" : 5,
                                                                "needTime" : 1,
                                                                "needYield" : 0,
                                                                "saveState" : 0,
                                                                "restoreState" : 0,
                                                                "isEOF" : 1,
                                                                "invalidates" : 0,
                                                                "keyPattern" : {
                                                                        "field2" : 1,
                                                                        "field5" : 1,
                                                                        "field7" : 1,
                                                                        "field3" : 1,
                                                                        "field4" : 1
                                                                },
                                                                "indexName" : "index_2",
                                                                "isMultiKey" : false,
                                                                "multiKeyPaths" : {
                                                                        "field2" : [ ],
                                                                        "field5" : [ ],
                                                                        "field7" : [ ],
                                                                        "field3" : [ ],
                                                                        "field4" : [ ]
                                                                },
                                                                "isUnique" : false,
                                                                "isSparse" : false,
                                                                "isPartial" : false,
                                                                "indexVersion" : 2,
                                                                "direction" : "forward",
                                                                "indexBounds" : {
                                                                        "field2" : [
                                                                                "[\"3402\", \"3402\"]"
                                                                        ],
                                                                        "field5" : [
                                                                                "[MinKey, MaxKey]"
                                                                        ],
                                                                        "field7" : [
                                                                                "[MinKey, MaxKey]"
                                                                        ],
                                                                        "field3" : [
                                                                                "[\"IB\", \"IB\"]"
                                                                        ],
                                                                        "field4" : [
                                                                                "[\"MAD\", \"MAD\"]"
                                                                        ]
                                                                },
                                                                "keysExamined" : 7,
                                                                "seeks" : 2,
                                                                "dupsTested" : 0,
                                                                "dupsDropped" : 0,
                                                                "seenInvalidated" : 0
                                                        }
                                                ]
                                        }
                                }
                        ]
                }
        },
        "ts" : ISODate("2021-02-22T19:16:17.280Z"),
        "client" : "127.0.0.1",
        "appName" : "MongoDB Shell",
        "allUsers" : [ ],
        "user" : ""
}

When the profiler entry is too large it can trigger the "BSONObjectTooLarge" error and causing such a query fail to execute.

Error: error: {
  "operationTime" : Timestamp(1614018738, 1),
  "ok" : 0,
  "errmsg" : "BSONObj size: 20642198 (0x13AF996) is invalid. Size must be between 0 and 16793600(16MB) First element: stage: \"OR\"",
  "code" : 10334,
  "codeName" : "BSONObjectTooLarge",
  "$clusterTime" : {
    "clusterTime" : Timestamp(1614018738, 1),
    "signature" : {
      "hash" : BinData(0,"AAAAAAAAAAAAAAAAAAAAAAAAAAA="),
      "keyId" : NumberLong(0)
    }
  }
}



 Comments   
Comment by Githook User [ 26/Mar/21 ]

Author:

{'name': 'David Storch', 'email': 'david.storch@mongodb.com', 'username': 'dstorch'}

Message: SERVER-54710 Improve checks for overlarge BSON when generating explain output

(cherry picked from commit 4fc3991bf64b33ca5f5237722bc563f8eb1a552a)
(cherry picked from commit 754b0efe8549fe2d5fa2847676985709c60412a7)
(cherry picked from commit fc232126bd406e6c85ec45b869c88d7a238e60c5)
Branch: v4.0
https://github.com/mongodb/mongo/commit/7e996c56ac576f8ef548a52c84aa0edf506344b7

Comment by Githook User [ 24/Mar/21 ]

Author:

{'name': 'David Storch', 'email': 'david.storch@mongodb.com', 'username': 'dstorch'}

Message: SERVER-54710 Improve checks for overlarge BSON when generating explain output

(cherry picked from commit 4fc3991bf64b33ca5f5237722bc563f8eb1a552a)
(cherry picked from commit 754b0efe8549fe2d5fa2847676985709c60412a7)
Branch: v4.2
https://github.com/mongodb/mongo/commit/fc232126bd406e6c85ec45b869c88d7a238e60c5

Comment by Githook User [ 24/Mar/21 ]

Author:

{'name': 'David Storch', 'email': 'david.storch@mongodb.com', 'username': 'dstorch'}

Message: SERVER-54710 Improve checks for overlarge BSON when generating explain output

(cherry picked from commit 4fc3991bf64b33ca5f5237722bc563f8eb1a552a)
Branch: v4.4
https://github.com/mongodb/mongo/commit/754b0efe8549fe2d5fa2847676985709c60412a7

Comment by Githook User [ 11/Mar/21 ]

Author:

{'name': 'David Storch', 'email': 'david.storch@mongodb.com', 'username': 'dstorch'}

Message: SERVER-54710 Improve checks for overlarge BSON when generating explain output
Branch: master
https://github.com/mongodb/mongo/commit/4fc3991bf64b33ca5f5237722bc563f8eb1a552a

Comment by David Storch [ 24/Feb/21 ]

Yeah, if we go with the quick fix I demonstrated above it is definitely safe to backport.

Comment by Jennifer Huang (Inactive) [ 24/Feb/21 ]

Thanks david.storch for the detailed insight, can this be backported to older version like 4.0 4.2?

Comment by David Storch [ 23/Feb/21 ]

I dug into the root cause of this a bit and have some results to report. The code originally added in SERVER-14123 to address a similar problem consults the current size of the top-level BSONObjBuilder when serializing the stats for a stage in the execution tree. If the buffer is already at least 10MB, then we we just add a field "warning":"stats tree exceeded BSON size limit for explain" and bail out, truncating a portion of the execution stats object.

This bug reports a scenario in which the aforementioned size check does not kick in correctly. It does not kick in because there is a code path that creates a separate buffer instead of always appending to the original buffer. Therefore, the stats are split across two buffers and we never notice that we have surpassed the 10MB limit. Here is a patch to correct this particular problem, which is probably good enough to resolve this ticket:

diff --git a/src/mongo/db/query/plan_explainer_impl.cpp b/src/mongo/db/query/plan_explainer_impl.cpp
index a04882ce57..2886c8f43c 100644
--- a/src/mongo/db/query/plan_explainer_impl.cpp
+++ b/src/mongo/db/query/plan_explainer_impl.cpp
@@ -470,9 +470,8 @@ void statsToBSON(const PlanStageStats& stats,
     // the output more readable by saving a level of nesting. Name the field 'inputStage'
     // rather than 'inputStages'.
     if (1 == stats.children.size()) {
-        BSONObjBuilder childBob;
+        BSONObjBuilder childBob(bob->subobjStart("inputStage"));
         statsToBSON(*stats.children[0], verbosity, &childBob, topLevelBob);
-        bob->append("inputStage", childBob.obj());
         return;
     }

A few additional notes, however. First, by default the system.profile collection is sized at 1MB. Therefore, if I run the repro script after my fix, the operation will succeed but it will not be able to write an entry to the system.profile collection because the entry exceeds 1MB. This is noted in the logs with a message like the following:

{"t":{"$date":"2021-02-23T16:24:20.470-05:00"},"s":"W",  "c":"-",        "id":20703,   "ctx":"conn5","msg":"Caught Assertion while trying to profile operation","attr":{"operation":"msg","namespace":"e2e.flight_bson_size","assertion":"BadValue: object to insert exceeds cappedMaxSize"

This isn't necessarily a problem, however, since the query as a whole succeeds as expected. Also, if the user re-sizes system.profile to allow more profiler data, then the profile entry will get written as expected.

Second, the fix proposed above works in practice although theoretically it would still be possible for queries to fail with the same symptom. I can think of two reasons for this:

  1. We check the buffer size after the fact, so if any particular stage adds an enormous amount of data, the size could grow from <10MB to >16MB all at once. If it ever exceeds 16MB, then the query will fail with a similar message as reported in this ticket.
  2. There could be enough sibling stages in the plan to exceed the 16MB limit by repeatedly adding the string "stats tree exceeded BSON size limit for explain".

Both of these scenarios are slightly farfetched and seem unlikely to occur in practice. Therefore, my recommendation would be to pursue the quick fix in my patch above.

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