"List of backup timestamps contains duplicates" due to DST change

Support
1

Here in California, DST just ended this morning, and Duplicati seems to not be happy with that.

List of backup timestamps contains duplicates: 2018-11-04 02:00:00, 2018-11-04 01:00:00, 2018-11-04 01:30:00, 2018-11-04 01:00:00, ...

It throws the above error and refuses to back up. I assume that I can work around this by deleting one of the offending “01:00:00” backups, but I wanted to check if there is a more permanent fix. The only other post I could find about this was this one, but they weren’t able to solve it, really (it seems like they restarted their backup from scratch).

Thanks in advance.

P.S.: I’m on version 2.0.3.3_beta_2018-04-02

2

Deleting or editing one of the dlist files would likely be the best way to fix it.

There are some pesky issues with DST in Duplicati

3

I attempted to delete one of the versions just now, but it threw the same error message, and when I checked in the Restore menu, the version was still present.

  Listing remote folder ...
promoting uploaded complete file from Uploading to Uploaded: duplicati-20181104T103000Z.dlist.zip.aes

System.Exception: List of backup timestamps contains duplicates: 2018-11-04 02:30:00, 2018-11-04 02:00:00, 2018-11-04 01:00:00, 2018-11-04 01:30:00, 2018-11-04 01:00:00, 2018-11-04 00:30:00, 2018-11-04 00:00:00, 2018-11-03 23:30:00, 2018-11-03 23:00:00, 2018-11-03 22:30:00, 2018-11-03 22:00:00, 2018-11-03 21:30:00, 2018-11-03 21:00:00, 2018-11-03 20:30:00, 2018-11-03 20:00:00, 2018-11-03 19:30:00, 2018-11-03 19:00:00, 2018-11-03 18:30:00, 2018-11-03 18:00:00, 2018-11-03 17:30:00, 2018-11-03 17:03:35, 2018-11-03 16:30:00, 2018-11-03 16:00:00, 2018-11-03 15:30:00, 2018-11-03 15:00:00, 2018-11-03 14:30:32, 2018-11-03 14:20:23, 2018-11-03 04:30:00, 2018-11-03 04:00:00, 2018-11-03 03:30:00, 2018-11-03 03:00:00, 2018-11-03 02:30:00, 2018-11-03 02:00:00, 2018-11-03 01:30:00, 2018-11-03 00:30:00, 2018-11-02 23:30:00, 2018-11-02 22:30:00, 2018-11-02 21:30:00, 2018-11-02 20:30:00, 2018-11-02 19:30:00, 2018-11-02 18:30:00, 2018-11-02 17:30:00, 2018-11-02 16:30:00, 2018-11-02 15:30:00, 2018-11-02 14:30:00, 2018-11-02 13:30:00, 2018-11-02 12:30:00, 2018-11-02 11:30:00, 2018-11-02 10:30:00, 2018-11-02 09:11:54, 2018-11-02 02:30:00, 2018-11-02 01:30:00, 2018-11-02 00:30:00, 2018-11-01 23:30:00, 2018-11-01 22:30:00, 2018-11-01 21:30:00, 2018-11-01 20:30:00, 2018-11-01 19:30:00, 2018-11-01 18:30:00, 2018-11-01 17:30:00, 2018-11-01 16:30:00, 2018-11-01 15:30:00, 2018-11-01 14:30:00, 2018-11-01 13:30:00, 2018-11-01 12:30:00, 2018-11-01 11:30:00, 2018-11-01 10:30:00, 2018-11-01 09:03:55, 2018-11-01 03:00:00, 2018-11-01 02:00:00, 2018-11-01 01:00:00, 2018-11-01 00:00:00, 2018-10-31 23:00:00, 2018-10-31 22:00:00, 2018-10-31 21:00:00, 2018-10-31 20:00:00, 2018-10-31 19:00:00, 2018-10-31 18:00:00, 2018-10-31 17:00:00, 2018-10-31 16:00:00, 2018-10-31 15:00:00, 2018-10-31 14:00:00, 2018-10-31 13:00:00, 2018-10-31 12:00:00, 2018-10-31 11:00:00, 2018-10-31 10:00:00, 2018-10-31 08:44:30, 2018-10-31 00:00:00, 2018-10-30 23:00:00, 2018-10-30 22:00:00, 2018-10-30 21:00:00, 2018-10-30 20:00:00, 2018-10-30 19:00:00, 2018-10-30 18:00:00, 2018-10-30 17:00:00, 2018-10-30 16:00:00, 2018-10-30 15:00:00, 2018-10-30 14:00:00, 2018-10-30 13:00:00, 2018-10-30 12:00:00, 2018-10-30 11:00:00, 2018-10-30 10:00:00, 2018-10-30 08:33:49, 2018-10-30 01:30:00, 2018-10-30 00:30:00, 2018-10-29 23:30:00, 2018-10-29 22:30:00, 2018-10-29 21:30:00, 2018-10-29 20:30:00, 2018-10-29 19:30:00, 2018-10-29 18:30:00, 2018-10-29 17:30:00, 2018-10-29 16:30:00, 2018-10-29 15:30:00, 2018-10-29 14:30:00, 2018-10-29 13:30:00, 2018-10-29 12:30:00, 2018-10-29 11:30:00, 2018-10-29 10:30:00, 2018-10-29 09:30:00, 2018-10-29 08:22:24, 2018-10-29 02:30:00, 2018-10-29 01:30:00, 2018-10-29 00:30:00, 2018-10-28 23:30:00, 2018-10-28 22:30:00, 2018-10-28 21:30:00, 2018-10-28 20:30:00, 2018-10-28 19:30:00, 2018-10-28 18:30:00, 2018-10-28 17:30:00, 2018-10-28 16:30:00, 2018-10-28 15:30:00, 2018-10-28 14:30:00, 2018-10-28 13:30:00, 2018-10-28 12:19:57, 2018-10-28 00:30:00, 2018-10-27 00:30:00, 2018-10-26 00:30:00, 2018-10-25 00:00:00, 2018-10-23 23:30:00, 2018-10-22 23:30:00, 2018-10-21 23:30:00, 2018-10-20 23:00:00, 2018-10-19 22:15:00, 2018-10-18 21:45:00, 2018-10-17 21:30:00, 2018-10-16 21:30:00, 2018-10-15 21:00:00, 2018-10-14 19:24:06
   at Duplicati.Library.Main.Operation.DeleteHandler.GetFilesetsToDelete(DateTime[] allBackups)
   at Duplicati.Library.Main.Operation.DeleteHandler.DoRun(LocalDeleteDatabase db, IDbTransaction& transaction, Boolean hasVerifiedBacked, Boolean forceCompact, BackendManager sharedManager)
   at Duplicati.Library.Main.Operation.DeleteHandler.Run()
   at Duplicati.Library.Main.Controller.RunAction[T](T result, String[]& paths, IFilter& filter, Action`1 method)
   at Duplicati.Library.Main.Controller.Delete()
   at Duplicati.CommandLine.Commands.Delete(TextWriter outwriter, Action`1 setup, List`1 args, Dictionary`2 options, IFilter filter)
   at Duplicati.CommandLine.Program.RunCommandLine(TextWriter outwriter, TextWriter errwriter, Action`1 setup, String[] args)
Return code: 100

Is there any way I can bypass this validation check in order to delete this specific backup?

Thanks.

4

How did you delete it?

There is some discussion about using the delete command manually (e.g. from commandline through the web UI): How does retention work?

The restore points exists both in the local database and on the remote store as a dlist, so the delete command has to remove both.

It’s possible to do operations with --no-local-db if there is an inconsistency, this is what Direct restore from backup files ... does on the restore page.

In either case, I’ll look into if there’s an issue on Github or if one should be created.

EDIT: I found List of backup timestamps contains duplicates · Issue #2857 · duplicati/duplicati · GitHub so it’s noted as a milestone, but it hasn’t be fixed yet.

5

I tried to delete using both the “delete” Commandline… option on the web UI and using the Duplicati.CommandLine.exe utility. For example, the full command I tried with the CommandLine utility was:

Duplicati.CommandLine.exe delete <target url> --passphrase=<encryption key> --dbpath=<local db path> --version=2 --no-auto-compact=true --debug-output=true --dry-run

Which returned the same error as above.

After my last post, I then tried deleting the dlist file from the destination that had the UTC time corresponding to the conflicting backup, but subsequently running a database repair replaced it on the destination. I therefore deleted it again and backed up my local DB before telling Duplicati to do a full rebuild of the local database, which I imagine should ultimately have the desired outcome.

I’ll update again once the rebuild is done.

6

The delete command looks correct, I’m wondering if it doesn’t know the file name and relies on the timestamp.

Your manual intervention is how I would have done as well if the tool didn’t work. Keep me posted.

7

So this error happens with every run now, not just ones that happened during the “duplicated” hour created by the clock adjustments, correct?

8

Yes, that is correct.

9

Thanks. So it sounds like only jobs with backups scheduled during the time shifted hour will have this problem.

I’m assuming this flow causes the issue:

  • at X o’clock backup runs, finds no duplicate back times recorded, and runs as normal.
  • clock adjusts back
  • at X o’clock (again) backup runs, finds no duplicate backup times recorded, and runs as normal
  • at Y o’clock backup runs, FINDS duplicate backup times recorded, and throws error assuming something went wrongly during a previous run

If I find some time I’ll try to simulate this scenario to verify (and test resolutions).

1 Like
10

I also have this problem, but only on the machine where I run backups once per hour. So when DST change happened I had two backup jobs which appear to have run at the same time, I guess.

Most of my other machines run backups every 4 hours and do not have this problem.

Would be nice to find a solution soon.

11

Screen shot showing the two “conflicting” backups:

Capture

12

Just for the heck of it I commented out that check for duplicate backups and recompiled Duplicati.Library.Main.dll. Backups are working again. Not sure what bad side effects I may have caused by disabling that check!

1 Like
13

Yeah, I was wondering if that would be a quick workaround. I suspect you’re not causing issues so much as potentially allowing future problems to go undetected.

I’d suggest you check your destination and make sure you really have two different dlist files for the “duplicate” backup. If so, manually run the delete command (by version #) to remove one of them then turn the duplicate check back on.

A longer term fix will likely involve storing UTC and local time for backups then checking BOTH for duplication before declaring a conflict.

14

What’s the best way to check the dlist corresponding to specific backups?

15

I can at least share how I was able to figure it out on my side.

Looking at the contents of the backup destination (in my case, an FTP server), I was able to find the dlist files for each version that I could see from the restore UI:

com_2124%20-%20FileZilla

(There was also a duplicati-20181104T090000Z.dlist.zip.aes file here, which was the “duplicate” backup, before I deleted it.)

From here, I looked at the UTC timestamps in the filenames (though, I suppose, you could look at the Last modified date as well) and found the two that corresponded to both “1 am” backups. Since I’m in the Pacific time zone, those were duplicati-20181104T090000Z.dlist.zip.aes and duplicati-20181104T080000Z.dlist.zip.aes. To double-check my work, I used Get-Date in PowerShell to convert the timestamps to local time:

PS C:\Users\amloessb> Get-Date "2018-11-04T09:00:00Z"

2018年11月4日 01:00:00

PS C:\Users\amloessb> Get-Date "2018-11-04T08:00:00Z"

2018年11月4日 01:00:00

Since backup versions are numbered from 0, and this was the 3rd most recent backup, I checked to make sure that it showed up as version 2 in the restore UI, which it did.

I hope that helps.

P.S.: @Pectojin Database re-creation is still running. It got to about 90% this morning and has been poking along at a snail’s pace ever since.

16

Thanks for the info - not too excited about having to rebuild the database to fix this. Maybe I’ll wait for a better fix in an upcoming version. For now the backups seem to be working after I removed the check for duplicates.

17

The annoying inability to just run delete command is probably because the check catching us runs just before that. Originally I was wondering why we got a complaint, thinking allBackups was UTC, but now I suspect it’s in local time because I found what looks like conversion from UTC time stored in the database and in dlist name.

The above was sort of a lead-in to a bypass, but you must be willing to edit the database and test a just-made method of retroactively tweaking the timestamp of a backup so it doesn’t land right on another due to daylight saving time. What I did for my test was to use DB Browser for SQLite to timestamp my 1:00 PM backup to 1:01 in the RemoteVolume table (change dlist name), then take that ID to Fileset table as VolumeID and add 60 to Timestamp to keep the fake backup time consistent. One can sanitycheck/doublecheck numerical time values in various ways. I used https://www.epochconverter.com/. Before starting, on Windows, one must touch the job database (e.g. using Server or TrayIcon) using --unencrypted-database. For safety, I kept database backups, did a repair first from the job Commandline (all OK), and used a --dry-run and --console-log-level=Information to keep an eye on what would happen. As hoped, Duplicati did what it thought was a restoration of 1:01 dlist plus a delete of a 1:00 dlist that it no longer recognized as valid, so I let it go for real and all seems OK so far. For a daylight savings time failure, you’d of course move a conflicting backup, but I don’t have one to move…

Editing databases is dangerous, so use all the safeties if you try this. Recreate can be dangerous too (might error partway through), so that path should also do a database backup first. Recreate can also be very slow. Obviously this annual bug should be fixed, and the above is just a possible workaround for stopped backups.

I wonder if I can get @drwtsn32 to test this? If it works well, it should allow use of unmodified Duplicati again.

18

Oh, I got rid of the “duplicate” backup by just purging it. I changed my --retention-policy setting temporarily from ‘7D:0s…’ to ‘7D:1h…’. When I ran the next backup, Duplicati purged one of the conflicting backups automatically (not sure which - it didn’t really matter to me). I then put the unmodified DLL back in place and don’t have the error any more.

I am curious why Duplicati source needs to check for duplicate timestamps in the first place…

19

I didn’t write it, so I can only guess. Sometimes programmers want to know (for sure) that things are a certain way so that they can then act with that knowledge instead of always wondering, or covering all odd situations. Duplicati has lots of sanity checks (that sometimes go off) that keep it from making bigger messes of things…

As an example of code where reliance on having no duplicated times seems to exist, the code doing the new retention policy thinning pulls the newest backup aside and puts it back after thinning is done. This ordinarily prevents it from being deleted, but that prevention is bypassed if that backup appears twice in the sorted list. Looking at the code below the check you deleted, you can see it’s generally careful to use “Distinct” despite having checked. Double coverage adds safety, but the new retention might have zero checks after your edit. Whether or not I’m reading the code right is not totally relevant, because it’s just an illustration of the point…

Or maybe the check is to prevent ugly cosmetics of confusingly seeing the same time twice on the dropdown.

20

So, after leaving the database rebuild running for 4 days and 19 hours, I gave up and used @drwtsn32’s method of recompiling Duplicati.Library.Main.dll without the problematic sanity check. I then (after restoring the DB from backup and re-uploading the “duplicate” dlist file) ran the same delete command that I previously tried, which succeeded to delete the duplicate backup this time.

I then shut down Duplicati, switched back to the original DLL, and now everything is working properly again.