Failed to set modification time: 1 error: PCloud: can't set modified time

Suspected Bug
1

What is the problem you are having with rclone?

Runnig rclone with options sync --delete-after fails with errors like

 
2023/05/29 01:01:17 ERROR : backup/db_20230526_141252.sql.bz2: Failed to set modification time: 1 error: PCloud: can't set modified time
2023/05/29 02:21:31 ERROR : Attempt 1/3 failed with 1 errors and: 1 error: PCloud: can't set modified time
2023/05/29 02:26:44 ERROR : backup/db_20230526_141252.sql.bz2: Failed to set modification time: 1 error: PCloud: can't set modified time
2023/05/29 03:44:09 ERROR : Attempt 2/3 failed with 1 errors and: 1 error: PCloud: can't set modified time
2023/05/29 03:49:31 ERROR : backup/db_20230526_141252.sql.bz2: Failed to set modification time: 1 error: PCloud: can't set modified time
2023/05/29 05:06:28 ERROR : Attempt 3/3 failed with 1 errors and: 1 error: PCloud: can't set modified time
2023/05/29 05:06:28 Failed to copy: 1 error: PCloud: can't set modified time

It's a new file, if I delete it manually it will stop with another one.

Run the command 'rclone version' and share the full output of the command.

rclone v1.61.1-DEV
- os/version: freebsd 13.2-release (64 bit)
- os/kernel: 13.2-release (amd64)
- os/type: freebsd
- os/arch: amd64
- go/version: go1.20.3
- go/linking: dynamic
- go/tags: none

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

PCloud in union with local filesystem

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

rclone sync  --delete-after "backup" "Remote_Backup:/backup"

The rclone config contents with secrets removed.

[Local]
type = local

[PCloud]
type = pcloud
hostname = api.pcloud.com
token = 

[Remote_Backup]
type = union
upstreams = Local:/mnt/usb PCloud:/backup
create_policy = epall

A log from the command with the -vv flag

2023/05/29 01:01:17 ERROR : backup/db_20230526_141252.sql.bz2: Failed to set modification time: 1 error: PCloud: can't set modified time
2023/05/29 02:21:31 ERROR : Attempt 1/3 failed with 1 errors and: 1 error: PCloud: can't set modified time
2023/05/29 02:26:44 ERROR : backup/db_20230526_141252.sql.bz2: Failed to set modification time: 1 error: PCloud: can't set modified time
2023/05/29 03:44:09 ERROR : Attempt 2/3 failed with 1 errors and: 1 error: PCloud: can't set modified time
2023/05/29 03:49:31 ERROR : backup/db_20230526_141252.sql.bz2: Failed to set modification time: 1 error: PCloud: can't set modified time
2023/05/29 05:06:28 ERROR : Attempt 3/3 failed with 1 errors and: 1 error: PCloud: can't set modified time
2023/05/29 05:06:28 Failed to copy: 1 error: PCloud: can't set modified time
2

hello and welcome to the forum,

  1. please run rclone selfupdate
  2. find a single file with the issue and run rclone copy -vv
  3. post the full debug output
3

Pcloud can't set modification times so it is necessary to upload a new copy of the file. However this doesn't seem to be happening.

Does it work OK without --delete-after?

I wonder whether the union is confusing rclone somehow.

4

I have another line in the same script, same filesystems but just copy and no --delete-after that works the same and ERROR for the same file.
I have 2 similar files on that filesystem:

2023/05/30 08:02:04 DEBUG : union root 'MySQLbackup': actionPolicy = *policy.EpAll, createPolicy = *policy.EpAll, searchPolicy = *policy.FF
2023/05/30 08:02:04 DEBUG : fs cache: renaming cache item "Backup:/MySQLbackup/" to be canonical "Backup:MySQLbackup"
2023/05/30 08:02:04 DEBUG : db_20230525_004457.sql.bz2: Size and modification time the same (differ by -213.679015ms, within tolerance 1s)
2023/05/30 08:02:04 DEBUG : db_20230525_004457.sql.bz2: Unchanged skipping
2023/05/30 08:02:04 DEBUG : db_20230526_141252.sql.bz2: Modification times differ by -1.199360154s: 2023-05-26 14:20:45.199360154 -0400 EDT, 2023-05-26 14:20:44 -0400 EDT

There also many other files with modification time difference > 1s:

