[SERVER-8313] Why slave always crash due to duplicated key? Created: 24/Jan/13  Updated: 10/Dec/14  Resolved: 28/Oct/13

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

Type: Question Priority: Major - P3
Reporter: Dong Wei Assignee: Unassigned
Resolution: Incomplete Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

CentOS 6.3


Participants:

 Description   

We have several shardings, each sharding has 3 nodes(1 primary, 1 slave, 1 arbiter). On one of those shardings, slave crashes for many times due to the same reason:

========================================================================================================================
Log from slave node:

Mon Jan 14 20:17:16 [rsBackgroundSync] replSet syncing to: test-mongodb-online01.company.internal:27018
Mon Jan 14 20:17:17 [conn361741] end connection 10.10.111.111:7099 (131 connections now open)
Mon Jan 14 20:17:17 [rsSync] replSet error possible failover clock skew issue? 50f3f741:305
Mon Jan 14 20:17:17 [conn361832] end connection 10.10.112.112:13124 (130 connections now open)
Mon Jan 14 20:17:17 [repl writer worker 1] ERROR: writer worker caught exception: E11000 duplicate key error index: test.test.$user_id_1_doc_id_1 dup key: { : "40b2d10559dd731750839a20b78ac075", : 331282 } on: { ts: Timestamp 1358165814000|175, h: -7276577398417103929, v: 2, op: "i", ns: "test.test", o:

{ _id: "2013-01-14_40b2d10559dd731750839a20b78ac075_331282", user_id: "40b2d10559dd731750839a20b78ac075", doc_id: 331282, col1: 277939, col2: 31, col3: -1, col4: 1358165766, col5: 2 }

}
Mon Jan 14 20:17:17 [repl writer worker 1] Fatal Assertion 16360
0xaffd31 0xac5323 0x9a2e56 0xad35cd 0xb45ba9 0x3d56407851 0x3d560e767d
/usr/bin/mongod(_ZN5mongo15printStackTraceERSo+0x21) [0xaffd31]
/usr/bin/mongod(_ZN5mongo13fassertFailedEi+0xa3) [0xac5323]
/usr/bin/mongod(_ZN5mongo7replset14multiSyncApplyERKSt6vectorINS_7BSONObjESaIS2_EEPNS0_8SyncTailE+0x156) [0x9a2e56]
/usr/bin/mongod(_ZN5mongo10threadpool6Worker4loopEv+0x26d) [0xad35cd]
/usr/bin/mongod() [0xb45ba9]
/lib64/libpthread.so.0() [0x3d56407851]
/lib64/libc.so.6(clone+0x6d) [0x3d560e767d]
Mon Jan 14 20:17:17 [repl writer worker 1]

***aborting after fassert() failure

========================================================================================================================

The following shows the indexes of our collection, user_id is our shard key:

test1:PRIMARY> use test
switched to db test
test1:PRIMARY> db.test.getIndexes()
[
{
"v" : 1,
"key" :

{ "_id" : 1 }

,
"ns" : "test.test",
"name" : "id"
},
{
"v" : 1,
"key" :

{ "user_id" : 1 }

,
"ns" : "test.test",
"name" : "user_id_1"
},
{
"v" : 1,
"key" :

{ "user_id" : 1, "doc_id" : 1 }

,
"unique" : true,
"ns" : "test.test",
"name" : "user_id_1_doc_id_1"
}
]

We have examined the oplog regarding the specific key, and we don't find any clues that we break the idempotency. Could anyone give me some advices? Thanks.

test1:PRIMARY> use local
switched to db local
test1:PRIMARY> db.oplog.rs.find(

{ "op" : "i", "o.user_id" : "40b2d10559dd731750839a20b78ac075" }

)
{ "ts" : Timestamp(1358165814000, 175), "h" : NumberLong("-7276577398417103929"), "v" : 2, "op" : "i", "ns" : "test.test", "o" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282", "user_id" : "40b2d10559dd731750839a20b78ac075", "doc_id" : 331282, "col1" : 277939, "col2" : 31, "col3" : -1, "col4" : 1358165766, "col5" : 2 }

}

