[SERVER-55298] Reproduce and Investigate BSONObjectTooLarge error Created: 18/Mar/21  Updated: 29/Oct/23  Resolved: 31/Mar/21

Status: Closed
Project: Core Server
Component/s: None
Affects Version/s: 4.4.4
Fix Version/s: 4.4.5, 5.0.0-rc0

Type: Task Priority: Critical - P2
Reporter: Lamont Nelson Assignee: Lamont Nelson
Resolution: Fixed Votes: 0
Labels: bkp, sharding-wfbf-day
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Backports
Depends
Related
Backwards Compatibility: Fully Compatible
Backport Requested:
v5.0, v4.4
Sprint: Sharding 2021-03-22, Sharding 2021-04-05
Participants:

 Description   

In version 4.4+, a cluster can get a BSONObjectTooLarge error when attempting to migrate chunks. The _migrateClone command that the recipient invokes has logic here and here to ensure that we don't return too big of a vector to be placed in the command. The particular error is below:

{"t": {"$date":"2021-03-10T21:27:33.038Z"} ,"s":"W","c":"SHARDING","id":23777,"ctx":"MoveChunk","msg":"Error while doing moveChunk","attr":{"error":"OperationFailed: Data transfer error: migrate failed: BSONObjectTooLarge: _migrateClone failed: :: caused by :: BSONObj size: 16861227 (0x101482B) is invalid. Size must be between 0 and 16793600(16MB) First element: ...REDACTED] }"}}

The goal of this ticket is to reproduce the error and determine the best way to mitigate the situation. The parameters internalQueryExecYieldIterations/internalQueryExecYieldPeriodMS have been suggested as a possible work around, but runtime effects of changing the parameters should be evaluated.



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

Author:

{'name': 'LaMont Nelson', 'email': 'lamont.nelson@mongodb.com', 'username': 'lamontnelson'}

Message: SERVER-55298: fix BSONObjTooLarge error when calling removeShard on a jumbo chunk

(cherry picked from commit ab6654feeb39f96065e89d90bba9c2dd5acb0731)
Branch: v4.4
https://github.com/mongodb/mongo/commit/ff5cb77101b052fa02da43b8538093486cf9b3f7

Comment by Githook User [ 31/Mar/21 ]

Author:

{'name': 'LaMont Nelson', 'email': 'lamont.nelson@mongodb.com', 'username': 'lamontnelson'}

Message: SERVER-55298: fix BSONObjTooLarge error when calling removeShard on a jumbo chunk
Branch: master
https://github.com/mongodb/mongo/commit/ab6654feeb39f96065e89d90bba9c2dd5acb0731

Comment by Lamont Nelson [ 29/Mar/21 ]

code review: https://mongodbcr.appspot.com/779940002/

Comment by Lamont Nelson [ 23/Mar/21 ]

Got it. That makes sense.

Comment by Max Hirschhorn [ 23/Mar/21 ]

Thanks for confirming obj is an index key! Empty strings are used in the BSONObj representation of index keys because the field names are redundant with the {a: 1, b: 1, ...} key pattern specification. The ordering of the key-value pairs is instead used to define the correspondence between the index key object and the key pattern specification.

