Sync does not delete old files

Help and Support
1

What is the problem you are having with rclone?

While using "rclone sync" in combination with "--delete-after" old files are not deleted.

What is your rclone version (output from rclone version)

rclone v1.45
- os/arch: linux/amd64
- go version: go1.11.6

Which OS you are using and how many bits (eg Windows 7, 64 bit)

Debian 10.7 64-bit (Proxmox VE server)

Which cloud storage system are you using? (eg Google Drive)

S3 compatible cloud storage with Linode

The command you were trying to run (eg rclone copy /tmp remote:tmp)

rclone sync --log-file=/tmp/backup_linodes3.log --log-level=DEBUG --delete-after /datapool1/dump/ linode_xxxxxxxxx:/backup/pve

The rclone config contents with secrets removed.

[linode_hidden]
type = s3
provider = Other
env_auth = false
access_key_id = secret
secret_access_key = secret
region = eu-central-1
acl = private
location_constraint = eu-central-1
endpoint = hidden

A log from the command with the -vv flag

I've redacted the logfile a bit to avoid the repeating progress data (none showed an error)

2021/01/12 19:10:48 DEBUG : rclone: Version "v1.45" starting with parameters ["rclone" "sync" "--log-file=/tmp/backup_linodes3.log" "--log-level=DEBUG" "--delete-after" "/datapool1/dump/" "linode_hidden:/backup/pve"]
2021/01/12 19:10:48 DEBUG : Using config file from "/root/.config/rclone/rclone.conf"
2021/01/12 19:10:49 DEBUG : pacer: Reducing sleep to 0s
2021/01/12 19:10:49 INFO  : S3 bucket backup path pve/: Waiting for checks to finish
2021/01/12 19:10:49 INFO  : S3 bucket backup path pve/: Waiting for transfers to finish
2021/01/12 19:10:49 INFO  : vzdump-qemu-100-2021_01_11-01_00_01.log: Copied (new)
2021/01/12 19:10:49 INFO  : vzdump-qemu-100-2021_01_12-01_00_01.log: Copied (new)
2021/01/12 19:10:49 INFO  : vzdump-qemu-101-2021_01_11-01_03_50.log: Copied (new)
2021/01/12 19:10:49 INFO  : vzdump-qemu-101-2021_01_12-01_03_37.log: Copied (new)
2021/01/12 19:11:49 INFO  :
Transferred:       33.505k / 37.383 GBytes, 0%, 567 Bytes/s, ETA 19633h29m46s
Errors:                 0
Checks:                 0 / 0, -
Transferred:            4 / 10, 40%
Elapsed time:      1m0.4s
Transferring:
 *     vzdump-qemu-100-2021…_11-01_00_01.vma.zst:  0% /9.270G, 0/s, -
 *     vzdump-qemu-100-2021…_12-01_00_01.vma.zst:  0% /8.923G, 0/s, -
 *     vzdump-qemu-101-2021…_11-01_03_50.vma.zst:  0% /9.022G, 0/s, -
 *     vzdump-qemu-101-2021…_12-01_03_37.vma.zst:  0% /9.010G, 0/s, -
.
.
.
2021/01/12 22:23:57 INFO  : vzdump-qemu-103-2021_01_12-01_13_59.vma.zst: Copied (new)
2021/01/12 22:23:57 INFO  : Waiting for deletions to finish
2021/01/12 22:23:57 INFO  :
Transferred:       37.383G / 37.383 GBytes, 100%, 3.303 MBytes/s, ETA 0s
Errors:                 0
Checks:                 0 / 0, -
Transferred:           10 / 10, 100%
Elapsed time:   3h13m8.5s

2021/01/12 22:23:57 DEBUG : 5 go routines active
2021/01/12 22:23:57 DEBUG : rclone: Version "v1.45" finishing with parameters ["rclone" "sync" "--log-file=/tmp/backup_linodes3.log" "--log-level=DEBUG" "--delete-after" "/datapool1/dump/" "linode_hidden:/backup/pve"]

Please advice. Maybe someone will suggest to upgrade, but this is the version currently shipped with Debian 10.

Cheers,

BC

2

Please upgrade as you want to install from the rclone site and not from any repo as they are all ancient and not well maintained.

3

Hi,

I just upgraded:

rclone v1.53.3
- os/arch: linux/amd64
- go version: go1.15.5

A run takes 3.5 hours, so I will report back tomorrow,

Cheers,

BC

1 Like
4

So the run has ended and the files are still there on the S3 object storage.
Looking at the debug file it is exceptionally long, but does not reflect any errors. Regarding the deletion at the end, I see:

2021/01/13 05:14:39 DEBUG : Waiting for deletions to finish
2021/01/13 05:14:39 INFO  :
Transferred:       38.578G / 38.578 GBytes, 100%, 3.383 MBytes/s, ETA 0s
Transferred:           12 / 12, 100%
Elapsed time:   3h14m37.6s