test1:PRIMARY> db.oplog.rs.find(

{ "op" : "u", "o2._id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

)
{ "ts" : Timestamp(1358165862000, 502), "h" : NumberLong("-2969379546764696617"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358165857 }

, "$set" :

{ "col4" : 1358165857 }

, "$set" :

{ "col4" : 1358165857 }

, "$set" :

{ "col4" : 1358165857 }

, "$set" :

{ "col4" : 1358165857 }

} }
{ "ts" : Timestamp(1358165862000, 847), "h" : NumberLong("-9174841252872684216"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358165860 }

, "$set" :

{ "col4" : 1358165860 }

, "$set" :

{ "col4" : 1358165860 }

, "$set" :

{ "col4" : 1358165860 }

, "$set" :

{ "col4" : 1358165860 }

} }
{ "ts" : Timestamp(1358165865000, 819), "h" : NumberLong("8728551110388921671"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358165860 }

, "$set" :

{ "col4" : 1358165860 }

, "$set" :

{ "col4" : 1358165860 }

, "$set" :

{ "col4" : 1358165860 }

, "$set" :

{ "col4" : 1358165860 }

} }
{ "ts" : Timestamp(1358165866000, 149), "h" : NumberLong("-5398085733751542631"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358165860 }

, "$set" :

{ "col4" : 1358165860 }

, "$set" :

{ "col4" : 1358165860 }

, "$set" :

{ "col4" : 1358165860 }

, "$set" :

{ "col4" : 1358165860 }

} }
{ "ts" : Timestamp(1358165868000, 974), "h" : NumberLong("-472422500396759906"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358165862 }

, "$set" :

{ "col4" : 1358165862 }

, "$set" :

{ "col4" : 1358165862 }

, "$set" :

{ "col4" : 1358165862 }

, "$set" :

{ "col4" : 1358165862 }

} }
{ "ts" : Timestamp(1358165869000, 1635), "h" : NumberLong("-2936801391795544718"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358165847 }

, "$set" :

{ "col4" : 1358165847 }

, "$set" :

{ "col4" : 1358165847 }

, "$set" :

{ "col4" : 1358165847 }

, "$set" :

{ "col4" : 1358165847 }

} }
{ "ts" : Timestamp(1358165871000, 328), "h" : NumberLong("4783438901816552532"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358165868 }

, "$set" :

{ "col4" : 1358165868 }

, "$set" :

{ "col4" : 1358165868 }

, "$set" :

{ "col4" : 1358165868 }

, "$set" :

{ "col4" : 1358165868 }

} }
{ "ts" : Timestamp(1358165871000, 923), "h" : NumberLong("-7701283919644547362"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358165831 }

, "$set" :

{ "col4" : 1358165831 }

, "$set" :

{ "col4" : 1358165831 }

, "$set" :

{ "col4" : 1358165831 }

, "$set" :

{ "col4" : 1358165831 }

} }
{ "ts" : Timestamp(1358165877000, 217), "h" : NumberLong("905044855275590032"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358165858 }

, "$set" :

{ "col4" : 1358165858 }

, "$set" :

{ "col4" : 1358165858 }

, "$set" :

{ "col4" : 1358165858 }

, "$set" :

{ "col4" : 1358165858 }

} }
{ "ts" : Timestamp(1358165878000, 321), "h" : NumberLong("1021697642751326149"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358165814 }

, "$set" :

{ "col4" : 1358165814 }

, "$set" :

{ "col4" : 1358165814 }

, "$set" :

{ "col4" : 1358165814 }

, "$set" :

{ "col4" : 1358165814 }

} }
{ "ts" : Timestamp(1358165878000, 1479), "h" : NumberLong("-1093460978146924040"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358165861 }

, "$set" :

{ "col4" : 1358165861 }

, "$set" :

{ "col4" : 1358165861 }

, "$set" :

{ "col4" : 1358165861 }

, "$set" :

{ "col4" : 1358165861 }

} }
{ "ts" : Timestamp(1358165881000, 253), "h" : NumberLong("7582300884665231609"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358165883 }

, "$set" :

{ "col4" : 1358165883 }

, "$set" :

{ "col4" : 1358165883 }

, "$set" :

{ "col4" : 1358165883 }

, "$set" :

{ "col4" : 1358165883 }

} }
{ "ts" : Timestamp(1358165886000, 194), "h" : NumberLong("-6977646000941125783"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358165841 }

, "$set" :

{ "col4" : 1358165841 }

, "$set" :

{ "col4" : 1358165841 }

, "$set" :

{ "col4" : 1358165841 }

, "$set" :

{ "col4" : 1358165841 }

} }
{ "ts" : Timestamp(1358165891000, 8), "h" : NumberLong("4878117036357406261"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358165882 }

, "$set" :

{ "col4" : 1358165882 }

, "$set" :

{ "col4" : 1358165882 }

, "$set" :

{ "col4" : 1358165882 }

, "$set" :

{ "col4" : 1358165882 }

} }
{ "ts" : Timestamp(1358165925000, 1403), "h" : NumberLong("-4218451351552474554"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358165892 }

, "$set" :

{ "col4" : 1358165892 }

, "$set" :

{ "col4" : 1358165892 }

, "$set" :

{ "col4" : 1358165892 }

, "$set" :

{ "col4" : 1358165892 }

} }
{ "ts" : Timestamp(1358165926000, 37), "h" : NumberLong("8166869776502988491"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358165883 }

, "$set" :

{ "col4" : 1358165883 }

, "$set" :

{ "col4" : 1358165883 }

, "$set" :

{ "col4" : 1358165883 }

, "$set" :

{ "col4" : 1358165883 }

} }
{ "ts" : Timestamp(1358165926000, 1020), "h" : NumberLong("-2018291843739556146"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358165913 }

, "$set" :

{ "col4" : 1358165913 }

, "$set" :

{ "col4" : 1358165913 }

, "$set" :

{ "col4" : 1358165913 }

, "$set" :

{ "col4" : 1358165913 }

} }
{ "ts" : Timestamp(1358165926000, 1578), "h" : NumberLong("-728060886959932591"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358165888 }

, "$set" :

{ "col4" : 1358165888 }

, "$set" :

{ "col4" : 1358165888 }

, "$set" :

{ "col4" : 1358165888 }

, "$set" :

{ "col4" : 1358165888 }

} }
{ "ts" : Timestamp(1358165932000, 363), "h" : NumberLong("-2899178056259116954"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358165873 }

, "$set" :

{ "col4" : 1358165873 }

, "$set" :

{ "col4" : 1358165873 }

, "$set" :

{ "col4" : 1358165873 }

, "$set" :

{ "col4" : 1358165873 }

} }
{ "ts" : Timestamp(1358165933000, 361), "h" : NumberLong("3881140476962009969"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358165883 }

, "$set" :

{ "col4" : 1358165883 }

, "$set" :

{ "col4" : 1358165883 }

, "$set" :

{ "col4" : 1358165883 }

, "$set" :

{ "col4" : 1358165883 }

} }
{ "ts" : Timestamp(1358165939000, 359), "h" : NumberLong("-7011314542025612956"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358165899 }

, "$set" :

{ "col4" : 1358165899 }

, "$set" :

{ "col4" : 1358165899 }

, "$set" :

{ "col4" : 1358165899 }

, "$set" :

{ "col4" : 1358165899 }

} }
{ "ts" : Timestamp(1358165942000, 1288), "h" : NumberLong("8584958629205924536"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358165882 }

, "$set" :

{ "col4" : 1358165882 }

, "$set" :

{ "col4" : 1358165882 }

, "$set" :

{ "col4" : 1358165882 }

, "$set" :

{ "col4" : 1358165882 }

} }
{ "ts" : Timestamp(1358165983000, 778), "h" : NumberLong("-1825276314084065452"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358165918 }

, "$set" :

{ "col4" : 1358165918 }

, "$set" :

{ "col4" : 1358165918 }

, "$set" :

{ "col4" : 1358165918 }

, "$set" :

{ "col4" : 1358165918 }

} }
{ "ts" : Timestamp(1358165991000, 747), "h" : NumberLong("-6136876944333387998"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358165935 }

, "$set" :

{ "col4" : 1358165935 }

, "$set" :

{ "col4" : 1358165935 }

, "$set" :

{ "col4" : 1358165935 }

, "$set" :

{ "col4" : 1358165935 }

} }
{ "ts" : Timestamp(1358165992000, 568), "h" : NumberLong("-628829561541387552"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358165981 }

, "$set" :

{ "col4" : 1358165981 }

, "$set" :

{ "col4" : 1358165981 }

, "$set" :

{ "col4" : 1358165981 }

, "$set" :

{ "col4" : 1358165981 }

} }
{ "ts" : Timestamp(1358165992000, 1586), "h" : NumberLong("2249883926090089681"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358165880 }

, "$set" :

{ "col4" : 1358165880 }

, "$set" :

{ "col4" : 1358165880 }

, "$set" :

{ "col4" : 1358165880 }

, "$set" :

{ "col4" : 1358165880 }

} }
{ "ts" : Timestamp(1358165993000, 913), "h" : NumberLong("-2406566488359488622"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358165986 }

, "$set" :

{ "col4" : 1358165986 }

, "$set" :

{ "col4" : 1358165986 }

, "$set" :

{ "col4" : 1358165986 }

, "$set" :

{ "col4" : 1358165986 }

} }
{ "ts" : Timestamp(1358166031000, 414), "h" : NumberLong("2038488693111769456"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358165985 }

, "$set" :

{ "col4" : 1358165985 }

, "$set" :

{ "col4" : 1358165985 }

, "$set" :

{ "col4" : 1358165985 }

, "$set" :

{ "col4" : 1358165985 }

} }
{ "ts" : Timestamp(1358166036000, 694), "h" : NumberLong("9076849425697437764"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358165981 }

, "$set" :

{ "col4" : 1358165981 }

, "$set" :

{ "col4" : 1358165981 }

, "$set" :

{ "col4" : 1358165981 }

, "$set" :

{ "col4" : 1358165981 }

} }
{ "ts" : Timestamp(1358166050000, 1186), "h" : NumberLong("3767029040654546262"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358165996 }

, "$set" :

{ "col4" : 1358165996 }

, "$set" :

{ "col4" : 1358165996 }

, "$set" :

{ "col4" : 1358165996 }

, "$set" :

{ "col4" : 1358165996 }

} }
{ "ts" : Timestamp(1358166057000, 465), "h" : NumberLong("4054304491520021028"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358166056 }

, "$set" :

{ "col4" : 1358166056 }

, "$set" :

{ "col4" : 1358166056 }

, "$set" :

{ "col4" : 1358166056 }

, "$set" :

{ "col4" : 1358166056 }

} }
{ "ts" : Timestamp(1358166057000, 867), "h" : NumberLong("-8241200638844377915"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358166049 }

, "$set" :

{ "col4" : 1358166049 }

, "$set" :

{ "col4" : 1358166049 }

, "$set" :

{ "col4" : 1358166049 }

, "$set" :

{ "col4" : 1358166049 }

} }
{ "ts" : Timestamp(1358166093000, 283), "h" : NumberLong("8163250488038851407"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358165996 }

, "$set" :

{ "col4" : 1358165996 }

, "$set" :

{ "col4" : 1358165996 }

, "$set" :

{ "col4" : 1358165996 }

, "$set" :

{ "col4" : 1358165996 }

} }
{ "ts" : Timestamp(1358166114000, 1077), "h" : NumberLong("3933283505264467446"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358166073 }

, "$set" :

{ "col4" : 1358166073 }

, "$set" :

{ "col4" : 1358166073 }

, "$set" :

{ "col4" : 1358166073 }

, "$set" :

{ "col4" : 1358166073 }

} }
{ "ts" : Timestamp(1358166116000, 1092), "h" : NumberLong("-3910445542003046573"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358166059 }

, "$set" :

{ "col4" : 1358166059 }

, "$set" :

{ "col4" : 1358166059 }

, "$set" :

{ "col4" : 1358166059 }

, "$set" :

{ "col4" : 1358166059 }

} }
{ "ts" : Timestamp(1358166123000, 19), "h" : NumberLong("-3379893690547749158"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358165899 }

, "$set" :

{ "col4" : 1358165899 }

, "$set" :

{ "col4" : 1358165899 }

, "$set" :

{ "col4" : 1358165899 }

, "$set" :

{ "col4" : 1358165899 }

} }
{ "ts" : Timestamp(1358166124000, 222), "h" : NumberLong("-1554362852666524628"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358166046 }

, "$set" :

{ "col4" : 1358166046 }

, "$set" :

{ "col4" : 1358166046 }

, "$set" :

{ "col4" : 1358166046 }

, "$set" :

{ "col4" : 1358166046 }

} }
{ "ts" : Timestamp(1358166124000, 1013), "h" : NumberLong("-6412016679312996442"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358166100 }

, "$set" :

{ "col4" : 1358166100 }

, "$set" :

{ "col4" : 1358166100 }

, "$set" :

{ "col4" : 1358166100 }

, "$set" :

{ "col4" : 1358166100 }

} }
{ "ts" : Timestamp(1358166162000, 1284), "h" : NumberLong("-3760011584546642058"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358166058 }

, "$set" :

{ "col4" : 1358166058 }

, "$set" :

{ "col4" : 1358166058 }

, "$set" :

{ "col4" : 1358166058 }

, "$set" :

{ "col4" : 1358166058 }

} }
{ "ts" : Timestamp(1358166163000, 190), "h" : NumberLong("-1824466010869690902"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358165987 }

, "$set" :

{ "col4" : 1358165987 }

, "$set" :

{ "col4" : 1358165987 }

, "$set" :

{ "col4" : 1358165987 }

, "$set" :

{ "col4" : 1358165987 }

} }
{ "ts" : Timestamp(1358166170000, 450), "h" : NumberLong("-6006134238326624856"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358166167 }

, "$set" :

{ "col4" : 1358166167 }

, "$set" :

{ "col4" : 1358166167 }

, "$set" :

{ "col4" : 1358166167 }

, "$set" :

{ "col4" : 1358166167 }

} }
{ "ts" : Timestamp(1358166173000, 1574), "h" : NumberLong("-38881893422671401"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358166096 }

, "$set" :

{ "col4" : 1358166096 }

, "$set" :

{ "col4" : 1358166096 }

, "$set" :

{ "col4" : 1358166096 }

, "$set" :

{ "col4" : 1358166096 }

} }
{ "ts" : Timestamp(1358166179000, 141), "h" : NumberLong("-4873708995553826291"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358166108 }

, "$set" :

{ "col4" : 1358166108 }

, "$set" :

{ "col4" : 1358166108 }

, "$set" :

{ "col4" : 1358166108 }

, "$set" :

{ "col4" : 1358166108 }

} }
{ "ts" : Timestamp(1358166187000, 372), "h" : NumberLong("2509842530284094589"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358166178 }

, "$set" :

{ "col4" : 1358166178 }

, "$set" :

{ "col4" : 1358166178 }

, "$set" :

{ "col4" : 1358166178 }

, "$set" :

{ "col4" : 1358166178 }

} }
{ "ts" : Timestamp(1358179966000, 593), "h" : NumberLong("-4290646640946455411"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358165806 }

, "$set" :

{ "col4" : 1358165806 }

, "$set" :

{ "col4" : 1358165806 }

, "$set" :

{ "col4" : 1358165806 }

, "$set" :

{ "col4" : 1358165806 }

} }
{ "ts" : Timestamp(1358179972000, 725), "h" : NumberLong("7234604075717479874"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358165803 }

, "$set" :

{ "col4" : 1358165803 }

, "$set" :

{ "col4" : 1358165803 }

, "$set" :

{ "col4" : 1358165803 }

, "$set" :

{ "col4" : 1358165803 }

} }
{ "ts" : Timestamp(1358180031000, 1444), "h" : NumberLong("7308405316679414687"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358166170 }

, "$set" :

{ "col4" : 1358166170 }

, "$set" :

{ "col4" : 1358166170 }

, "$set" :

{ "col4" : 1358166170 }

, "$set" :

{ "col4" : 1358166170 }

} }
{ "ts" : Timestamp(1358180102000, 1710), "h" : NumberLong("3814167846358794846"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358166102 }

, "$set" :

{ "col4" : 1358166102 }

, "$set" :

{ "col4" : 1358166102 }

, "$set" :

{ "col4" : 1358166102 }

, "$set" :

{ "col4" : 1358166102 }

} }
{ "ts" : Timestamp(1358180154000, 1605), "h" : NumberLong("-8728984085139165017"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358166096 }

, "$set" :

{ "col4" : 1358166096 }

, "$set" :

{ "col4" : 1358166096 }

, "$set" :

{ "col4" : 1358166096 }

, "$set" :

{ "col4" : 1358166096 }

} }
{ "ts" : Timestamp(1358180158000, 669), "h" : NumberLong("-4665390581863594269"), "v" : 2, "op" : "u", "ns" : "test.test", "o2" :

{ "_id" : "2013-01-14_40b2d10559dd731750839a20b78ac075_331282" }

, "o" : { "$set" :

{ "col4" : 1358166117 }

, "$set" :

{ "col4" : 1358166117 }

, "$set" :

{ "col4" : 1358166117 }

, "$set" :

{ "col4" : 1358166117 }

, "$set" :

{ "col4" : 1358166117 }

} }



 Comments   
