Migration of 5.0 cluster

[sudhirgautam21]

Hi,

I am facing below error while doing migration from atlas to ec2 instance.

[2022/11/02 00:00:01 UTC] [CRIT] Replayer-0, executor-0, oplog for namespace[abc.xyz] op[u] failed. error type[*errors.errorString] error[unknow Key[{strack_exports [{u [{electroniclabels [20211201_211238 20220420_044917 20220503_000745 20220614_014209 20220623_010229 20220803_013509 20221001_170217 20221101_170750 20221201_180950]}]}]}]], logs number[194], firstLog: {"ts":{"T":1669918082,"I":1},"t":26,"h":null,"v":2,"op":"u","ns":"abc.xyz","o":[{"Key":"diff","Value":[{"Key":"i","Value":[{"Key":"is_duplicate_fp","Value":[{"Key":"scd","Value":null}]}]}]}],"o2":[{"Key":"_id","Value":"63872ed1184w536096c9c62b"}],"PrevOpTime":null,"ui":{"Subtype":4,"Data":"srKbzJzkQS+89UtPg6janA=="}}

This issue happens after full sync is done and mongoshake tries to apply oplog. All the update operations (only ops) are getting failed.

mongoshake version : 2.8.1
source mongodb version : 5.0 (atlas)
target mongodb version: 5.0 (PSMDB)

[zhangst]

Hi,

Can you find the oplog that caused this error? To solve this problem, I need to reproduce it in my test environment.

"[{strack_exports [{u [{electroniclabels [20211201_211238 20220420_044917 20220503_000745 20220614_014209 20220623_010229 20220803_013509 20221001_170217 20221101_170750 20221201_180950]}]}]}]],"

[sudhirgautam21]

Hi,

Below are the 2 similar oplog that is causing the same error:

{ "lsid" : { "id" : UUID("5880b3f1-74b3-6502-ab56-bbaa3a6c866d"), "uid" : BinData(0,"ZAQvkzjGj8ZkcHTy+GYyjH6YYHiDnCCqt4co7BDZD+I=") }, "txnNumber" : NumberLong(1), "op" : "u", "ns" : "abc.xyz", "ui" : UUID("c2c29bcc-9ce4-782f-b8e9-4b4f83a2ca9c"), "o" : { "$v" : 2, "diff" : { "i" : { "sig" : { "2_0" : true } } } }, "o2" : { "_id" : ObjectId("63895798124f53602478771f") }, "ts" : Timestamp(1669947268, 1), "t" : NumberLong(26), "v" : NumberLong(2), "wall" : ISODate("2022-12-02T02:14:28.966Z"), "stmtId" : 2, "prevOpTime" : { "ts" : Timestamp(0, 0), "t" : NumberLong(-1) } }

{ "op" : "u", "ns" : "abc.xyz", "ui" : UUID("b2b29bcc-9ce4-412f-b8e9-4b4f83a8da9c"), "o" : { "$v" : 2, "diff" : { "i" : { "track_exports" : { "cdm" : [ "20221202_175837" ] } } } }, "o2" : { "_id" : ObjectId("63895751154f53606975771f") }, "ts" : Timestamp(1670003933, 976), "t" : NumberLong(26), "v" : NumberLong(2), "wall" : ISODate("2022-12-02T17:58:53.279Z") }

I tried to reproduce the error in test env with same oplog, unfortunately not able to reproduce it. Not sure why it is creating issue in the env from where I am migrating the data.

[zhangst]

Hi,

Can you find any document in table abc.xyz or local.oplog.rs of source database, document that have below content：

"[{strack_exports [{u [{electroniclabels [20211201_211238 20220420_044917 20220503_000745 20220614_014209 20220623_010229 20220803_013509 20221001_170217 20221101_170750 20221201_180950]}]}]}]],"

The document that caused this error may contain these contens.

[zhangst]

bin.tgz

Please try this version(base 2.8.1) which I add some log. if it recurs, please provide the log.

[sudhirgautam21]

This is the oplog in source database for above entry:

{
"op" : "u",
"ns" : "abc.xyz",
"ui" : UUID("b2b29bcc-9ce4-412f-b8e9-4b4f83a8da9c"),
"o" : {
"$v" : 2,
"diff" : {
"i" : {
"is_duplicate_fp" : {
"scd" : null
}
}
}
},
"o2" : {
"_id" : ObjectId("63872ed1184w536096c9c62b")
},
"ts" : Timestamp(1669918082, 1),
"t" : NumberLong(26),
"v" : NumberLong(2),
"wall" : ISODate("2022-12-01T18:08:02.322Z")
}

If you compare the timestamp of above oplog I just shared from source and the timestamp of oplog entry of mongoshake, both are same so this is the op which got failed in mongoshake.

Can't find these values in any oplog entry or document in source:

