Replica Set : Secondary always aborts

[Thomas]

Hello,

I'm trying to set a replica set on my plateform but it's unsuccessful since the SECONDARY always failed by exiting and writting a message shown in the PS section.

I feel that the issue came from the fact that my collection has an _id field that is not an index.

nws_rs_1:PRIMARY> db.record.stats()

{

"ns" : "nadb.record",

"count" : 1599426,

"size" : 4766719236,

"avgObjSize" : 2980.2686938939346,

"storageSize" : 8696713216,

"numExtents" : 33,

"nindexes" : 1,

"lastExtentSize" : 1940869120,

"paddingFactor" : 1.0010000004921944,

"systemFlags" : 0,

"userFlags" : 0,

"totalIndexSize" : 103508160,

"indexSizes" : {

"_id_L_1__id_K_1" : 103508160

},

"ok" : 1

}

Can you confirm that the problem comes from the fact that _id is not an index ? Or do you have any other idea where the issue could come from ?

BR,

Thomas.

PS : Error returned by Secondary :

Wed Oct 24 17:07:54 [repl writer worker 1] replication couldn't find doc: { ts: Timestamp 1351091117000|1, h: -7888475657595607546, op: "u", ns: "nadb.record", o2: { _id: { K: 1351029600.0, L: "70:ee:50:00:19:60" }, 02:00:00:00:15:c0.R: { $size: 198 }, 70:ee:50:00:19:60.R: { $size: 198 } }, o: { $set: { 02:00:00:00:15:c0.(: 5040625.0 }, $set: { 02:00:00:00:15:c0.): 204.0 }, $pushAll: { 02:00:00:00:15:c0.R: [ { a: 16.40000024437904, b: 88, #: 23469, K: 1351089578.0 }, { a: 16.40000024437904, b: 88, #: 23458, K: 1351089886.0 }, { a: 16.40000024437904, b: 88, #: 23453, K: 1351090194.0 }, { a: 16.40000024437904, b: 88, #: 23461, K: 1351090450.0 }, { a: 16.40000024437904, b: 88, #: 23450, K: 1351090758.0 }, { a: 16.40000024437904, b: 88, #: 23452, K: 1351091065.0 } ] }, $set: { 02:00:00:00:15:c0.i: 2622.300039075315 }, $set: { 02:00:00:00:15:c0.j: 204.0 }, $set: { 02:00:00:00:15:c0.m: 19593.0 }, $set: { 02:00:00:00:15:c0.n: 204.0 }, $set: { 70:ee:50:00:19:60.£: 204.0 }, $set: { 70:ee:50:00:19:60.(: 2009877.0 }, $set: { 70:ee:50:00:19:60.): 204.0 }, $set: { 70:ee:50:00:19:60.+: 204732.503050752 }, $set: { 70:ee:50:00:19:60.G: 213370.0 }, $set: { 70:ee:50:00:19:60.H: 204.0 }, $pushAll: { 70:ee:50:00:19:60.R: [ { a: 22.40000033378601, b: 62, ': 1001.100014917552, e: 1015.8000151366, S: 51, h: 1273, #: 9848, K: 1351089595.0 }, { a: 22.40000033378601, b: 62, ': 1001.200014919043, e: 1015.90001513809, S: 58, h: 1273, #: 9849, K: 1351089895.0 }, { a: 22.40000033378601, b: 62, ': 1001.100014917552, e: 1015.8000151366, S: 54, h: 1294, #: 9848, K: 1351090199.0 }, { a: 22.40000033378601, b: 62, ': 1001.000014916062, e: 1015.700015135109, S: 53, h: 1352, #: 9848, K: 1351090500.0 }, { a: 22.50000033527613, b: 62, ': 1001.100014917552, e: 1015.8000151366, S: 52, h: 1367, #: 9849, K: 1351090804.0 }, { a: 22.50000033527613, b: 62, ': 1000.900014914572, e: 1015.600015133619, S: 53, h: 1363, #: 9848, K: 1351091104.0 } ] }, $set: { 70:ee:50:00:19:60.V: 9030.0 }, $set: { 70:ee:50:00:19:60.W: 204.0 }, $set: { 70:ee:50:00:19:60.i: 4352.700064860284 }, $set: { 70:ee:50:00:19:60.j: 204.0 }, $set: { 70:ee:50:00:19:60.m: 12777.0 }, $set: { 70:ee:50:00:19:60.n: 204.0 }, $set: { 70:ee:50:00:19:60.y: 207732.8030954599 }, $set: { 70:ee:50:00:19:60.z: 204.0 } } }