Comment by Nic Cottrell (Personal) [ 26/Mar/14 ]

Oh, and journalling is enabled on this secondary - pretty much all settings are default.

Comment by Nic Cottrell (Personal) [ 26/Mar/14 ]

Forgot to mention that the hard drive on this node become full so I suspect something went wrong with the replication from the primary and it thinks it hasn't created this document here yet, and went it does it fails. I'm going to wipe the data on this secondary and let it resync. That has worked before when I had a similar problem.

Comment by Nic Cottrell (Personal) [ 26/Mar/14 ]

I just got something very similar running on 2.4.9:

Wed Mar 26 19:10:34.679 [conn27184]  authenticate db: local { authenticate: 1, nonce: "7a00a63fdb203376", user: "__system", key: "87b2b9b609ad4dbbbb097cf01e869161" }
Wed Mar 26 19:10:34.696 [initandlisten] connection accepted from 46.4.84.213:40416 #27185 (53 connections now open)
Wed Mar 26 19:10:34.696 [conn27184] end connection 46.4.84.213:40415 (51 connections now open)
Wed Mar 26 19:10:34.697 [conn27185]  authenticate db: local { authenticate: 1, nonce: "157fe2c22f44726a", user: "__system", key: "b68d5e327d66b340d47a5610f619315b" }
Wed Mar 26 19:10:34.702 [initandlisten] connection accepted from 46.4.84.213:40417 #27186 (53 connections now open)
Wed Mar 26 19:10:34.702 [conn27185] end connection 46.4.84.213:40416 (52 connections now open)
Wed Mar 26 19:10:34.703 [conn27186]  authenticate db: local { authenticate: 1, nonce: "27217002242fa2c5", user: "__system", key: "2a7712eaff1b0076c3fa81b578560e28" }
Wed Mar 26 19:10:34.706 [conn27186] end connection 46.4.84.213:40417 (51 connections now open)
Wed Mar 26 19:10:34.715 [initandlisten] connection accepted from 46.4.84.213:40418 #27187 (52 connections now open)
Wed Mar 26 19:10:34.717 [conn27187]  authenticate db: local { authenticate: 1, nonce: "70d92ee62a56efa2", user: "__system", key: "06192578907d970d2b23f8981da49302" }
Wed Mar 26 19:10:35.140 [repl writer worker 3] ERROR: writer worker caught exception: E11000 duplicate key error index: jerome5.TranslationQueue.$tl_1_g_1_sl_1_st_1  dup key: { : null, : null, : null, : null } on: { ts: Timestamp 1395857435000|78, h: -2353438816918522240, v: 2, op: "u", ns: "jerome5.TranslationQueue", o2: { _id: ObjectId('5332b1b61aff1b5d3e0add87') }, o: { $set: { count: 2, lr: new Date(1395857435015) } } }
Wed Mar 26 19:10:35.140 [repl writer worker 3]   Fatal Assertion 16360
0xde46e1 0xda44d3 0xc2ca7c 0xdb2021 0xe2cf69 0x7f6ef772d9d1 0x7f6ef6ad2b6d 
 /usr/bin/mongod(_ZN5mongo15printStackTraceERSo+0x21) [0xde46e1]
 /usr/bin/mongod(_ZN5mongo13fassertFailedEi+0xa3) [0xda44d3]
 /usr/bin/mongod(_ZN5mongo7replset14multiSyncApplyERKSt6vectorINS_7BSONObjESaIS2_EEPNS0_8SyncTailE+0x12c) [0xc2ca7c]
 /usr/bin/mongod(_ZN5mongo10threadpool6Worker4loopEv+0x281) [0xdb2021]
 /usr/bin/mongod() [0xe2cf69]
 /lib64/libpthread.so.0(+0x79d1) [0x7f6ef772d9d1]
 /lib64/libc.so.6(clone+0x6d) [0x7f6ef6ad2b6d]