"[{strack_exports [{u [{electroniclabels [20211201_211238 20220420_044917 20220503_000745 20220614_014209 20220623_010229 20220803_013509 20221001_170217 20221101_170750 20221201_180950]}]}]}]],"

Not sure how and why mongoshake is getting above oplog entry.

[zhangst]

Hi,

logs number[194], firstLog: {"ts":{"T":1669918082,"I":1},"t":26,"h":null,"v":2,"op":"u","ns":"abc.xyz","o":[{"Key":"diff","Value":[{"Key":"i","Value":[{"Key":"is_duplicate_fp","Value":[{"Key":"scd","Value":null}]}]}]}],"o2":[{"Key":"_id","Value":"63872ed1184w536096c9c62b"}],"PrevOpTime":null,"ui":{"Subtype":4,"Data":"srKbzJzkQS+89UtPg6janA=="}}

This oplog is the first log of a batch which have 194 oplogs, but it may not be the oplog which causes the failure. In bin.tgz I add some log to print the failure oplog.

I will try test this oplog locally, if you can reproduce it, please provide the corresponding oplog.

[zhangst]

Hi,

[2022/12/12 10:34:14 CST] [DEBG] bulk_writer: update [{$set [{name <nil>}]}] aftermodify_doc:{"ts":{"T":1670812453,"I":2},"t":1,"h":null,"v":2,"op":"u","ns":"test.fur","o":[{"Key":"diff","Value":[{"Key":"i","Value":[{"Key":"name","Value":null}]}]}],"o2":[{"Key":"_id","Value":"639692169feb138b1f6e7982"}],"PrevOpTime":null,"ui":{"Subtype":4,"Data":"HOagWVwYRt689hGOl12fGg=="}}

{
    "ts": {
        "T": 1670812453,
        "I": 2
    },
    "t": 1,
    "h": null,
    "v": 2,
    "op": "u",
    "ns": "test.fur",
    "o": [
        {
            "Key": "diff",
            "Value": [
                {
                    "Key": "i",
                    "Value": [
                        {
                            "Key": "name",
                            "Value": null
                        }
                    ]
                }
            ]
        }
    ],
    "o2": [
        {
            "Key": "_id",
            "Value": "639692169feb138b1f6e7982"
        }
    ],
    "PrevOpTime": null,
    "ui": {
        "Subtype": 4,
        "Data": "HOagWVwYRt689hGOl12fGg=="
    }
}

I have test it locally , it can replication success. so the problem is not caused by this record.

[sudhirgautam21]

Hi,

I will try to run it using bin.tgz. I am able to reproduce it every time when it tries to implement the oplog after full sync is done, below are more example of the same error. Even I tried to run same operation in local test env and the oplog was copied successfully without any error.

[CRIT] Replayer-0, executor-0, oplog for namespace[abc.xyz] op[u] failed. error type[*errors.errorString] error[unknow Key[{sis_duplicate_fp [{u [{believeisrcde [{source crawler_believe} {service_id 19500181}]}]}]}]], logs number[203], firstLog: {"ts":{"T":1670539271,"I":1161},"t":26,"h":null,"v":2,"op":"u","ns":"landing_db.tracks","o":[{"Key":"diff","Value":[{"Key":"sis_duplicate_fp","Value":[{"Key":"u","Value":[{"Key":"believeisrcde","Value":[{"Key":"source","Value":"crawler_believe"},{"Key":"service_id","Value":"19572734"}]}]}]}]}],"o2":[{"Key":"_id","Value":"5b9f7803fecd27ae5e5aa752"}],"PrevOpTime":null,"ui":{"Subtype":4,"Data":"srKbzJzkQS+46UtPg6janA=="}}

[EROR] doUpdate run Faild err[unknow Key[{sis_duplicate_fp [{u [{believeisrcde [{source crawler_believe} {service_id 20744924}]}]}]}]] org_doc[{"ts":{"T":1670539271,"I":1218},"t":26,"h":null,"v":2,"op":"u","ns":"abc.xyz","o":[{"Key":"diff","Value":[{"Key":"sis_duplicate_fp","Value":[{"Key":"u","Value":[{"Key":"believeisrcde","Value":[{"Key":"source","Value":"crawler_believe"},{"Key":"service_id","Value":"20744924"}]}]}]}]}],"o2":[{"Key":"_id","Value":"5b89720efecd27ae5ec13e61"}],"PrevOpTime":null,"ui":{"Subtype":4,"Data":"srKbzJzkQS+46UtPg6janA=="}}]

[CRIT] Replayer-0, executor-0, oplog for namespace[abc.xyz] op[u] failed. error type[*errors.errorString] error[unknow Key[{sis_duplicate_fp [{u [{believeisrcde [{source crawler_believe} {service_id 20744924}]}]}]}]], logs number[203], firstLog: {"ts":{"T":1670539271,"I":1161},"t":26,"h":null,"v":2,"op":"u","ns":"landing_db.tracks","o":[{"Key":"diff","Value":[{"Key":"sis_duplicate_fp","Value":[{"Key":"u","Value":[{"Key":"believeisrcde","Value":[{"Key":"source","Value":"crawler_believe"},{"Key":"service_id","Value":"19572734"}]}]}]}]}],"o2":[{"Key":"_id","Value":"5b9f7803fecd27ae5e5aa752"}],"PrevOpTime":null,"ui":{"Subtype":4,"Data":"srKbzJzkQS+46UtPg6janA=="}}

[EROR] doUpdate run Faild err[unknow Key[{sis_duplicate_fp [{u [{believeisrcde [{source crawler_believe} {service_id 19500171}]}]}]}]] org_doc[{"ts":{"T":1670539271,"I":1219},"t":26,"h":null,"v":2,"op":"u","ns":"abc.xyz","o":[{"Key":"diff","Value":[{"Key":"sis_duplicate_fp","Value":[{"Key":"u","Value":[{"Key":"believeisrcde","Value":[{"Key":"source","Value":"crawler_believe"},{"Key":"service_id","Value":"19500171"}]}]}]}]}],"o2":[{"Key":"_id","Value":"5b8971f4fecd27ae5ec1097b"}],"PrevOpTime":null,"ui":{"Subtype":4,"Data":"srKbzJzkQS+46UtPg6janA=="}}]

[CRIT] Replayer-0, executor-0, oplog for namespace[abc.xyz] op[u] failed. error type[*errors.errorString] error[unknow Key[{sis_duplicate_fp [{u [{believeisrcde [{source crawler_believe} {service_id 19500171}]}]}]}]], logs number[203], firstLog: {"ts":{"T":1670539271,"I":1161},"t":26,"h":null,"v":2,"op":"u","ns":"landing_db.tracks","o":[{"Key":"diff","Value":[{"Key":"sis_duplicate_fp","Value":[{"Key":"u","Value":[{"Key":"believeisrcde","Value":[{"Key":"source","Value":"crawler_believe"},{"Key":"service_id","Value":"19572734"}]}]}]}]}],"o2":[{"Key":"_id","Value":"5b9f7803fecd27ae5e5aa752"}],"PrevOpTime":null,"ui":{"Subtype":4,"Data":"srKbzJzkQS+46UtPg6janA=="}}

[EROR] doUpdate run Faild err[unknow Key[{sis_duplicate_fp [{u [{believeisrcde [{source crawler_believe} {service_id 19500172}]}]}]}]] org_doc[{"ts":{"T":1670539271,"I":1220},"t":26,"h":null,"v":2,"op":"u","ns":"abc.xyz","o":[{"Key":"diff","Value":[{"Key":"sis_duplicate_fp","Value":[{"Key":"u","Value":[{"Key":"believeisrcde","Value":[{"Key":"source","Value":"crawler_believe"},{"Key":"service_id","Value":"19500172"}]}]}]}]}],"o2":[{"Key":"_id","Value":"5b89720efecd27ae5ec13e62"}],"PrevOpTime":null,"ui":{"Subtype":4,"Data":"srKbzJzkQS+46UtPg6janA=="}}]

It is failing for the update operations only.

[zhangst]

Hi,

Please attach logs when you reproduce it with the binary in bin.tgz

[sannithisubbarao]

Hi,

We are able to migrate mongo 4.4 version and however we are having issues with 5.0 using mongoshake. we do not have any logs generated when we start migrating 5.0.

[zhangst]

Hi,

We are able to migrate mongo 4.4 version and however we are having issues with 5.0 using mongoshake. we do not have any logs generated when we start migrating 5.0.

which version do you use, please try ver2.8.1.

[coltisa]

Hi, have you fixed this issue? we have a issue almost like yours happened when renameCollection. And our source and target MongoDB version are 5.0.14.

Logs as below:
[2023/03/28 00:01:33 UTC] [CRIT] Replayer-0, executor-0, oplog for namespace[esb.tmp_6661] op[c] failed. error type[mongo.CommandError] error[(TypeMismatch) BSON field 'renameCollection.dropTarget' is the wrong type 'binData', expected type 'bool'], logs number[1], firstLog: {"ts":{"T":1679938277,"I":106497},"t":139,"h":null,"v":2,"op":"c","ns":"esb.tmp_6661","o":[{"Key":"renameCollection","Value":"xxx.t_6661"},{"Key":"to","Value":"xxx.a_6661"},{"Key":"stayTemp","Value":false},{"Key":"dropTarget","Value":{"Subtype":4,"Data":"2iIYLK7CRhSpV+INU8S6mA"}}],"o2":[{"Key":"numRecords","Value":5294}],"PrevOpTime":null,"ui":{"Subtype":4,"Data":"dnM41M0KQpOGOF2WBeA"}}