Welcome to the forum @dt2021
It’s harder to say with only partial logs and no Excel to help with date math. Better logs would look like this:
2021-10-29 07:55:36 -04 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-StartCheck]: Start checking if backups can be removed
2021-10-29 07:55:36 -04 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-FramesAndIntervals]: Time frames and intervals pairs: 1.00:00:00 / Keep all, 7.00:00:00 / 1.00:00:00, 28.00:00:00 / 7.00:00:00, 365.00:00:00 / 31.00:00:00
2021-10-29 07:55:36 -04 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-BackupList]: Backups to consider: 10/29/2021 7:19:47 AM, 10/28/2021 9:50:00 PM, 10/28/2021 8:50:00 PM, 10/28/2021 7:50:01 PM, 10/28/2021 6:50:13 PM, 10/28/2021 5:50:02 PM, 10/28/2021 4:50:33 PM, 10/28/2021 3:50:28 PM, 10/28/2021 2:50:04 PM, 10/28/2021 1:50:04 PM, 10/28/2021 12:50:06 PM, 10/28/2021 11:50:02 AM, 10/28/2021 10:50:01 AM, 10/28/2021 9:50:04 AM, 10/28/2021 8:50:03 AM, 10/28/2021 7:50:05 AM, 10/27/2021 11:51:23 AM, 10/26/2021 10:50:11 AM, 10/25/2021 9:51:01 AM, 10/24/2021 9:50:00 AM, 10/23/2021 8:51:46 AM, 10/22/2021 8:50:09 AM, 10/21/2021 8:50:01 AM, 10/13/2021 8:50:35 PM, 10/6/2021 5:50:03 PM
2021-10-29 07:55:36 -04 - [Profiling-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-NextTimeAndFrame]: Next time frame and interval pair: 1.00:00:00 / Keep all
2021-10-29 07:55:36 -04 - [Profiling-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-BackupsInFrame]: Backups in this time frame: 10/28/2021 8:50:03 AM, 10/28/2021 9:50:04 AM, 10/28/2021 10:50:01 AM, 10/28/2021 11:50:02 AM, 10/28/2021 12:50:06 PM, 10/28/2021 1:50:04 PM, 10/28/2021 2:50:04 PM, 10/28/2021 3:50:28 PM, 10/28/2021 4:50:33 PM, 10/28/2021 5:50:02 PM, 10/28/2021 6:50:13 PM, 10/28/2021 7:50:01 PM, 10/28/2021 8:50:00 PM, 10/28/2021 9:50:00 PM, 10/29/2021 7:19:47 AM
2021-10-29 07:55:36 -04 - [Profiling-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-KeepBackups]: Keeping backup: 10/28/2021 8:50:03 AM
2021-10-29 07:55:36 -04 - [Profiling-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-KeepBackups]: Keeping backup: 10/28/2021 9:50:04 AM
2021-10-29 07:55:36 -04 - [Profiling-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-KeepBackups]: Keeping backup: 10/28/2021 10:50:01 AM
2021-10-29 07:55:36 -04 - [Profiling-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-KeepBackups]: Keeping backup: 10/28/2021 11:50:02 AM
2021-10-29 07:55:36 -04 - [Profiling-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-KeepBackups]: Keeping backup: 10/28/2021 12:50:06 PM
2021-10-29 07:55:36 -04 - [Profiling-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-KeepBackups]: Keeping backup: 10/28/2021 1:50:04 PM
2021-10-29 07:55:36 -04 - [Profiling-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-KeepBackups]: Keeping backup: 10/28/2021 2:50:04 PM
2021-10-29 07:55:36 -04 - [Profiling-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-KeepBackups]: Keeping backup: 10/28/2021 3:50:28 PM
2021-10-29 07:55:36 -04 - [Profiling-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-KeepBackups]: Keeping backup: 10/28/2021 4:50:33 PM
2021-10-29 07:55:36 -04 - [Profiling-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-KeepBackups]: Keeping backup: 10/28/2021 5:50:02 PM
2021-10-29 07:55:36 -04 - [Profiling-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-KeepBackups]: Keeping backup: 10/28/2021 6:50:13 PM
2021-10-29 07:55:36 -04 - [Profiling-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-KeepBackups]: Keeping backup: 10/28/2021 7:50:01 PM
2021-10-29 07:55:36 -04 - [Profiling-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-KeepBackups]: Keeping backup: 10/28/2021 8:50:00 PM
2021-10-29 07:55:36 -04 - [Profiling-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-KeepBackups]: Keeping backup: 10/28/2021 9:50:00 PM
2021-10-29 07:55:36 -04 - [Profiling-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-KeepBackups]: Keeping backup: 10/29/2021 7:19:47 AM
2021-10-29 07:55:36 -04 - [Profiling-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-NextTimeAndFrame]: Next time frame and interval pair: 7.00:00:00 / 1.00:00:00
2021-10-29 07:55:36 -04 - [Profiling-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-BackupsInFrame]: Backups in this time frame: 10/22/2021 8:50:09 AM, 10/23/2021 8:51:46 AM, 10/24/2021 9:50:00 AM, 10/25/2021 9:51:01 AM, 10/26/2021 10:50:11 AM, 10/27/2021 11:51:23 AM, 10/28/2021 7:50:05 AM
2021-10-29 07:55:36 -04 - [Profiling-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-KeepBackups]: Keeping backup: 10/22/2021 8:50:09 AM
2021-10-29 07:55:36 -04 - [Profiling-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-KeepBackups]: Keeping backup: 10/23/2021 8:51:46 AM
2021-10-29 07:55:36 -04 - [Profiling-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-KeepBackups]: Keeping backup: 10/24/2021 9:50:00 AM
2021-10-29 07:55:36 -04 - [Profiling-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-KeepBackups]: Keeping backup: 10/25/2021 9:51:01 AM
2021-10-29 07:55:36 -04 - [Profiling-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-KeepBackups]: Keeping backup: 10/26/2021 10:50:11 AM
2021-10-29 07:55:36 -04 - [Profiling-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-KeepBackups]: Keeping backup: 10/27/2021 11:51:23 AM
2021-10-29 07:55:36 -04 - [Profiling-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-DeletingBackups]: Deleting backup: 10/28/2021 7:50:05 AM
2021-10-29 07:55:36 -04 - [Profiling-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-NextTimeAndFrame]: Next time frame and interval pair: 28.00:00:00 / 7.00:00:00
2021-10-29 07:55:36 -04 - [Profiling-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-BackupsInFrame]: Backups in this time frame: 10/6/2021 5:50:03 PM, 10/13/2021 8:50:35 PM, 10/21/2021 8:50:01 AM
2021-10-29 07:55:36 -04 - [Profiling-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-KeepBackups]: Keeping backup: 10/6/2021 5:50:03 PM
2021-10-29 07:55:36 -04 - [Profiling-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-KeepBackups]: Keeping backup: 10/13/2021 8:50:35 PM
2021-10-29 07:55:36 -04 - [Profiling-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-KeepBackups]: Keeping backup: 10/21/2021 8:50:01 AM
2021-10-29 07:55:36 -04 - [Profiling-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-NextTimeAndFrame]: Next time frame and interval pair: 365.00:00:00 / 31.00:00:00
2021-10-29 07:55:36 -04 - [Profiling-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-BackupsInFrame]: Backups in this time frame:
2021-10-29 07:55:36 -04 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-BackupsToDelete]: Backups outside of all time frames and thus getting deleted:
2021-10-29 07:55:36 -04 - [Information-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-AllBackupsToDelete]: All backups to delete: 10/28/2021 7:50:05 AM
2021-10-29 07:55:36 -04 - [Information-Duplicati.Library.Main.Operation.DeleteHandler-DeleteRemoteFileset]: Deleting 1 remote fileset(s) ...
That’s from huge Profiling log. If you want to look at retention in great detail, use log-file-log-filter, however I’m not sure how that interacts with log-file-log-level if you still want a general log. Let us know, if you try it.
My impression as well. Because I think both prior posters here read code to some extent, here’s the code.
Assuming it checks in backup order (oldest to newest) within a time frame, the 365.00:00:00 / 31.00:00:00 setting should delete a newer backup that’s less than 31 days from the backup that was taken before that.
9/27/2021 1:13:49 AM, 8/27/2021 8:39:12 AM crosses the end of 31-day month August, so 9/27 is roughly 31 days away, but backup was earlier in the day so it’s actually 30 days and some fractional day, meaning it’s too close to the backup before it, so gets deleted when it leaves the safety of 28.00:00:00 / 7.00:00:00.
In case it’s not clear from the log time display form and the code, the comparison doesn’t go by days, and sometimes it’s helpful to get to at least hours (lowercase h), so that one avoids situations where a daily is slightly late, and chops off the next daily. For people who dislike that, they can set minimum interval to 23h.
The backup start time jitter problem is aggravated by typical backup intervals lining up with typical retention intervals. Get slightly off, and a delete happens. It can happen on hourlies too, but lowercase m is minutes.
Thanks for the detail, but it was a little TL;DR, especially since there’s a lingering question of date ordering.
As evidence that it does times older to newer, look at above log and note which backup it decided to delete:
2021-10-29 07:55:36 -04 - [Profiling-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-KeepBackups]: Keeping backup: 10/27/2021 11:51:23 AM
2021-10-29 07:55:36 -04 - [Profiling-Duplicati.Library.Main.Operation.DeleteHandler:RetentionPolicy-DeletingBackups]: Deleting backup: 10/28/2021 7:50:05 AM
This is everyone’s problem. There are vastly more things people want than people willing and able to help.
GUI smart and custom backup retention aren’t covered #83 is a documentation issue to at least explain it. There are also pointers to some of the original work you might have missed if you didn’t look over GitHub. Perhaps either a pull request or a collaboration between a code expert and the manual author would work. This wouldn’t likely be me, because I have more than a full load trying to keep up with forum. Any helpers?
Duplicati is a community effort, and all areas (docs, forum, test, code, etc.) would really benefit from help.