Wed Oct 24 17:07:54 [repl writer worker 1] replication info adding missing object

Wed Oct 24 17:07:58 [repl writer worker 1] replication couldn't find doc: { ts: Timestamp 1351091117000|1, h: -7888475657595607546, op: "u", ns: "nadb.record", o2: { _id: { K: 1351029600.0, L: "70:ee:50:00:19:60" }, 02:00:00:00:15:c0.R: { $size: 198 }, 70:ee:50:00:19:60.R: { $size: 198 } }, o: { $set: { 02:00:00:00:15:c0.(: 5040625.0 }, $set: { 02:00:00:00:15:c0.): 204.0 }, $pushAll: { 02:00:00:00:15:c0.R: [ { a: 16.40000024437904, b: 88, #: 23469, K: 1351089578.0 }, { a: 16.40000024437904, b: 88, #: 23458, K: 1351089886.0 }, { a: 16.40000024437904, b: 88, #: 23453, K: 1351090194.0 }, { a: 16.40000024437904, b: 88, #: 23461, K: 1351090450.0 }, { a: 16.40000024437904, b: 88, #: 23450, K: 1351090758.0 }, { a: 16.40000024437904, b: 88, #: 23452, K: 1351091065.0 } ] }, $set: { 02:00:00:00:15:c0.i: 2622.300039075315 }, $set: { 02:00:00:00:15:c0.j: 204.0 }, $set: { 02:00:00:00:15:c0.m: 19593.0 }, $set: { 02:00:00:00:15:c0.n: 204.0 }, $set: { 70:ee:50:00:19:60.£: 204.0 }, $set: { 70:ee:50:00:19:60.(: 2009877.0 }, $set: { 70:ee:50:00:19:60.): 204.0 }, $set: { 70:ee:50:00:19:60.+: 204732.503050752 }, $set: { 70:ee:50:00:19:60.G: 213370.0 }, $set: { 70:ee:50:00:19:60.H: 204.0 }, $pushAll: { 70:ee:50:00:19:60.R: [ { a: 22.40000033378601, b: 62, ': 1001.100014917552, e: 1015.8000151366, S: 51, h: 1273, #: 9848, K: 1351089595.0 }, { a: 22.40000033378601, b: 62, ': 1001.200014919043, e: 1015.90001513809, S: 58, h: 1273, #: 9849, K: 1351089895.0 }, { a: 22.40000033378601, b: 62, ': 1001.100014917552, e: 1015.8000151366, S: 54, h: 1294, #: 9848, K: 1351090199.0 }, { a: 22.40000033378601, b: 62, ': 1001.000014916062, e: 1015.700015135109, S: 53, h: 1352, #: 9848, K: 1351090500.0 }, { a: 22.50000033527613, b: 62, ': 1001.100014917552, e: 1015.8000151366, S: 52, h: 1367, #: 9849, K: 1351090804.0 }, { a: 22.50000033527613, b: 62, ': 1000.900014914572, e: 1015.600015133619, S: 53, h: 1363, #: 9848, K: 1351091104.0 } ] }, $set: { 70:ee:50:00:19:60.V: 9030.0 }, $set: { 70:ee:50:00:19:60.W: 204.0 }, $set: { 70:ee:50:00:19:60.i: 4352.700064860284 }, $set: { 70:ee:50:00:19:60.j: 204.0 }, $set: { 70:ee:50:00:19:60.m: 12777.0 }, $set: { 70:ee:50:00:19:60.n: 204.0 }, $set: { 70:ee:50:00:19:60.y: 207732.8030954599 }, $set: { 70:ee:50:00:19:60.z: 204.0 } } }

Wed Oct 24 17:07:58 [repl writer worker 1]   Fatal Assertion 15915

0xade6e1 0x802e03 0x65047c 0x77d3dd 0x7c3659 0x7f1cad8aae9a 0x7f1cacbbdcbd

 /usr/bin/mongod(_ZN5mongo15printStackTraceERSo+0x21) [0xade6e1]

 /usr/bin/mongod(_ZN5mongo13fassertFailedEi+0xa3) [0x802e03]

 /usr/bin/mongod(_ZN5mongo7replset21multiInitialSyncApplyERKSt6vectorINS_7BSONObjESaIS2_EEPNS0_8SyncTailE+0x9c) [0x65047c]

 /usr/bin/mongod(_ZN5mongo10threadpool6Worker4loopEv+0x26d) [0x77d3dd]

 /usr/bin/mongod() [0x7c3659]

 /lib/x86_64-linux-gnu/libpthread.so.0(+0x7e9a) [0x7f1cad8aae9a]

 /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d) [0x7f1cacbbdcbd]