Please advice,

Cheers,
BC

5

Can you include the full debug log please?

6

I cannot paste it here nor on pastebin.com because it's too big , allow me to look for an alternative,

BC

7

Please check https://privatebin.net/?43360ec99ca8c244#CJRTfTgXcD6ZTfcjMDAz3MP1ndZC6vWJFSC4AJXU8odV

BC

8

Sweet. The debug log validates many things along the way and is just super helpful.

What's the rclone ls on the source vs the dest look like? What's on the dest that should not be?

I'd expect to see something like this at the end:

felix@gemini:~/test1$ rclone sync /home/felix/test1 /home/felix/test2 -vv --delete-after
2021/01/13 09:15:23 DEBUG : rclone: Version "v1.53.3" starting with parameters ["rclone" "sync" "/home/felix/test1" "/home/felix/test2" "-vv" "--delete-after"]
2021/01/13 09:15:23 DEBUG : Creating backend with remote "/home/felix/test1"
2021/01/13 09:15:23 DEBUG : Using config file from "/opt/rclone/rclone.conf"
2021/01/13 09:15:23 DEBUG : Creating backend with remote "/home/felix/test2"
2021/01/13 09:15:23 DEBUG : Local file system at /home/felix/test2: Waiting for checks to finish
2021/01/13 09:15:23 DEBUG : Local file system at /home/felix/test2: Waiting for transfers to finish
2021/01/13 09:15:23 DEBUG : hosts: MD5 = 0e85d4dc7562b55116a9d144da989dfb OK
2021/01/13 09:15:23 DEBUG : blah: MD5 = 0e85d4dc7562b55116a9d144da989dfb OK
2021/01/13 09:15:23 INFO  : hosts: Copied (new)
2021/01/13 09:15:23 INFO  : blah: Copied (new)
2021/01/13 09:15:23 DEBUG : Waiting for deletions to finish
2021/01/13 09:15:23 INFO  : deleteme: Deleted
2021/01/13 09:15:23 INFO  :
Transferred:           450 / 450 Bytes, 100%, 1.288 MBytes/s, ETA 0s
Checks:                 1 / 1, 100%
Deleted:                1
Transferred:            2 / 2, 100%
Elapsed time:         0.0s

2021/01/13 09:15:23 DEBUG : 2 go routines active
9

The source contains 2 versions of backups of virtual machines plus their corresponding log files. The source is changing daily and old versions are deleted.
The destination, currently, contains these backups but all backup versions are there, so things are accumulating constantly as older versions are not deleted. This gets expensive of course.

Cheers,

BC

10

From your example I gather this is missing:

2021/01/13 09:15:23 INFO  : deleteme: Deleted

So I assume the problem is related to that?

BC

11

The usual reason for sync not deleting files is that there were IO errors in the transfer - if there were IO errors then rclone will skip the delete phase for safety.

This doesn't appear to be the case in the log you've posted

After you've done a transfer can you do

rclone -vv check /datapool1/dump/ linode_dekringwinkel:/backup/pve

That will tell you whether rclone things the source and destionation are in sync or not.

If you could paste the output of

rclone lsf /datapool1/dump/

and

rclone lsf linode_dekringwinkel:/backup/pve

Then that should show the problem

12

Hi,

This produced some errors:

root@pm01:/install/rclone# rclone -vv check /datapool1/dump/ linode_dekringwinkel:/backup/pve
2021/01/13 16:34:25 DEBUG : rclone: Version "v1.53.3" starting with parameters ["rclone" "-vv" "check" "/datapool1/dump/" "linode_dekringwinkel:/backup/pve"]
2021/01/13 16:34:25 DEBUG : Creating backend with remote "/datapool1/dump/"
2021/01/13 16:34:25 DEBUG : Using config file from "/root/.config/rclone/rclone.conf"
2021/01/13 16:34:25 DEBUG : Creating backend with remote "linode_dekringwinkel:/backup/pve"
2021/01/13 16:34:26 DEBUG : fs cache: renaming cache item "linode_dekringwinkel:/backup/pve" to be canonical "linode_dekringwinkel:backup/pve"
2021/01/13 16:34:26 DEBUG : S3 bucket backup path pve: Waiting for checks to finish
2021/01/13 16:34:26 ERROR : vzdump-qemu-100-2021_01_12-01_00_01.log: File not in S3 bucket backup path pve
2021/01/13 16:34:26 ERROR : vzdump-qemu-100-2021_01_12-01_00_01.vma.zst: File not in S3 bucket backup path pve
2021/01/13 16:34:26 ERROR : vzdump-qemu-100-2021_01_13-01_00_01.log: File not in S3 bucket backup path pve
2021/01/13 16:34:26 ERROR : vzdump-qemu-100-2021_01_13-01_00_01.vma.zst: File not in S3 bucket backup path pve
2021/01/13 16:34:26 ERROR : vzdump-qemu-101-2021_01_12-01_03_37.log: File not in S3 bucket backup path pve
2021/01/13 16:34:26 ERROR : vzdump-qemu-101-2021_01_12-01_03_37.vma.zst: File not in S3 bucket backup path pve
2021/01/13 16:34:26 ERROR : vzdump-qemu-101-2021_01_13-01_04_26.log: File not in S3 bucket backup path pve
2021/01/13 16:34:26 ERROR : vzdump-qemu-101-2021_01_13-01_04_26.vma.zst: File not in S3 bucket backup path pve
2021/01/13 16:34:26 ERROR : vzdump-qemu-103-2021_01_12-01_13_59.log: File not in S3 bucket backup path pve
2021/01/13 16:34:26 ERROR : vzdump-qemu-103-2021_01_12-01_13_59.vma.zst: File not in S3 bucket backup path pve
2021/01/13 16:34:26 ERROR : vzdump-qemu-103-2021_01_13-01_14_40.log: File not in S3 bucket backup path pve
2021/01/13 16:34:26 ERROR : vzdump-qemu-103-2021_01_13-01_14_40.vma.zst: File not in S3 bucket backup path pve
2021/01/13 16:34:26 NOTICE: S3 bucket backup path pve: 12 files missing
2021/01/13 16:34:26 NOTICE: S3 bucket backup path pve: 12 differences found
2021/01/13 16:34:26 NOTICE: S3 bucket backup path pve: 12 errors while checking
2021/01/13 16:34:26 INFO  :
Transferred:             0 / 0 Bytes, -, 0 Bytes/s, ETA -
Errors:                13 (retrying may help)
Elapsed time:         0.6s

2021/01/13 16:34:26 DEBUG : 5 go routines active
2021/01/13 16:34:26 Failed to check with 13 errors: last error was: 12 differences found

But this can be due to the fact that a backup occured after the last Rclone run.

root@pm01:/install/rclone# rclone lsf /datapool1/dump/
vzdump-qemu-100-2021_01_12-01_00_01.log
vzdump-qemu-100-2021_01_12-01_00_01.vma.zst
vzdump-qemu-100-2021_01_13-01_00_01.log
vzdump-qemu-100-2021_01_13-01_00_01.vma.zst
vzdump-qemu-101-2021_01_12-01_03_37.log
vzdump-qemu-101-2021_01_12-01_03_37.vma.zst
vzdump-qemu-101-2021_01_13-01_04_26.log
vzdump-qemu-101-2021_01_13-01_04_26.vma.zst
vzdump-qemu-103-2021_01_12-01_13_59.log
vzdump-qemu-103-2021_01_12-01_13_59.vma.zst
vzdump-qemu-103-2021_01_13-01_14_40.log
vzdump-qemu-103-2021_01_13-01_14_40.vma.zst

the last command did not show anything:

root@pm01:/install/rclone# rclone lsf linode_dekringwinkel:/backup/pve

BC

13

That seems to say that there is nothing uploaded to your bucket? Which I don't understand, but it explains why there was nothing deleted.

Is there something else accessing the bucket?

Hmm, might you be running simultaneous rclones? Maybe a seperate rclone is removing the contents?

Remember if you are doing syncs to the same bucket from different sources then they need to be to a different directory.

Could the local backup get removed while rclone was uploading?

If you run the rclone check immediately after an rclone sync there should be no differences.

14

Hey Nick.

There is only one instance of rclone running every night.
The bucket is filled with files, I can see that in my management tool.
The backup files are uploaded successfully, I can see them.
Will do the rclone check command after a manual run (which should also deletes files, but does not)

BC

15

image
image849×1219 159 KB

This is a screenshot to show how many files remain on the S3 storage, they stack up ad inifinitum,

cheers,

BC

16

It doesn't delete. It just checks as it does not alter the source or destination.

17

you misread: the rclone check will not delete, but the manual run I referred to, will,

cheers,

BC

18

I didn't misread as I misunderstood and was clarifying for anyone else that might misunderstand what was written.

Cheers.

19

Right, very good.

I am now manually deleting all files on the server and do an rclone run, a backup and a rclone run again. Hopefully this will work out, will keep you posted,

BC

20

This command should have showed your files and the fact that it didn't is the cause of the problem - if rclone can't see the files, it doesn't know it should be deleting them.

Is it possible the s3 user doesn't have permissions to list buckets?

Also could you try these variants

rclone lsf linode_dekringwinkel:backup/pve
rclone lsf -R linode_dekringwinkel:backup/pve
rclone lsf -R --disable ListR linode_dekringwinkel:backup/pve