Wed Mar 26 19:10:35.142 [repl writer worker 3] 
 
***aborting after fassert() failure
 
 
Wed Mar 26 19:10:35.142 Got signal: 6 (Aborted).
 
Wed Mar 26 19:10:35.143 Backtrace:
0xde46e1 0x6d06c9 0x7f6ef6a1c9a0 0x7f6ef6a1c925 0x7f6ef6a1e105 0xda450e 0xc2ca7c 0xdb2021 0xe2cf69 0x7f6ef772d9d1 0x7f6ef6ad2b6d 
 /usr/bin/mongod(_ZN5mongo15printStackTraceERSo+0x21) [0xde46e1]
 /usr/bin/mongod(_ZN5mongo10abruptQuitEi+0x399) [0x6d06c9]
 /lib64/libc.so.6(+0x329a0) [0x7f6ef6a1c9a0]
 /lib64/libc.so.6(gsignal+0x35) [0x7f6ef6a1c925]
 /lib64/libc.so.6(abort+0x175) [0x7f6ef6a1e105]
 /usr/bin/mongod(_ZN5mongo13fassertFailedEi+0xde) [0xda450e]
 /usr/bin/mongod(_ZN5mongo7replset14multiSyncApplyERKSt6vectorINS_7BSONObjESaIS2_EEPNS0_8SyncTailE+0x12c) [0xc2ca7c]
 /usr/bin/mongod(_ZN5mongo10threadpool6Worker4loopEv+0x281) [0xdb2021]
 /usr/bin/mongod() [0xe2cf69]
 /lib64/libpthread.so.0(+0x79d1) [0x7f6ef772d9d1]
 /lib64/libc.so.6(clone+0x6d) [0x7f6ef6ad2b6d]

