Uploaded image for project: 'Core Server'
  1. Core Server
  2. SERVER-20895

Strange behavior with wired tiger oplog and duplicate ts values

    XMLWordPrintableJSON

Details

    • Icon: Bug Bug
    • Resolution: Done
    • Icon: Minor - P4 Minor - P4
    • None
    • None
    • Replication, Storage
    • None
    • Replication
    • ALL

    Description

      It seems like inserts are fine with duplicate ts values but mask older documents, or replace them.

      test:PRIMARY> db.getSiblingDB("local").oplog.rs.insert({ts: new Timestamp(1444669076,3), op:"n", h: NumberLong("12312")})
      WriteResult({ "nInserted" : 1 })
      test:PRIMARY> db.getSiblingDB("local").oplog.rs.insert({ts: new Timestamp(1444669076,3), op:"n", h: NumberLong("12312")})
      WriteResult({ "nInserted" : 1 })
      test:PRIMARY> db.getSiblingDB("local").oplog.rs.insert({ts: new Timestamp(1444669076,3), op:"n", h: NumberLong("12312")})
      WriteResult({ "nInserted" : 1 })
      test:PRIMARY> db.getSiblingDB("local").oplog.rs.find()
      { "_id" : ObjectId("561d0d5e30adac216043a161"), "ts" : Timestamp(1444669076, 3), "op" : "n", "h" : NumberLong(12312) }
      { "ts" : Timestamp(1444669605, 1), "t" : NumberLong(0), "h" : NumberLong("-6898850243195961135"), "v" : 2, "op" : "n", "ns" : "", "o" : { "msg" : "initiating set" } }
      { "ts" : Timestamp(1444669606, 1), "t" : NumberLong(1), "h" : NumberLong("-1589401225501337977"), "v" : 2, "op" : "n", "ns" : "", "o" : { "msg" : "new primary" } }
      { "ts" : Timestamp(1444669631, 1), "t" : NumberLong(1), "h" : NumberLong("1621003532950817417"), "v" : 2, "op" : "n", "ns" : "", "o" : { "foo" : 1 } }
      { "ts" : Timestamp(1444744494, 1), "t" : NumberLong(2), "h" : NumberLong("-7504719105121076257"), "v" : 2, "op" : "n", "ns" : "", "o" : { "msg" : "new primary" } }
      test:PRIMARY> db.getSiblingDB("local").oplog.rs.insert({ts: new Timestamp(1444669076,3), op:"n", h: NumberLong("12312")})
      WriteResult({ "nInserted" : 1 })
      test:PRIMARY> db.getSiblingDB("local").oplog.rs.find()
      { "_id" : ObjectId("561d0d6930adac216043a162"), "ts" : Timestamp(1444669076, 3), "op" : "n", "h" : NumberLong(12312) }
      { "ts" : Timestamp(1444669605, 1), "t" : NumberLong(0), "h" : NumberLong("-6898850243195961135"), "v" : 2, "op" : "n", "ns" : "", "o" : { "msg" : "initiating set" } }
      { "ts" : Timestamp(1444669606, 1), "t" : NumberLong(1), "h" : NumberLong("-1589401225501337977"), "v" : 2, "op" : "n", "ns" : "", "o" : { "msg" : "new primary" } }
      { "ts" : Timestamp(1444669631, 1), "t" : NumberLong(1), "h" : NumberLong("1621003532950817417"), "v" : 2, "op" : "n", "ns" : "", "o" : { "foo" : 1 } }
      { "ts" : Timestamp(1444744494, 1), "t" : NumberLong(2), "h" : NumberLong("-7504719105121076257"), "v" : 2, "op" : "n", "ns" : "", "o" : { "msg" : "new primary" } }
      test:PRIMARY> db.getSiblingDB("local").oplog.rs.count()
      8
      test:PRIMARY> db.getSiblingDB("local").oplog.rs.stats().count
      8
      test:PRIMARY> db.getSiblingDB("local").oplog.rs.insert({ts: new Timestamp(1444669076,3), op:"n", h: NumberLong("12312")})
      WriteResult({ "nInserted" : 1 })
      test:PRIMARY> db.getSiblingDB("local").oplog.rs.stats().count
      9
      test:PRIMARY> db.getSiblingDB("local").oplog.rs.count()
      9
      

      The mmapv1 storage engine does not show this behavior:

      > db.getSiblingDB("local").oplog.rs.find()
      { "ts" : Timestamp(1444744966, 1), "t" : NumberLong(0), "h" : NumberLong("373345472902605703"), "v" : 2, "op" : "n", "ns" : "", "o" : { "msg" : "initiating set" } }
      { "ts" : Timestamp(1444744967, 1), "t" : NumberLong(1), "h" : NumberLong("5520691837775396305"), "v" : 2, "op" : "n", "ns" : "", "o" : { "msg" : "new primary" } }
      test:PRIMARY> db.getSiblingDB("local").oplog.rs.insert({ts: new Timestamp(1444669076,3), op:"n", h: NumberLong("12312")})
      WriteResult({ "nInserted" : 1 })
      test:PRIMARY> db.getSiblingDB("local").oplog.rs.find()
      { "ts" : Timestamp(1444744966, 1), "t" : NumberLong(0), "h" : NumberLong("373345472902605703"), "v" : 2, "op" : "n", "ns" : "", "o" : { "msg" : "initiating set" } }
      { "ts" : Timestamp(1444744967, 1), "t" : NumberLong(1), "h" : NumberLong("5520691837775396305"), "v" : 2, "op" : "n", "ns" : "", "o" : { "msg" : "new primary" } }
      { "_id" : ObjectId("561d0f0e30adac216043a164"), "ts" : Timestamp(1444669076, 3), "op" : "n", "h" : NumberLong(12312) }
      test:PRIMARY> db.getSiblingDB("local").oplog.rs.insert({ts: new Timestamp(1444669076,3), op:"n", h: NumberLong("12312")})
      WriteResult({ "nInserted" : 1 })
      test:PRIMARY> db.getSiblingDB("local").oplog.rs.insert({ts: new Timestamp(1444669076,3), op:"n", h: NumberLong("12312")})
      WriteResult({ "nInserted" : 1 })
      test:PRIMARY> db.getSiblingDB("local").oplog.rs.find()
      { "ts" : Timestamp(1444744966, 1), "t" : NumberLong(0), "h" : NumberLong("373345472902605703"), "v" : 2, "op" : "n", "ns" : "", "o" : { "msg" : "initiating set" } }
      { "ts" : Timestamp(1444744967, 1), "t" : NumberLong(1), "h" : NumberLong("5520691837775396305"), "v" : 2, "op" : "n", "ns" : "", "o" : { "msg" : "new primary" } }
      { "_id" : ObjectId("561d0f0e30adac216043a164"), "ts" : Timestamp(1444669076, 3), "op" : "n", "h" : NumberLong(12312) }
      { "_id" : ObjectId("561d0f1330adac216043a165"), "ts" : Timestamp(1444669076, 3), "op" : "n", "h" : NumberLong(12312) }
      { "_id" : ObjectId("561d0f1430adac216043a166"), "ts" : Timestamp(1444669076, 3), "op" : "n", "h" : NumberLong(12312) }
      

      Attachments

        Activity

          People

            backlog-server-repl Backlog - Replication Team
            scotthernandez Scott Hernandez (Inactive)
            Votes:
            0 Vote for this issue
            Watchers:
            6 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: