Local backup not cleaned up by retention policy

[ChainsLunatic]

Describe the bug
Using local backup /archive leaves me with backups that are not cleaned up by the configured retention policy. Dropbox on the other hand is being cleaned up correctly.

To Reproduce
Steps to reproduce the behavior:

1. Setup backup utilizing retention policy of 3 days

image: offen/docker-volume-backup:latest
environment:
  DROPBOX_APP_KEY: "░░░░░░░░░░░░░░░"
  DROPBOX_APP_SECRET: "░░░░░░░░░░░░░░░"
  DROPBOX_REFRESH_TOKEN: "░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░░"
  DROPBOX_REMOTE_PATH: "/Apps/░░░░░░░░░░░░░/backups"
  BACKUP_CRON_EXPRESSION: "0 2 * * *"
  BACKUP_RETENTION_DAYS: "3"
volumes:
  - /var/run/docker.sock:/var/run/docker.sock:ro
  - /etc/timezone:/etc/timezone:ro
  - /etc/localtime:/etc/localtime:ro

  - backup-data:/archive

3. Let it do it's jobs for e.g. a week
4. Collect directory content

~ # ls -la /archive
total 4327680
drwxr-xr-x    2 1000     1000             0 Nov 25 02:01 .
drwxr-xr-x    1 root     root          4096 Nov 17 13:11 ..
-rwxr-xr-x    1 1000     1000     551793735 Nov 19 02:01 backup-2024-11-19T02-00-00.tar.gz
-rwxr-xr-x    1 1000     1000     555052403 Nov 20 02:01 backup-2024-11-20T02-00-00.tar.gz
-rwxr-xr-x    1 1000     1000     558087120 Nov 21 02:01 backup-2024-11-21T02-00-00.tar.gz
-rwxr-xr-x    1 1000     1000     561238941 Nov 22 02:01 backup-2024-11-22T02-00-00.tar.gz
-rwxr-xr-x    1 1000     1000     562819809 Nov 23 02:01 backup-2024-11-23T02-00-00.tar.gz
-rwxr-xr-x    1 1000     1000     566158530 Nov 24 02:01 backup-2024-11-24T02-00-00.tar.gz
-rwxr-xr-x    1 1000     1000     568411176 Nov 25 02:01 backup-2024-11-25T02-00-00.tar.gz

Expected behavior
I would expect only 11/22 to 11/25 to be left after pruning.

Version (please complete the following information):

• Image Version: offen/docker-volume-backup latest 4c971ebeada2 3 months ago 34.3MB
• Docker Version: 27.3.1
• Docker Compose Version (if applicable): v2.29.7

Additional context

[m90]

What's the full log output of such a run? It'd be interesting to see the deadline used by Dropbox as printed here

docker-volume-backup/internal/storage/storage.go

Lines 52 to 57 in 94e59a1

	b.Log(LogLevelInfo, context,
	"Pruned %d out of %d backups as they were older than the given deadline of %s.",
	lenMatches,
	lenCandidates,
	string(formattedDeadline),
	)

[ChainsLunatic]

I'll provide the logs in a few days; as I was tinkering around and doing manual backups I used up my dropbox contingent and had to remove them manually because no new ones could be created

[shalafi99]

Hi @m90
Please keep in mind that unlike the OP, I am not having an issue with backups not being deleted when the appointed retention period is reached.
However, I think I remember you mentioning that usage of the Dropbox backend was not a frequent topic all around.
Since you asked the OP for a full log output, in the spirit of providing (reference?) information for a "differential diagnosis" here goes a recent container backup log run of mine:

time=2024-11-20T08:02:52.838-03:00 level=INFO msg="Successfully scheduled backup from environment with expression 0 20 * * 3,6"
time=2024-11-20T20:00:00.000-03:00 level=INFO msg="Now running script on schedule 0 20 * * 3,6"
time=2024-11-20T20:00:00.020-03:00 level=INFO msg="Fetching fresh access token for Dropbox storage backend." storage=Dropbox
time=2024-11-20T20:00:01.477-03:00 level=INFO msg="Stopping 1 out of 21 running container(s) as they were labeled docker-volume-backup.stop-during-backup=diun."
time=2024-11-20T20:00:01.847-03:00 level=INFO msg="Created backup of `/backup` at `/tmp/backup-diun-2024-11-20T20-00-00.tar.gz`."
time=2024-11-20T20:00:02.361-03:00 level=INFO msg="Restarted 1 container(s)."
time=2024-11-20T20:00:02.592-03:00 level=INFO msg="Stored copy of backup `/tmp/backup-diun-2024-11-20T20-00-00.tar.gz` in `/archive`." storage=Local
time=2024-11-20T20:00:02.600-03:00 level=INFO msg="Created/Updated symlink `backup.latest.tar.gz` for latest backup." storage=Local
time=2024-11-20T20:00:03.163-03:00 level=INFO msg="Destination path '/diun' already exists, no new directory required." storage=Dropbox
time=2024-11-20T20:00:03.164-03:00 level=INFO msg="Starting upload session for backup '/tmp/backup-diun-2024-11-20T20-00-00.tar.gz' at path '/diun'." storage=Dropbox
time=2024-11-20T20:00:06.612-03:00 level=INFO msg="Uploaded a copy of backup '/tmp/backup-diun-2024-11-20T20-00-00.tar.gz' at path '/diun'." storage=Dropbox
time=2024-11-20T20:00:06.788-03:00 level=INFO msg="Pruned 1 out of 9 backups as they were older than the given deadline of 2024-10-21T20:01:06.749165728-03:00." storage=Local
time=2024-11-20T20:00:07.808-03:00 level=INFO msg="Pruned 1 out of 9 backups as they were older than the given deadline of 2024-10-21T20:01:06.749165728-03:00." storage=Dropbox
time=2024-11-20T20:00:07.818-03:00 level=INFO msg="Removed tar file `/tmp/backup-diun-2024-11-20T20-00-00.tar.gz`."

I have 6 other backup containers in my environment, prune behavior is being respected like above.

The only time this did not ever work as expected was when I had set a memory limit to the backup container which was too low in comparison to the output backup file size (the dropbox upload was aborted without any error messages, it took me a little while to figure out why for some stacks' uploads it worked ok and for others it did not 😞 ).

[ChainsLunatic]

Fixing the failing dropbox backup seems to also have fixed the retention