ExportXMLWordPrintableJSON

    • Type: Bug
    • Resolution: Unresolved
    • Priority: Medium
    • None
    • Affects Version/s: 100.18.0
    • Component/s: mongorestore
    • None
    • DB Tools, Tools and Replicator
    • 1

      Problem Statement/Rationale

      mongodump --oplog followed by mongorestore --oplogReplay aborts the entire
      restore if the source database contains a time-series collection that was written
      to while the dump ran. The failure is not limited to the time-series collection:
      the whole restore stops, so unrelated collections in the same dump are left
      incomplete.

      The archive itself is not damaged. Restoring the very same archive with
      --bypassDocumentValidation completes and produces data that matches the
      source exactly over the window the archive covers. The abort therefore comes from
      a bucket-validation check firing on an intermediate state during oplog replay,
      not from corrupt input.

      This makes the documented point-in-time backup workflow unusable for any database
      with an actively written time-series collection, and there is no way to work
      around it in the tools: --oplog requires a full dump, so the collection cannot
      be excluded on the dump side, and mongorestore refuses --oplogReplay
      together with any namespace filter ("cannot use --oplogReplay with excludes
      specified").

      What we would like: either make the dump/replay pairing valid for time-series
      buckets, or fail early with a clear diagnostic instead of aborting mid-restore.
      If the fix belongs in the server rather than the tools, please route this to
      SERVER / time-series triage.

      Steps to Reproduce

      Requires mongod, mongosh, mongodump and mongorestore on PATH.
      Uses ports 29017/29018 and /tmp/ts-repro. Runs in about two minutes.

      #!/bin/bash
      set -uo pipefail
      
      DIR=/tmp/ts-repro
      SRC=mongodb://127.0.0.1:29017/?replicaSet=rs0
      DST=mongodb://127.0.0.1:29018/?replicaSet=rs1
      
      rm -rf "$DIR"; mkdir -p "$DIR/src" "$DIR/dst"
      
      mongod --replSet rs0 --port 29017 --bind_ip 127.0.0.1 --dbpath "$DIR/src" \
             --logpath "$DIR/src.log" --wiredTigerCacheSizeGB 1 --fork >/dev/null
      mongod --replSet rs1 --port 29018 --bind_ip 127.0.0.1 --dbpath "$DIR/dst" \
             --logpath "$DIR/dst.log" --wiredTigerCacheSizeGB 1 --fork >/dev/null
      mongosh --quiet "mongodb://127.0.0.1:29017/?directConnection=true" --eval \
        'rs.initiate({_id:"rs0",members:[{_id:0,host:"127.0.0.1:29017"}]})' >/dev/null
      mongosh --quiet "mongodb://127.0.0.1:29018/?directConnection=true" --eval \
        'rs.initiate({_id:"rs1",members:[{_id:0,host:"127.0.0.1:29018"}]})' >/dev/null
      sleep 6
      
      # time-series collection + history + ballast (the ballast only lengthens the dump)
      mongosh --quiet "$SRC" --eval '
      var d = db.getSiblingDB("tsdb");
      d.dropDatabase();
      d.createCollection("metrics", {timeseries: {timeField: "ts", metaField: "m", granularity: "seconds"}});
      var now = Date.now(), b = [];
      for (var i = 0; i < 50000; i++) {
        b.push({ts: new Date(now - (50000 - i) * 1000), m: "m" + (i % 4), a: i % 97, c: i, e: i % 7});
        if (b.length === 1000) { d.metrics.insertMany(b, {ordered: false}); b = []; }
      }
      if (b.length) d.metrics.insertMany(b, {ordered: false});
      var pad = "x".repeat(4096); b = [];
      for (var j = 0; j < 65536; j++) {
        b.push({n: j, pad: pad});
        if (b.length === 200) { d.aaa_ballast.insertMany(b, {ordered: false}); b = []; }
      }'
      
      # continuous writer into the time-series collection
      mongosh --quiet "$SRC" --eval '
      var d = db.getSiblingDB("tsdb");
      var deadline = Date.now() + 90000, n = 0;
      while (Date.now() < deadline) {
        var b = [];
        for (var i = 0; i < 50; i++) {
          b.push({ts: new Date(), m: "m" + ((n + i) % 4), a: (n + i) % 97, c: n + i, e: (n + i) % 7});
        }
        d.metrics.insertMany(b, {ordered: false});
        n += 50;
      }' &
      writer=$!
      
      # let the writer create buckets BEFORE the dump starts
      sleep 5
      
      mongodump --archive="$DIR/dump.archive" --oplog --uri="$SRC"
      wait "$writer" 2>/dev/null
      
      mongorestore --archive="$DIR/dump.archive" --oplogReplay --uri="$DST"
      

      The condition is timing-dependent (the writer must be active across the dump),
      but with these parameters it reproduced on every attempt: 6 dumps across
      mongod 8.0.32, 8.3.7 and 8.3.11. If a run happens to pass, repeat it.

      Expected Results

      mongorestore --oplogReplay completes, and the target holds the source state
      as of the end of the dump's oplog window.

      Actual Results

      The restore aborts during oplog replay:

      Failed: restore error: error applying oplog: applyOps: (DocumentValidationFailure)
      Location7667503: Bucket _id: 6aa7fffc3e498c0379bbd39b :: caused by ::
      Invalid BSON Column encoding
      65476 document(s) restored successfully. 0 document(s) failed to restore.
      

      Restoring the same archive with --bypassDocumentValidation completes, and the
      result is correct:

      validate({full: true, checkBSONConformance: true}) -> valid: true, errors: []
      
      comparing source and target over the window the archive covers (ts <= max(ts) on target):
        src: n=81550  sumC=1747660475  sumA=3912330
        dst: n=81550  sumC=1747660475  sumA=3912330
      

      Additional Notes

      Analysis. A time-series bucket append is written to the oplog as a $v: 2
      diff carrying a byte-offset patch into the compressed column:

      op: "u", ns: "<db>.system.buckets.<coll>"
      o: { $v: 2, diff: { scontrol: {...},
                          sdata: { b: { "<field>": { o: <byte offset>, d: <appended bytes> } } } } }
      

      o, d means "truncate the column at offset o, then append d", so the patch
      is only valid against the exact pre-image it was computed from.

      Replaying such a stream is fine as long as the bucket's INSERT is inside the
      oplog window: the insert resets the bucket and the diffs rebuild it. We verified
      this by replaying one bucket's full stream op by op - 1 insert plus 80 diffs took
      it from count=1 to count=1000 with no error.

      The failure comes from buckets created before the oplog start timestamp. For
      those, the window holds only diffs. Measured for one failing bucket:

      oplog window: 2737 entries
      ops for this bucket inside the window: 60, of them INSERT: 0
      archived state:      control.version=2  count=345  len(ts)=229  len(waiting)=274
      first op in window:  UPDATE, ts: offset=139 append=42b, waiting: offset=135 append=82b
                            -> targets count=270
      

      The diff expects a pre-image at count=269 (len(ts)=139) but the archive holds
      count=345 (len(ts)=229). Truncating at offset 139 does not yield the earlier
      state, because appending to a BSONColumn repacks the trailing partial Simple8b
      block - the prefix at a given offset is not stable as the bucket grows. In the
      same run a diff with offset=655 was applied to a column of length 689, i.e. it
      rewrote the last 34 bytes. So the truncation lands inside a repacked region and
      the column stops being a well-formed BSONColumn.

      The stream still converges: later diffs overwrite the damaged region, and the
      final state matches the source exactly. Only the per-op validation during
      applyOps sees the malformed intermediate.

      Versions. Reproduced with Database Tools 100.18.0 against mongod 8.0.32, 8.3.7
      and 8.3.11 (all with the same tools build). The inner error varies by version -
      on one 8.0.32 run it surfaced as {{BadValue: Incorrect column data min for field
      'waiting'}} instead - which suggests the issue is not specific to the
      Location7667503 check but to validating the bucket after every applied op.

      Not a workaround. --bypassDocumentValidation happens to produce correct data
      here, but it disables a genuine integrity check, so it is not something we would
      want to standardise on.

      Related. SERVER-76675 introduced the Location7667503 check. SERVER-121132
      describes a similarly shaped problem during logical initial sync, but it is a
      different cause: there the bucket ends up with a version indicating uncompressed
      while holding compressed columns, whereas in our case control.version is 2
      everywhere, including in the bucket's oplog insert.

            Assignee:
            Dave Rolsky
            Reporter:
            Aleksey Kondratev (EXT)
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

              Created:
              Updated: