[SERVER-2658] map reduce foundindex assertion in repl basic1 test Created: 01/Mar/11  Updated: 12/Jul/16  Resolved: 02/Mar/11

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

Type: Bug Priority: Major - P3
Reporter: Aaron Staple Assignee: Eliot Horowitz (Inactive)
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Operating System: ALL
Participants:

 Description   

m31001| Thu Feb 24 21:25:56 [conn1] Assertion failure foundIndex db/commands/mr.cpp 587
m31001| 0x817e6eb 0x8193713 0x84716b5 0x847ee28 0x84416a1 0x8443d14 0x82883dc 0x828d96f 0x83b2d87 0x83b5adc 0x8520cb3 0x81f9598 0x853569d 0x79d542 0x1e5b6e
m31001| /mnt/slaves/Linux_32bit/mongo/mongod(_ZN5mongo12sayDbContextEPKc+0xcb) [0x817e6eb]
m31001| /mnt/slaves/Linux_32bit/mongo/mongod(_ZN5mongo8assertedEPKcS1_j+0x143) [0x8193713]
m31001| /mnt/slaves/Linux_32bit/mongo/mongod(_ZN5mongo2mr5State11finalReduceEPNS_5CurOpERNS_19ProgressMeterHolderE+0x565) [0x84716b5]
m31001| /mnt/slaves/Linux_32bit/mongo/mongod(_ZN5mongo2mr16MapReduceCommand3runERKSsRNS_7BSONObjERSsRNS_14BSONObjBuilderEb+0xf78) [0x847ee28]
m31001| /mnt/slaves/Linux_32bit/mongo/mongod(_ZN5mongo11execCommandEPNS_7CommandERNS_6ClientEiPKcRNS_7BSONObjERNS_14BSONObjBuilderEb+0x211) [0x84416a1]
m31001| /mnt/slaves/Linux_32bit/mongo/mongod(_ZN5mongo12_runCommandsEPKcRNS_7BSONObjERNS_10BufBuilderERNS_14BSONObjBuilderEbi+0x694) [0x8443d14]
m31001| /mnt/slaves/Linux_32bit/mongo/mongod(_ZN5mongo11runCommandsEPKcRNS_7BSONObjERNS_5CurOpERNS_10BufBuilderERNS_14BSONObjBuilderEbi+0x4c) [0x82883dc]
m31001| /mnt/slaves/Linux_32bit/mongo/mongod(ZN5mongo8runQueryERNS_7MessageERNS_12QueryMessageERNS_5CurOpES1+0x2e6f) [0x828d96f]
m31001| /mnt/slaves/Linux_32bit/mongo/mongod [0x83b2d87]
m31001| /mnt/slaves/Linux_32bit/mongo/mongod(_ZN5mongo16assembleResponseERNS_7MessageERNS_10DbResponseERKNS_8SockAddrE+0x70c) [0x83b5adc]
m31001| /mnt/slaves/Linux_32bit/mongo/mongod(_ZN5mongo10connThreadEPNS_13MessagingPortE+0x273) [0x8520cb3]
m31001| /mnt/slaves/Linux_32bit/mongo/mongod(_ZN5boost6detail11thread_dataINS_3_bi6bind_tIvPFvPN5mongo13MessagingPortEENS2_5list1INS2_5valueIS6_EEEEEEE3runEv+0x18) [0x81f9598]
m31001| /mnt/slaves/Linux_32bit/mongo/mongod(thread_proxy+0x7d) [0x853569d]
Thu Feb 24 21:25:56 uncaught exception: map reduce failed:{
"assertion" : "assertion db/commands/mr.cpp:587",
"errmsg" : "db assertion failure",
"ok" : 0
}
m31001| /lib/i686/nosegneg/libpthread.so.0 [0x79d542]
failed to load: /mnt/slaves/Linux_32bit/mongo/jstests/repl/basic1.js
m31001| /lib/i686/nosegneg/libc.so.6(clone+0x5e) [0x1e5b6e]

<http://buildbot.mongodb.org/builders/Linux%2032-bit/builds/2855/steps/test_4/logs/stdio>



 Comments   
Comment by auto [ 02/Mar/11 ]

Author:

{u'login': u'erh', u'name': u'Eliot Horowitz', u'email': u'eliot@10gen.com'}

Message: fix mr test SERVER-2658
https://github.com/mongodb/mongo/commit/8fcdd4c30e08380d730b4301a7e78f93de0de7f5

Comment by auto [ 02/Mar/11 ]

Author:

{u'login': u'erh', u'name': u'Eliot Horowitz', u'email': u'eliot@10gen.com'}

Message: fix mr test SERVER-2658
https://github.com/mongodb/mongo/commit/8fcdd4c30e08380d730b4301a7e78f93de0de7f5

Comment by Aaron Staple [ 02/Mar/11 ]

It's not my test, but I am seeing:

m31001| Thu Feb 24 21:25:56 [replslave] building new index on

{ _id: 1 }

for foo.mr
m31001| Thu Feb 24 21:25:56 [replslave] done for 0 records 0secs
m31001| Thu Feb 24 21:25:56 [conn1] CMD: drop foo.tmp.mr.mr_basic1_out_0
m31001| Thu Feb 24 21:25:56 [conn1] CMD: drop foo.tmp.mr.mr_basic1_out_0_inc
m31001| Thu Feb 24 21:25:56 [conn1] building new index on

{ 0: 1 }

for foo.tmp.mr.mr_basic1_out_0_inc
m31001| Thu Feb 24 21:25:56 [conn1] done for 0 records 0secs
m31001| 0
m31001| 0
m31001| 1
m31001| Thu Feb 24 21:25:56 [conn1] CMD: drop foo.tmp.mr.mr_basic1_out_0
m31001| Thu Feb 24 21:25:56 [replslave] building new index on

{ _id: 1 }

for foo.tmp.mr.mr_basic1_out_0
m31001| Thu Feb 24 21:25:56 [replslave] done for 0 records 0secs
m31001| Thu Feb 24 21:25:56 [replslave] CMD: drop foo.tmp.mr.mr_basic1_out_0_inc
m31001| Thu Feb 24 21:25:56 [conn1] building new index on

{ _id: 1 }

for foo.tmp.mr.mr_basic1_out_0
m31001| Thu Feb 24 21:25:56 [conn1] done for 0 records 0secs
m31001| Thu Feb 24 21:25:56 [conn1] Assertion failure foundIndex db/commands/mr.cpp 587

So it looks like the slave is creating an index on the _inc collection, then as part of replication it drops the _inc collection, then it asserts because it can't find an index for the _inc collection.

Just having glanced at the test script it looks like the same m/r operations are running on both the master and slave - though not sure on the order of events with reference to the test script.

Comment by Eliot Horowitz (Inactive) [ 02/Mar/11 ]

Why is this running against the slave anyway?
I'm confused where this is even happening.

Comment by Aaron Staple [ 01/Mar/11 ]

Would it make sense to have some sort of policy of not replicating temp / output collections to slaves - or else putting a machine unique component in the auto generated collection names?

Comment by Aaron Staple [ 01/Mar/11 ]

From the logs it looks like the master is dropping its temp collection, so the slave drops its temp collection as well. And this happens while the slave m/r task is yielding and is not expecting the temp collection to suddenly disappear.

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