There are functions like rehydrateIndexKey() and IndexKeyEntry::rehydrateKey() to transform the index key into something more human readable. (Those functions aren't as helpful here because chunk migration is wanting the full document anyway.)

Comment by Lamont Nelson [ 23/Mar/21 ]

max.hirschhorn The object I'm seeing for obj is

{"":1.0}

I'm curious as to how one interprets this object? I thought that column names would be required.

Comment by Lamont Nelson [ 23/Mar/21 ]

Yes I had thought this as well, and ended up correcting this statement in the help ticket. I have a patch that fixes the issue by finding the doc earlier, but I'll change it to use IXSCAN_FETCH since that's more efficient.

Comment by Max Hirschhorn [ 23/Mar/21 ]

I'm opening a ticket to add tests for bsonobj.objsize().

I couldn't imagine BSONObj::objsize() being incorrect given how widely used that method is.

lamont.nelson, is it possible the 15 bytes for obj is correct and the issue is that we're using the size of the index key to estimate the size of the full document which is instead fetched with Collection::findDoc() later on in the loop?

It looks like _jumboChunkCloneState->clonerExec is an IndexScan using the default options of IXSCAN_DEFAULT and therefore won't have access to the full document via PlanExecutor::getNext(). Changing it to use IXSCAN_FETCH and removing the Collection::findDoc() call might be a solution here.

Comment by Lamont Nelson [ 22/Mar/21 ]

I made a workload that inserts documents near the 16MB limit (16MB - 5kb specifically). It then calls removeShard and waits for that operation to complete. I added the following log statement here:

LOGV2_DEBUG(1234501,
                 0,
                 "check limit 1",
                 "arrBuilderLen"_attr = arrBuilder->len(),
                 "objSize"_attr = obj.objsize(),
                 "maxSize"_attr = BSONObjMaxUserSize,
                 "arrSize"_attr = arrBuilder->arrSize(),
                 "valid"_attr =
                     (arrBuilder->len() + obj.objsize() + 1024) <= BSONObjMaxUserSize);

This results in the following output:

[js_test:repro-HELP-22995] 2021-03-20T03:04:01.475+0000 d20023| {"t":{"$date":"2021-03-20T03:04:01.475+00:00"},"s":"I",  "c":"SHARDING", "id":1234501, "ctx":"conn65","msg":"check limit 1","attr":{"arrBuilderLen":4,"objSize":15,"maxSize":16777216,"arrSize":0,"valid":true}}
[js_test:repro-HELP-22995] 2021-03-20T03:04:01.481+0000 d20023| {"t":{"$date":"2021-03-20T03:04:01.481+00:00"},"s":"I",  "c":"SHARDING", "id":1234501, "ctx":"conn65","msg":"check limit 1","attr":{"arrBuilderLen":16772170,"objSize":15,"maxSize":16777216,"arrSize":1,"valid":true}}
[js_test:repro-HELP-22995] 2021-03-20T03:04:01.490+0000 d20023| {"t":{"$date":"2021-03-20T03:04:01.490+00:00"},"s":"I",  "c":"SHARDING", "id":1234501, "ctx":"conn65","msg":"check limit 1","attr":{"arrBuilderLen":33544336,"objSize":15,"maxSize":16777216,"arrSize":2,"valid":false}}
[js_test:repro-HELP-22995] 2021-03-20T03:04:01.490+0000 d20023| {"t":{"$date":"2021-03-20T03:04:01.490+00:00"},"s":"I",  "c":"SHARDING", "id":1234501, "ctx":"conn65","msg":"check limit 1","attr":{"arrBuilderLen":33544336,"objSize":15,"maxSize":16777216,"arrSize":2,"valid":false}}
[js_test:repro-HELP-22995] 2021-03-20T03:04:01.490+0000 d20023| {"t":{"$date":"2021-03-20T03:04:01.490+00:00"},"s":"E",  "c":"-",        "id":23077,   "ctx":"conn65","msg":"Assertion","attr":{"error":"BSONObjectTooLarge: BSONObj size: 33544337 (0x1FFD891) is invalid. Size must be between 0 and 16793600(16MB) First element: 0: { _id: ObjectId('6055661515ff954a732caf10'), x: 1.0, seq: 0.0, data: \"moOYX8eXBv6nGL8gjHn5VYvTEMvc7vGGQOQpqlj8zlk66sWESXI0nueDONxNkeS27zD7ZRaV15xImW0wDlJLgcwdvKFo9pjiMceil1GNNWoBaNiB27epHmyuodzNtd0tyVNTMxmi9gfczeawjl4uqE...\", arr: [] }","file":"src/mongo/bson/bsonobj.cpp","line":101}}

We can see that objsize is reported as 15 constantly, so that the expression "arrBuilder->len() + obj.objsize() + 1024) > BSONObjMaxUserSize" will not have the intended effect. This allows two of the documents to be admitted into the array.

I'm opening a ticket to add tests for bsonobj.objsize().

Comment by Lamont Nelson [ 22/Mar/21 ]

I'm seeing that the objsize method of BsonObj in the two links in the ticket description is underreporting the size for the next document, and this allows the array to grow beyond the defined limits as kaloian.manassiev had speculated. I'll post a more detailed message in a bit.

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