Backups not "restorable" after 6.3 upgrade

Using FoundationDB
1

Hi, I recently upgraded from 6.2.30 to 6.3.9. After the upgrade, newly taken backups seem to succeed but report not “restorable” in fdbbackup describe. I run the fdbbackup start with -w and it exits without any error. When I run backup status it says it completed at a version:

$ /usr/bin/fdbbackup status [...]
The previous backup on tag `default' at <backupURL> completed at version 37341037222796.
BackupUID: <UID>
BackupURL: <backupURL>

However backup describe for that same backup shows:

$/usr/bin/fdbbackup describe [...] -d "<backupURL>" --version_timestamps
URL: <backupURL>
Restorable: false
Partitioned logs: false
Snapshot:  startVersion=37340640061336 (2021/11/03.00:32:34+0000)  endVersion=37341025172871 (2021/11/03.00:38:59+0000)  totalBytes=247807760945  restorable=false  expiredPct=0.00
SnapshotBytes: 247807760945
MinLogBeginVersion:      37340639699336 (2021/11/03.00:32:34+0000)
ContiguousLogEndVersion: 37340659699336 (2021/11/03.00:32:54+0000)
MaxLogEndVersion:        37341037222797 (2021/11/03.00:39:11+0000)

status json also seems to report these backups as the last restorable backups, implying that it thinks the backup is correct.

I listed the files stored under logs/ for that backup in s3:

2021-11-03 00:33:10   15543400 log,37340639699336,37340659699336,<id>,1048576
2021-11-03 00:38:34   15586330 log,37340659699336,37340680000000,<id>,1048576
2021-11-03 00:38:35   17202396 log,37340680000000,37340701000000,<id>,1048576
2021-11-03 00:38:37   15982999 log,37340701000000,37340722000000,<id>,1048576
2021-11-03 00:38:34   16973921 log,37340722000000,37340743000000,<id>,1048576
2021-11-03 00:38:36   17042492 log,37340743000000,37340764000000,<id>,1048576
2021-11-03 00:38:35   20670557 log,37340764000000,37340785000000,<id>,1048576
2021-11-03 00:38:36   21732211 log,37340785000000,37340806000000,<id>,1048576
2021-11-03 00:38:36   16505583 log,37340806000000,37340827000000,<id>,1048576
2021-11-03 00:38:35   17870614 log,37340827000000,37340848000000,<id>,1048576
2021-11-03 00:38:34   15546839 log,37340848000000,37340869000000,<id>,1048576
2021-11-03 00:38:33   16408900 log,37340869000000,37340890000000,<id>,1048576
2021-11-03 00:38:35   15652378 log,37340890000000,37340911000000,<id>,1048576
2021-11-03 00:38:32   18924242 log,37340911000000,37340932000000,<id>,1048576
2021-11-03 00:38:33   18320261 log,37340932000000,37340953000000,<id>,1048576
2021-11-03 00:38:37   16340490 log,37340953000000,37340974000000,<id>,1048576
2021-11-03 00:38:36   19173216 log,37340974000000,37340995000000,<id>,1048576
2021-11-03 00:38:37    3106381 log,37340995000000,37340997222797,<id>,1048576
2021-11-03 00:38:56   14958408 log,37340997222797,37341017222797,<id>,1048576
2021-11-03 00:41:29   16486454 log,37341017222797,37341037222797,<id>,1048576

(I dont know what that hash is so redacted it in case it’s sensitive) Note that the “finished at” timestamp in the backup status output is 1 less than the max log end version - The second timestamp of the last log file

Seems like the log min timestamp and log contiguous end are the start/end of the very first log, but the remaining timestamps look contiguous to me? Is there anything else I can look at to see why the backup is not restorable? We are not using the experimental partitioned log feature.

Backups taken on 6.2.30 still report as restorable - It’s only backups taken on 6.3.9 that are reporting un-restorable.

2

I think this might be a bug in writing to the backup metadata stored in backup container? I added the --deep flag and then it reports it is restorable:

$ /usr/bin/fdbbackup describe [...] -d "<backupURL>" --deep
URL: <backupURL>
Restorable: true
Partitioned logs: false
Snapshot:  startVersion=37340640061336 (2021/11/03.00:32:34+0000)  endVersion=37341025172871 (2021/11/03.00:38:59+0000)  totalBytes=247807760945  restorable=true  expiredPct=0.00
SnapshotBytes: 247807760945
MinLogBeginVersion:      37340639699336 (2021/11/03.00:32:34+0000)
ContiguousLogEndVersion: 37341037222797 (2021/11/03.00:39:11+0000)
MaxLogEndVersion:        37341037222797 (2021/11/03.00:39:11+0000)
MinRestorableVersion:    37341025172871 (2021/11/03.00:38:59+0000)
MaxRestorableVersion:    37341037222796 (2021/11/03.00:39:11+0000)

(This is the same backup as above)

Then running the same describe without --deep now reports restorable, so I’m guessing it was fixed in the stored FDB metadata by the deep scan.

3

We’ve found that this is due to us running fdbbackup describe during the backup, and not using the --deep flag when we run fdbbackup describe. So the first time the backup is run, the cached metadata is saved and reports the backup as unrestorable, and this never gets changed unless you rerun describe with --deep. I’m guessing this must have changed with 6.3 since we ran fdbbackup describe during backups on 6.2.30 and didn’t hit this.

Would it be possible to update the backup metadata upon the successful completion of a backup? This new behavior feels a bit unintuitive.

4

We have tried with the --deep for the fdbbackup describe command and the backup is in
Restorable : true status, but when we restore the backup from 6.2.29 into 6.3.24, we still got the error message:

...
Tag: default  UID: 747e673c5f28e42da54085419b15ad78  State: starting  Blocks: 0/0  BlocksInProgress: 0  Files: 0  BytesWritten: 0  CurrentVersion: -1  FirstConsistentVersion: 0  ApplyVersionLag: 0  LastError: ''Backup before 6.3 cannot be filtered with key ranges' on 'restore_start'' 0s ago.
...

Any suggestion? Thanks!