Wed Oct 24 17:07:58 [repl writer worker 1]

***aborting after fassert() failure

Wed Oct 24 17:07:58 Got signal: 6 (Aborted).

Wed Oct 24 17:07:58 Backtrace:

0xade6e1 0x5582d9 0x7f1cacb004a0 0x7f1cacb00425 0x7f1cacb03b8b 0x802e3e 0x65047c 0x77d3dd 0x7c3659 0x7f1cad8aae9a 0x7f1cacbbdcbd

 /usr/bin/mongod(_ZN5mongo15printStackTraceERSo+0x21) [0xade6e1]

 /usr/bin/mongod(_ZN5mongo10abruptQuitEi+0x399) [0x5582d9]

 /lib/x86_64-linux-gnu/libc.so.6(+0x364a0) [0x7f1cacb004a0]

 /lib/x86_64-linux-gnu/libc.so.6(gsignal+0x35) [0x7f1cacb00425]

 /lib/x86_64-linux-gnu/libc.so.6(abort+0x17b) [0x7f1cacb03b8b]

 /usr/bin/mongod(_ZN5mongo13fassertFailedEi+0xde) [0x802e3e]

 /usr/bin/mongod(_ZN5mongo7replset21multiInitialSyncApplyERKSt6vectorINS_7BSONObjESaIS2_EEPNS0_8SyncTailE+0x9c) [0x65047c]

[Jenna deBoisblanc]

Yes, did you drop the index on _id? If so, you should recreate this index before attempting to resync the secondary.

The index "_id_L_1__id_K_1" is semantically different. For the document,

{_id: {K: val1, L: val2}}

> db.collection.ensureIndex({_id.L: 1, id.K: 1})

creates index entries in the form,

{_id.K: val1, _id.L: val2}

whereas, 

> db.collection.ensureIndex({_id: 1})
creates index entries in the form,

{K: val1, L: val2}

[Thomas]

Yes i explicitely create the record collection without any _id indexes, since i only needed _id_L_1__id_K_1 as an index.

Since I was not using replica there were not issue with that.

I will create the index

Thank you,

Thomas.

[Thomas]

I'have indexed every collection that was not indexed.

I restart a new replication to a new instance and I still have the same issue !!!

Any idea on what could be wrong ? (That is not the index apparently ...)

Thomas.

Thu Oct 25 10:17:45 [repl writer worker 1] replication info adding missing object

Thu Oct 25 10:17:46 [repl writer worker 1] replication couldn't find doc: { ts: Timestamp 1351152744000|3, h: -2081251096167342483, op: "u", ns: "nadb.record", o2: { _id: { K: 1351116000.0, L: "70:ee:50:00:0a:9e" }, 02:00:00:00:0b:98.R: { $size: 116 }, 70:ee:50:00:0a:9e.R: { $size: 116 } }, o: { $set: { 02:00:00:00:0b:98.(: 2443974.0 }, $set: { 02:00:00:00:0b:98.): 122.0 }, $pushAll: { 02:00:00:00:0b:98.R: [ { a: 15.60000023245811, b: 83, #: 21233, K: 1351151199.0 }, { a: 15.60000023245811, b: 83, #: 21222, K: 1351151507.0 }, { a: 15.70000023394823, b: 83, #: 21223, K: 1351151815.0 }, { a: 15.70000023394823, b: 83, #: 21227, K: 1351152071.0 }, { a: 15.80000023543835, b: 83, #: 21233, K: 1351152379.0 }, { a: 15.90000023692846, b: 83, #: 21237, K: 1351152686.0 } ] }, $set: { 02:00:00:00:0b:98.i: 1956.600029155612 }, $set: { 02:00:00:00:0b:98.j: 122.0 }, $set: { 02:00:00:00:0b:98.m: 9990.0 }, $set: { 02:00:00:00:0b:98.n: 122.0 }, $set: { 70:ee:50:00:0a:9e.£: 122.0 }, $set: { 70:ee:50:00:0a:9e.(: 2189145.0 }, $set: { 70:ee:50:00:0a:9e.): 122.0 }, $set: { 70:ee:50:00:0a:9e.+: 120899.2018015385 }, $set: { 70:ee:50:00:0a:9e.G: 43999.0 }, $set: { 70:ee:50:00:0a:9e.H: 122.0 }, $pushAll: { 70:ee:50:00:0a:9e.R: [ { a: 21.1000003144145, b: 63, ': 990.6000147610903, e: 1015.700015135109, S: 38, h: 359, #: 17943, K: 1351151211.0 }, { a: 21.1000003144145, b: 63, ': 991.200014770031, e: 1016.30001514405, S: 38, h: 359, #: 17947, K: 1351151515.0 }, { a: 21.1000003144145, b: 63, ': 991.3000147715211, e: 1016.40001514554, S: 37, h: 365, #: 17943, K: 1351151815.0 }, { a: 21.1000003144145, b: 63, ': 991.3000147715211, e: 1016.40001514554, S: 38, h: 355, #: 17942, K: 1351152119.0 }, { a: 21.1000003144145, b: 63, ': 991.200014770031, e: 1016.30001514405, S: 38, h: 359, #: 17943, K: 1351152424.0 }, { a: 21.1000003144145, b: 63, ': 990.7000147625804, e: 1015.8000151366, S: 37, h: 361, #: 17943, K: 1351152728.0 } ] }, $set: { 70:ee:50:00:0a:9e.V: 4630.0 }, $set: { 70:ee:50:00:0a:9e.W: 122.0 }, $set: { 70:ee:50:00:0a:9e.i: 2560.400038152933 }, $set: { 70:ee:50:00:0a:9e.j: 122.0 }, $set: { 70:ee:50:00:0a:9e.m: 7659.0 }, $set: { 70:ee:50:00:0a:9e.n: 122.0 }, $set: { 70:ee:50:00:0a:9e.y: 123961.4018471688 }, $set: { 70:ee:50:00:0a:9e.z: 122.0 } } }