Prior to this, we see hundreds of

Wed Mar 26 19:10:34.351 [conn27175] end connection 46.4.84.213:40391 (52 connections now open)
Wed Mar 26 19:10:34.353 [conn27176]  authenticate db: local { authenticate: 1, nonce: "2459cc473977ebcd", user: "__system", key: "479ac7d29cb0d908aa9d120d7fbcb8be" }
Wed Mar 26 19:10:34.367 [initandlisten] connection accepted from 46.4.84.213:40395 #27177 (53 connections now open)
Wed Mar 26 19:10:34.367 [conn27176] end connection 46.4.84.213:40393 (52 connections now open)
Wed Mar 26 19:10:34.368 [conn27177]  authenticate db: local { authenticate: 1, nonce: "66b4dc583bcef4b6", user: "__system", key: "c12ce657ce342db7952e1e1998184832" }
Wed Mar 26 19:10:34.375 [initandlisten] connection accepted from 46.4.84.213:40397 #27178 (53 connections now open)
Wed Mar 26 19:10:34.375 [conn27177] end connection 46.4.84.213:40395 (52 connections now open)
Wed Mar 26 19:10:34.376 [conn27178]  authenticate db: local { authenticate: 1, nonce: "7e7e4da7a7db32e2", user: "__system", key: "4b739971b2257ae5b41108effb39abbb" }
Wed Mar 26 19:10:34.391 [initandlisten] connection accepted from 46.4.84.213:40399 #27179 (53 connections now open)
Wed Mar 26 19:10:34.392 [conn27178] end connection 46.4.84.213:40397 (52 connections now open)
Wed Mar 26 19:10:34.393 [conn27179]  authenticate db: local { authenticate: 1, nonce: "a8a22da45f87c7ed", user: "__system", key: "97b277b9c0f1dc8342609081a5137f8f" }
Wed Mar 26 19:10:34.400 [initandlisten] connection accepted from 46.4.84.213:40401 #27180 (53 connections now open)
Wed Mar 26 19:10:34.400 [conn27179] end connection 46.4.84.213:40399 (52 connections now open)
Wed Mar 26 19:10:34.401 [conn27180]  authenticate db: local { authenticate: 1, nonce: "3765611158fc44ab", user: "__system", key: "7e62a1a32b123460a0aba15f694c3911" }
Wed Mar 26 19:10:34.415 [initandlisten] connection accepted from 46.4.84.213:40403 #27181 (53 connections now open)
Wed Mar 26 19:10:34.415 [conn27180] end connection 46.4.84.213:40401 (51 connections now open)
Wed Mar 26 19:10:34.417 [conn27181]  authenticate db: local { authenticate: 1, nonce: "c4d2cdd593201728", user: "__system", key: "8060ce358c0050444663adb8f06d1eac" }
Wed Mar 26 19:10:34.425 [initandlisten] connection accepted from 46.4.84.213:40405 #27182 (53 connections now open)
Wed Mar 26 19:10:34.425 [conn27181] end connection 46.4.84.213:40403 (51 connections now open)
Wed Mar 26 19:10:34.426 [conn27182]  authenticate db: local { authenticate: 1, nonce: "a5297100e5ad4ae2", user: "__system", key: "67b372b789ebe0de4bc3ea47b3c94502" }
Wed Mar 26 19:10:34.587 [initandlisten] connection accepted from 46.4.84.213:40409 #27183 (53 connections now open)
Wed Mar 26 19:10:34.587 [conn27182] end connection 46.4.84.213:40405 (51 connections now open)
Wed Mar 26 19:10:34.589 [conn27183]  authenticate db: local { authenticate: 1, nonce: "312985067c35f6fb", user: "__system", key: "b82aa9474d5540db1b8750814f939573" }
Wed Mar 26 19:10:34.678 [initandlisten] connection accepted from 46.4.84.213:40415 #27184 (53 connections now open)

which looks like failed connections from another server with a mongos and another secondary for this RS.

Comment by Stennie Steneker (Inactive) [ 28/Oct/13 ]

Hi,

I'm closing this issue due to inactivity.

If you are still seeing this issue (particularly with a newer version of MongoDB, such as 2.4.x) please feel free to open a new issue or comment on this one with the relevant details.

Thanks,
Stephen

Comment by Randolph Tan [ 28/Jan/13 ]

This looks very similar to SERVER-7186. But it should have been fixed in 2.2.2. Can you confirm what version the secondary was running on?

Comment by Dong Wei [ 28/Jan/13 ]

no reply?

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