2023/05/30 08:32:08 DEBUG : daily/mysql/daily_mysql_2023-05-26_03h12m_Friday.sql.bz2: Modification times differ by -1.538929331s: 2023-05-26 03:20:33.538929331 -0400 EDT, 2023-05-26 03:20:32 -0400 EDT
2023/05/30 08:32:08 DEBUG : daily/mysql/daily_mysql_2023-05-26_03h12m_Friday.sql.bz2: md5 = 0c15a6a6bc1954237d8b8abcc3a80f05 OK
2023/05/30 08:32:08 INFO  : daily/mysql/daily_mysql_2023-05-26_03h12m_Friday.sql.bz2: Updated modification time in destination
2023/05/30 08:32:08 DEBUG : daily/mysql/daily_mysql_2023-05-26_03h12m_Friday.sql.bz2: Unchanged skipping
2023/05/30 08:32:08 DEBUG : daily/mysql/daily_mysql_2023-05-27_03h51m_Saturday.sql.bz2: Modification times differ by -1.855750766s: 2023-05-27 03:59:07.855750766 -0400 EDT, 2023-05-27 03:59:06 -0400 EDT
2023/05/30 08:32:08 DEBUG : daily/mysql/daily_mysql_2023-05-27_03h51m_Saturday.sql.bz2: md5 = 825bc6fd126651663096e326338e285a OK
2023/05/30 08:32:08 INFO  : daily/mysql/daily_mysql_2023-05-27_03h51m_Saturday.sql.bz2: Updated modification time in destination
2023/05/30 08:32:08 DEBUG : daily/mysql/daily_mysql_2023-05-27_03h51m_Saturday.sql.bz2: Unchanged skipping
2023/05/30 08:32:08 DEBUG : daily/mysql/daily_mysql_2023-05-28_03h28m_Sunday.sql.bz2: Size and modification time the same (differ by -754.617131ms, within tolerance 1s)
2023/05/30 08:32:08 DEBUG : daily/mysql/daily_mysql_2023-05-28_03h28m_Sunday.sql.bz2: Unchanged skipping
2023/05/30 08:32:08 DEBUG : daily/mysql/daily_mysql_2023-05-29_03h10m_Monday.sql.bz2: Modification times differ by -1.113577342s: 2023-05-29 03:18:33.113577342 -0400 EDT, 2023-05-29 03:18:32 -0400 EDT
2023/05/30 08:32:08 DEBUG : daily/mysql/daily_mysql_2023-05-29_03h10m_Monday.sql.bz2: md5 = fd37434cfe38a9c83366572341ef80e4 OK
2023/05/30 08:32:08 INFO  : daily/mysql/daily_mysql_2023-05-29_03h10m_Monday.sql.bz2: Updated modification time in destination
2023/05/30 08:32:08 DEBUG : daily/mysql/daily_mysql_2023-05-29_03h10m_Monday.sql.bz2: Unchanged skipping
5

You can use --modify-window to adjust the 1s interval rclone is using for checks.

Can you post a log with -vv of the original problem please?

6

Here is the full log file
https://file.io/B34UU2QrlApz

It also has another problem. Exclusion list is like not working.

7

Thanks for the log - that was very helpful.

I think this is a bug to do with wrapping the pcloud in the union.

I've had a go at fixing it here - can you give it a go please

v1.63.0-beta.7056.b8b3e7d47.fix-union-error on branch fix-union-error (uploaded in 15-30 mins)

Probably best to open a new topic about that.

8

I would be happy to try, but I am using FreeBSD package and have no idea how to "side install" a Go program from git.

9 
sudo pkg update && sudo pkg upgrade
sudo pkg install go
sudo pkg install git

git clone -b fix-union-error https://github.com/rclone/rclone.git
cd rclone
go build rclone.go
10

The FreeBSD build failed for reasons unrelated to my fix! I'm trying to work out how to fix that, but in the mean time if you could test using @kapitainsky 's recipe that would be great - thanks.

11

The FreeBSD build is working again

v1.63.0-beta.7057.854a79003.fix-union-error on branch fix-union-error

12

I've got the build. But in mean time I have deleted the problematic file from the remote and it has been successfully resynchronised. I've tried to recreate the situation again (I was copying files inside the backup folders). I well see if it happens again so I can try with the fixed package.

13

I've merged this to master now which means it will be in the latest beta in 15-30 minutes and released in v1.63

14

I was able to reproduce the issue then I've tested the fix branch. I can confirm it works now.