-
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.