[SERVER-7871] Updates create $set operations in oplog in a new format that is not parseable by most drivers Created: 07/Dec/12  Updated: 15/Feb/13  Resolved: 27/Dec/12

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

Type: Bug Priority: Major - P3
Reporter: Dave Curylo Assignee: Unassigned
Resolution: Duplicate Votes: 0
Labels: oplog,, tailable, triage
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Same effect when server is running on Windows or CentOS.


Issue Links:
Duplicate
duplicates SERVER-1606 Oplog entries contain repeated fields... Closed
Related
related to SERVER-1606 Oplog entries contain repeated fields... Closed
related to DOCS-923 Document driver support for duplicate... Closed
Backwards Compatibility: Fully Compatible
Operating System: ALL
Participants:

 Description   

The oplog starting in version 2.2.1 seemed to get a new format when updates are performed containing $set operations. This new format creates BSON documents in the rs.oplog collection where the $set key is included for each $set operation, whereas in versions prior to 2.2.1 there would only be a single $set key in the document and a subdocument would describe all the fields to be set. Since there are multiple $set keys, most drivers cannot parse these oplog documents, and will get exceptions while iterating through the oplog query results that contain any update operation with multiple $set updates.

Here is an example for creating the malformed oplog entries on a new 2.2.1 or 2.2.2 system:

rs0:PRIMARY> db.mycoll.save({_id:"unique-id-1234", "aaa":"0000", "bbb": "1111"})
rs0:PRIMARY> db.mycoll.update({_id:"unique-id-1234"}, {$set:{"aaa":"1234","bbb":"7654"}})
rs0:PRIMARY> use local
rs0:PRIMARY> db.oplog.rs.find().pretty()
{
        "ts" : Timestamp(1353099630000, 1),
        "h" : NumberLong(0),
        "v" : 2,
        "op" : "n",
        "ns" : "",
        "o" : {
                "msg" : "initiating set"
        }
}
{
        "ts" : Timestamp(1353099716000, 1),
        "h" : NumberLong("6562103115049336849"),
        "v" : 2,
        "op" : "i",
        "ns" : "sample.mycoll",
        "o" : {
                "_id" : "unique-id-1234",
                "aaa" : "0000",
                "bbb" : "1111"
        }
}
{
        "ts" : Timestamp(1353099904000, 1),
        "h" : NumberLong("-7902296395036453900"),
        "v" : 2,
        "op" : "u",
        "ns" : "sample.mycoll",
        "o2" : {
                "_id" : "unique-id-1234"
        },
        "o" : {
                "$set" : {
                        "aaa" : "1234"
                },
                "$set" : {
                        "aaa" : "1234"
                }
        }
}

You will notice the "o" subdocument contains two "$set" keys, and drivers can't handle this new format. In prior versions, including 2.2.0, I would see this type of oplog entry when performing a update on a document, setting multiple fields:

{
        "ts" : Timestamp(1353074108000, 3),
        "h" : NumberLong("-3950642131243057651"),
        "op" : "u",
        "ns" : "mydb.mycollection",
        "o2" : {
                "_id" : "my-unique-id-1234"
        },
        "o" : {
                "$set" : {
                        "aaa" : "1234",
                        "bbb" : "2345",
                        "ccc" : "3456",
                        "ddd" : "4567",
                        "eee" : "5678",
                        "fff" : "6789",
                        "ggg" : "7890",
                        "hhh" : "asdf"
                }
        }
}

If it is helpful, here is the entire conversation in context.



 Comments   
Comment by Dwight Merriman [ 27/Dec/12 ]

one nuance on any fix is imagine an update applied in this order by the primary ($A is abstraction for any operator that is in the oplog e.g. let $A = "$set":
{ $A :

{x:_}

, $B :

{y:_}

, $A :

{z:_}

}
we need to maintain same ordering on secondary and that might not happen if transformed to
{ $A :

{ x:_, z:_ }

, $B :

{y:_}

}

Comment by Dwight Merriman [ 27/Dec/12 ]

separate of the server issue, mongo shell cannot display completely wrong info so that should be fixed regardless. it could show an error, but it can't show wrong info. (ideally it shows what is there not just an error.)

Comment by Stennie Steneker (Inactive) [ 21/Dec/12 ]

Hi Dave,

Duplicate keys have been used in replication historically for a long time (for example, SERVER-1606 references this issue in MongoDB 1.4.4).

I've raised a DOCS ticket as there is limited information available on driver support for working with duplicate keys: DOCS-923

You can use the C++ driver which has full support for this; most driver do not.

Cheers,
Stephen

Comment by Dave Curylo [ 07/Dec/12 ]

Forgot this additional information. There seems to be a shell display issue with this as well, so you have to do a bsondump to see what is actually in the oplog:

c:\mongodb-2.2.1\bin>bsondump.exe dump\local\oplog.rs.bson
{ "ts" :

{ "t" : 1353099630000 , "i" : 1 }

, "h" : 0, "v" : 2, "op" : "n", "ns" : "", "o" :

{ "msg" : "initiating set" }

}
{ "ts" :

{ "t" : 1353099716000 , "i" : 1 }

, "h" : 6562103115049336849, "v" : 2,"op" : "i", "ns" : "sample.mycoll", "o" :

{ "_id" : "unique-id-1234", "aaa" : "0000", "bbb" : "1111" }

}
{ "ts" :

{ "t" : 1353099904000 , "i" : 1 }

, "h" : -7902296395036453900, "v" : 2, "op" : "u", "ns" : "sample.mycoll", "o2" :

{ "_id" : "unique-id-1234" }

, "o" :{ "$set" :

{ "aaa" : "1234" }

, "$set" :

{ "bbb" : "7654" }

} }
3 objects found

This looks better, but there is still a problem since the "o" subdocument from the update contains multiple keys with the same name, "$set".

"o" :{ "$set" :

{ "aaa" : "1234" }

, "$set" :

{ "bbb" : "7654" }

}

Comment by Dave Curylo [ 07/Dec/12 ]

Submitted too soon. Here is the full discussion of this issue:

https://groups.google.com/d/topic/mongodb-user/eDPGj9nS6_A/discussion

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