[SERVER-64860] Transactions fail with TransactionTooLarge instead of generating multiple applyOps Created: 24/Mar/22  Updated: 29/Oct/23  Resolved: 25/Mar/22

Status: Closed
Project: Core Server
Component/s: None
Affects Version/s: None
Fix Version/s: 6.0.0-rc0

Type: Bug Priority: Major - P3
Reporter: Josef Ahmad Assignee: Mindaugas Malinauskas
Resolution: Fixed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Backwards Compatibility: Fully Compatible
Operating System: ALL
Steps To Reproduce:

db.c.insertMany([...Array(400000).keys()].map(x => ({_id: x})));
const session = db.getMongo().startSession();
const coll = session.getDatabase('test').c
session.startTransaction();coll.deleteMany({_id: {$gte: 0}});
session.commitTransaction();

Sprint: QE 2022-04-04
Participants:

 Description   

SERVER-62785 introduced a regression that fails transactions which would previously succeed and generate multiple applyOps entries. The regression can be reproduced deleting a large amount of small documents in a single transaction such that the committed operation would span across multiple applyOps.



 Comments   
Comment by Githook User [ 25/Mar/22 ]

Author:

{'name': 'Mindaugas Malinauskas', 'email': 'mindaugas.malinauskas@mongodb.com'}

Message: SERVER-64860 Tighten up "applyOps" oplog entry size computation
Branch: master
https://github.com/mongodb/mongo/commit/5564cf6f7cdb65ef6eb4323d320d1bba4f303e33

Comment by Josef Ahmad [ 24/Mar/22 ]

Output from the reproducer:

Error: command failed: {
	"ok" : 0,
	"errmsg" : "BSONObj size: 18431811 (0x1193F43) is invalid. Size must be between 0 and 16793600(16MB) First element: 0: { op: \"d\", ns: \"test.c\", ui: UUID(\"5bd73d86-7e79-4f70-88e7-31d2505fe0eb\"), o: { _id: 0.0 } }",
	"code" : 257,
	"codeName" : "TransactionTooLarge",
	"$clusterTime" : {
		"clusterTime" : Timestamp(1648108576, 400000),
		"signature" : {
			"hash" : BinData(0,"AAAAAAAAAAAAAAAAAAAAAAAAAAA="),
			"keyId" : NumberLong(0)
		}
	},
	"operationTime" : Timestamp(1648108567, 26000)
} with original command request: {
	"commitTransaction" : 1,
	"txnNumber" : NumberLong(0),
	"lsid" : {
		"id" : UUID("903c2d98-5075-4b16-9401-e9828585257c")
	},
	"$clusterTime" : {
		"clusterTime" : Timestamp(1648108567, 26000),
		"signature" : {
			"hash" : BinData(0,"AAAAAAAAAAAAAAAAAAAAAAAAAAA="),
			"keyId" : NumberLong(0)
		}
	},
	"autocommit" : false,
	"stmtId" : NumberInt(1)
}

Backtrace:

Thread 68 "conn14" hit Breakpoint 1, mongo::BSONObj::_assertInvalid (this=0x7f7dada209b0, maxSize=16793600) at src/mongo/bson/bsonobj.cpp:100
100	    massert(ErrorCodes::BSONObjectTooLarge, ss.str(), 0);
(gdb) bt 15
#0  mongo::BSONObj::_assertInvalid (this=0x7f7dada209b0, maxSize=16793600) at src/mongo/bson/bsonobj.cpp:100
#1  0x00007f7df5f35cbd in mongo::BSONObj::init<mongo::BSONObj::DefaultSizeTrait> (this=0x7f7dada209b0, data=0x7f7d6e7a6036 "Sl\020\001\003\060") at src/mongo/bson/bsonobj.h:708
#2  0x00007f7df5f35c35 in mongo::BSONObj::BSONObj<mongo::BSONObj::DefaultSizeTrait> (this=0x7f7dada209b0, bsonData=0x7f7d6e7a6036 "Sl\020\001\003\060", t=...) at src/mongo/bson/bsonobj.h:143
#3  0x00007f7df5f343ef in mongo::BSONObjBuilderBase<mongo::BSONObjBuilder, mongo::BufBuilder>::done<mongo::BSONObj::DefaultSizeTrait> (this=0x7f7dada20a40) at src/mongo/bson/bsonobjbuilder.h:579
#4  0x00007f7df5fa1e60 in mongo::BSONArrayBuilderBase<mongo::BSONArrayBuilder, mongo::BSONObjBuilder>::done (this=0x7f7dada20a30) at src/mongo/bson/bsonobjbuilder.h:957
#5  0x00007f7dee31ca5f in mongo::(anonymous namespace)::packTransactionStatementsForApplyOps (applyOpsBuilder=0x7f7dada20e30, stmtIdsWritten=0x7f7dada20d70, imageToWrite=0x7f7dada21128, stmtBegin=..., stmtEnd=..., operations=...) at src/mongo/db/op_observer_impl.cpp:1566
#6  0x00007f7dee319247 in mongo::(anonymous namespace)::logOplogEntries (opCtx=0x7f7d95f1e8e0, stmts=0x7f7d974cc430, oplogSlots=..., applyOpsOperationAssignment=..., prePostImageToWriteToImageCollection=0x7f7dada21230, numberOfPrePostImagesToWrite=0, prepare=false, wallClockTime=...) at src/mongo/db/op_observer_impl.cpp:1755
#7  0x00007f7dee319e5a in mongo::OpObserverImpl::onBatchedWriteCommit (this=0x7f7dc2af80a0, opCtx=0x7f7d95f1e8e0) at src/mongo/db/op_observer_impl.cpp:1985
#8  0x00007f7df5171a83 in mongo::OpObserverRegistry::onBatchedWriteCommit (this=0x7f7dc29b48d0, opCtx=0x7f7d95f1e8e0) at src/mongo/db/op_observer_registry.h:436
#9  0x00007f7dd391f640 in mongo::WriteUnitOfWork::commit (this=0x7f7dada21578) at src/mongo/db/storage/write_unit_of_work.cpp:132
#10 0x00007f7de5f9159a in mongo::BatchedDeleteStage::_deleteBatch (this=0x7f7d9cde2560, out=0x7f7dada21a20) at src/mongo/db/exec/batched_delete_stage.cpp:201
#11 0x00007f7de5f91d5c in mongo::BatchedDeleteStage::doWork (this=0x7f7d9cde2560, out=0x7f7dada21a20) at src/mongo/db/exec/batched_delete_stage.cpp:254
#12 0x00007f7de5f759bc in mongo::PlanStage::work (this=0x7f7d9cde2560, out=0x7f7dada21a20) at src/mongo/db/exec/plan_stage.h:207
#13 0x00007f7de61668b6 in mongo::PlanExecutorImpl::_getNextImpl (this=0x7f7d974efce0, objOut=0x7f7dada21b28, dlOut=0x0) at src/mongo/db/query/plan_executor_impl.cpp:367
#14 0x00007f7de6166448 in mongo::PlanExecutorImpl::getNextDocument (this=0x7f7d974efce0, objOut=0x7f7dada21b98, dlOut=0x0) at src/mongo/db/query/plan_executor_impl.cpp:319

Generated at Thu Feb 08 06:01:19 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.