Thu Oct 25 10:17:46 [repl writer worker 1]   Fatal Assertion 15915

0xade6e1 0x802e03 0x65047c 0x77d3dd 0x7c3659 0x7f84d36a9e9a 0x7f84d29bccbd 

 /usr/bin/mongod(_ZN5mongo15printStackTraceERSo+0x21) [0xade6e1]

 /usr/bin/mongod(_ZN5mongo13fassertFailedEi+0xa3) [0x802e03]

 /usr/bin/mongod(_ZN5mongo7replset21multiInitialSyncApplyERKSt6vectorINS_7BSONObjESaIS2_EEPNS0_8SyncTailE+0x9c) [0x65047c]

 /usr/bin/mongod(_ZN5mongo10threadpool6Worker4loopEv+0x26d) [0x77d3dd]

 /usr/bin/mongod() [0x7c3659]

 /lib/x86_64-linux-gnu/libpthread.so.0(+0x7e9a) [0x7f84d36a9e9a]

 /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d) [0x7f84d29bccbd]

Thu Oct 25 10:17:46 [repl writer worker 1] 

***aborting after fassert() failure

Thu Oct 25 10:17:46 Got signal: 6 (Aborted).

Thu Oct 25 10:17:46 Backtrace:

0xade6e1 0x5582d9 0x7f84d28ff4a0 0x7f84d28ff425 0x7f84d2902b8b 0x802e3e 0x65047c 0x77d3dd 0x7c3659 0x7f84d36a9e9a 0x7f84d29bccbd 

 /usr/bin/mongod(_ZN5mongo15printStackTraceERSo+0x21) [0xade6e1]

 /usr/bin/mongod(_ZN5mongo10abruptQuitEi+0x399) [0x5582d9]

 /lib/x86_64-linux-gnu/libc.so.6(+0x364a0) [0x7f84d28ff4a0]

 /lib/x86_64-linux-gnu/libc.so.6(gsignal+0x35) [0x7f84d28ff425]

 /lib/x86_64-linux-gnu/libc.so.6(abort+0x17b) [0x7f84d2902b8b]

 /usr/bin/mongod(_ZN5mongo13fassertFailedEi+0xde) [0x802e3e]

 /usr/bin/mongod(_ZN5mongo7replset21multiInitialSyncApplyERKSt6vectorINS_7BSONObjESaIS2_EEPNS0_8SyncTailE+0x9c) [0x65047c]

 /usr/bin/mongod(_ZN5mongo10threadpool6Worker4loopEv+0x26d) [0x77d3dd]

 /usr/bin/mongod() [0x7c3659]

 /lib/x86_64-linux-gnu/libpthread.so.0(+0x7e9a) [0x7f84d36a9e9a]

 /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d) [0x7f84d29bccbd]

[Jenna deBoisblanc]

For anyone who may be interested, the resolution to this issue can be found in Jira:

https://jira.mongodb.org/browse/SERVER-7466

On Wednesday, October 24, 2012 1:02:13 PM UTC-4, Thomas wrote: