[SERVER-8361] CRUD operation fails: cannot update arrays using $set Created: 28/Jan/13  Updated: 08/Mar/13  Resolved: 18/Feb/13

Status: Closed
Project: Core Server
Component/s: Stability, Testing Infrastructure
Affects Version/s: 2.2.2, 2.2.3
Fix Version/s: None

Type: Bug Priority: Critical - P2
Reporter: Janko Thyson Assignee: Stennie Steneker (Inactive)
Resolution: Done Votes: 0
Labels: BSON, Windows, crash, driver, update
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

OS: Windows 7 (64 Bit)
R: 2.15.1
Driver: rmongodb (1.0.5)


Operating System: Windows
Steps To Reproduce:

For a full reproducible example see here: http://stackoverflow.com/questions/14564613/updating-arrays-with-the-set-operator-in-mongodb-rmongodb

Participants:

 Description   

Certain updated constellations either fail and/or crash the server.

// EXAMPLE DOC //

_id : 7      5106887fe2be1937c1e3c8b0
host : 2     host1.com
array : 4    
    0 : 2    value1
    1 : 2    value2
    2 : 2    value3

// EXAMPLE OF UPDATE THAT FAILS //

b <- mongo.bson.from.list(list(
    host="host1.com",
    array="value1"
))
b
mongo.find.one(mongo=con, ns="mytest.hosts", query=b)
value.new <- "othervalue"
bnew <- mongo.bson.from.list(list(
    "$set"=list("array.$"=value.new)
))
res <- mongo.update(mongo=con, ns=ns, criteria=b, objNew=bnew)

// EXCERPT OF ERROR LOG //

Mon Jan 28 15:19:37 [conn1]  mytest.hosts Assertion failure x == _nfields src\mongo\db\jsobj.cpp 1250
Mon Jan 28 15:19:37 [conn1] mongod.exe    ...\src\mongo\util\stacktrace.cpp(182)                           mongo::printStackTrace+0x3e
Mon Jan 28 15:19:37 [conn1] mongod.exe    ...\src\mongo\util\assert_util.cpp(109)                          mongo::verifyFailed+0xdc
Mon Jan 28 15:19:37 [conn1] mongod.exe    ...\src\mongo\db\jsobj.cpp(1250)                                 mongo::BSONIteratorSorted::BSONIteratorSorted+0xf3
Mon Jan 28 15:19:37 [conn1] mongod.exe    ...\src\mongo\db\ops\update_internal.cpp(906)                    mongo::ModSetState::createNewFromMods+0xa3
Mon Jan 28 15:19:37 [conn1] mongod.exe    ...\src\mongo\db\ops\update.cpp(370)                             mongo::_updateObjects+0x15a2
Mon Jan 28 15:19:37 [conn1] mongod.exe    ...\src\mongo\db\instance.cpp(573)                               mongo::receivedUpdate+0x60d
Mon Jan 28 15:19:37 [conn1] mongod.exe    ...\src\mongo\db\instance.cpp(437)                               mongo::assembleResponse+0x626
Mon Jan 28 15:19:37 [conn1] mongod.exe    ...\src\mongo\db\db.cpp(193)                                     mongo::MyMessageHandler::process+0xf5
Mon Jan 28 15:19:37 [conn1] mongod.exe    ...\src\mongo\util\net\message_server_port.cpp(86)               mongo::pms::threadRun+0x59a
Mon Jan 28 15:19:37 [conn1] mongod.exe    ...\src\third_party\boost\libs\thread\src\win32\thread.cpp(180)  boost::`anonymous namespace'::thread_start_function+0x21
Mon Jan 28 15:19:37 [conn1] mongod.exe    f:\dd\vctools\crt_bld\self_64_amd64\crt\src\threadex.c(314)      _callthreadstartex+0x17
Mon Jan 28 15:19:37 [conn1] mongod.exe    f:\dd\vctools\crt_bld\self_64_amd64\crt\src\threadex.c(292)      _threadstartex+0x7f
Mon Jan 28 15:19:37 [conn1] kernel32.dll                                                                   BaseThreadInitThunk+0xd
Mon Jan 28 15:19:37 [conn1] update mytest.hosts query: { host: "host1.com", array: "VALUE1" } update: { $set: { array.$: "othervalue" } } nscanned:1 keyUpdates:0 exception: assertion src\mongo\db\jsobj.cpp:1250 locks(micros) w:343875 344ms
Mon Jan 28 15:20:06 [conn1]  mytest.hosts Assertion failure x == _nfields src\mongo\db\jsobj.cpp 1250
Mon Jan 28 15:20:06 [conn1] mongod.exe    ...\src\mongo\util\stacktrace.cpp(182)                           mongo::printStackTrace+0x3e
Mon Jan 28 15:20:06 [conn1] mongod.exe    ...\src\mongo\util\assert_util.cpp(109)                          mongo::verifyFailed+0xdc
Mon Jan 28 15:20:06 [conn1] mongod.exe    ...\src\mongo\db\jsobj.cpp(1250)                                 mongo::BSONIteratorSorted::BSONIteratorSorted+0xf3
Mon Jan 28 15:20:06 [conn1] mongod.exe    ...\src\mongo\db\ops\update_internal.cpp(906)                    mongo::ModSetState::createNewFromMods+0xa3
Mon Jan 28 15:20:06 [conn1] mongod.exe    ...\src\mongo\db\ops\update.cpp(370)                             mongo::_updateObjects+0x15a2
Mon Jan 28 15:20:06 [conn1] mongod.exe    ...\src\mongo\db\instance.cpp(573)                               mongo::receivedUpdate+0x60d
Mon Jan 28 15:20:06 [conn1] mongod.exe    ...\src\mongo\db\instance.cpp(437)                               mongo::assembleResponse+0x626
Mon Jan 28 15:20:06 [conn1] mongod.exe    ...\src\mongo\db\db.cpp(193)                                     mongo::MyMessageHandler::process+0xf5
Mon Jan 28 15:20:06 [conn1] mongod.exe    ...\src\mongo\util\net\message_server_port.cpp(86)               mongo::pms::threadRun+0x59a
Mon Jan 28 15:20:06 [conn1] mongod.exe    ...\src\third_party\boost\libs\thread\src\win32\thread.cpp(180)  boost::`anonymous namespace'::thread_start_function+0x21
Mon Jan 28 15:20:06 [conn1] mongod.exe    f:\dd\vctools\crt_bld\self_64_amd64\crt\src\threadex.c(314)      _callthreadstartex+0x17
Mon Jan 28 15:20:06 [conn1] mongod.exe    f:\dd\vctools\crt_bld\self_64_amd64\crt\src\threadex.c(292)      _threadstartex+0x7f
Mon Jan 28 15:20:06 [conn1] kernel32.dll                                                                   BaseThreadInitThunk+0xd
Mon Jan 28 15:20:06 [conn1] update mytest.hosts query: { host: "host1.com", array: "value2" } update: { $set: { array.0: "abcd" } } nscanned:1 keyUpdates:0 exception: assertion src\mongo\db\jsobj.cpp:1250 locks(micros) w:344363 345ms
Mon Jan 28 15:20:06 [journal] *** unhandled exception (access violation) at 0x0000000076D632D0, terminating
Mon Jan 28 15:20:06 [journal] *** access violation was a read from 0x0000008301570AD8
Mon Jan 28 15:20:06 [journal] *** stack trace for unhandled exception:
Mon Jan 28 15:20:06 [journal] ntdll.dll                                                                      RtlFreeHeap+0xd0
Mon Jan 28 15:20:06 [journal] kernel32.dll                                                                   HeapFree+0xa
Mon Jan 28 15:20:06 [journal] mongod.exe    f:\dd\vctools\crt_bld\self_64_amd64\crt\src\free.c(51)           free+0x1c
Mon Jan 28 15:20:06 [journal] mongod.exe    ...\src\mongo\db\d_concurrency.cpp(309)                          mongo::Lock::ScopedLock::~ScopedLock+0xac
Mon Jan 28 15:20:06 [journal] mongod.exe                                                                     mongo::Lock::GlobalRead::`scalar deleting destructor'+0x14
Mon Jan 28 15:20:06 [journal] mongod.exe    ...\src\mongo\db\dur.cpp(567)                                    mongo::dur::_groupCommitWithLimitedLocks+0x174
Mon Jan 28 15:20:06 [journal] mongod.exe    ...\src\mongo\db\dur.cpp(608)                                    mongo::dur::groupCommitWithLimitedLocks+0x24
Mon Jan 28 15:20:06 [journal] mongod.exe    ...\src\mongo\db\dur.cpp(743)                                    mongo::dur::durThreadGroupCommit+0x70
Mon Jan 28 15:20:06 [journal] mongod.exe    ...\src\mongo\db\dur.cpp(814)                                    mongo::dur::durThread+0x198
Mon Jan 28 15:20:06 [journal] mongod.exe    ...\src\third_party\boost\libs\thread\src\win32\thread.cpp(180)  boost::`anonymous namespace'::thread_start_function+0x21
Mon Jan 28 15:20:06 [journal] mongod.exe    f:\dd\vctools\crt_bld\self_64_amd64\crt\src\threadex.c(314)      _callthreadstartex+0x17
Mon Jan 28 15:20:06 [journal] mongod.exe    f:\dd\vctools\crt_bld\self_64_amd64\crt\src\threadex.c(292)      _threadstartex+0x7f
Mon Jan 28 15:20:06 [journal] kernel32.dll                                                                   BaseThreadInitThunk+0xd
Mon Jan 28 15:20:06 [journal] writing minidump diagnostic file mongo.dmp
Mon Jan 28 15:20:06 [journal] *** immediate exit due to unhandled exception

For a fully reproducible example see here: http://stackoverflow.com/questions/14564613/updating-arrays-with-the-set-operator-in-mongodb-rmongodb



 Comments   
Comment by Janko Thyson [ 18/Feb/13 ]

@Stephen: right, both issues were caused by the same driver issue. I just didn't have the time to let you guys know last week. I'll post a similar comment in https://jira.mongodb.org/browse/SERVER-8319 as it can also be considered to be resolved.

I really like the --objcheck feature. Yet, it'd be great to have the option to perform this check client-side. Certainly some overhead/somewhat redundant as the server can do it. But with MongoDB/NoSQL-approaches following a rather "base as much of the application logic within the *application*, not the DBMS" paradigm, I think that would just another tiny aspect of it and a great feature for MongoDB drivers.

Best regards,
J

Comment by Stennie Steneker (Inactive) [ 18/Feb/13 ]

Hi Janko,

It looks like this is a similar issue to SERVER-8319, in that passing poorly constructed BSON to the server can cause errors.

As mentioned in SERVER-8319, you can include the --objcheck config option to validate the BSON passed to the server.

FYI, the --objcheck option will be enabled by default in MongoDB 2.4.

Cheers,
Stephen

Comment by Janko Thyson [ 18/Feb/13 ]

Hi everyone,
with the help of Gerald Lindsly, I was able to make some major progress in figuring out where the bad BSON structure comes from. It's definitely caused by the driver for either C and/or R (rmongodb), not the server. AFIU, it was caused due to multiple calls of a "finish BSON buffer object" which corrupted the actual BSON structure but made everything still look OK in my application. IIRC, Gerald will try to implement options to validate BSON structures client-side before passing everything to the server and running the risk that it rejects it.

Not sure what the "ticket procedure" is at this point. It's probably OK to call it a "case closed"? Thanks a lot for everyone that was involved in helping me make progress on this!

Comment by Ian Whalen (Inactive) [ 15/Feb/13 ]

moving from Blocker to Critical since this is not blocking the upcoming 2.4 release.

and please review SERVER-8319 for any overlap.

Generated at Thu Feb 08 03:17:14 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.