macOS local-to-local copy with --copy-links causes error

What is the problem you are having with rclone?

Consistent failures on macOS (APFS) with copy and --copy-links. Third retry works which is also confusing.

See the log below for more.

This is likely the same (or similar) to what I discuss in this thread though it has a different error so I may be wrong.

Also, tagging @nielash

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

rclone v1.68.0
- os/version: darwin 14.6.1 (64 bit)
- os/kernel: 23.6.0 (arm64)
- os/type: darwin
- os/arch: arm64 (ARMv8 compatible)
- go/version: go1.23.1
- go/linking: dynamic
- go/tags: cmount

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

Local to Local, macOS APFS formatted drive

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

rclone copy src dst -vv --copy-links

Setup:

.
└── src
    β”œβ”€β”€ file.txt
    └── link.txt -> file.txt

Note:

rclone copy src dst -vv --copy-links --local-no-clone

works without retries.

And --metadata has no effect (despite the errors in my other thread. Not sure if it is the same problem or not.

The rclone config contents with secrets removed.

N/A -- local to locl

A log from the command with the -vv flag

2024/09/10 13:13:20 DEBUG : rclone: Version "v1.68.0" starting with parameters ["rclone" "copy" "src" "dst" "-vv" "--copy-links"]
2024/09/10 13:13:20 DEBUG : Creating backend with remote "src"
2024/09/10 13:13:20 DEBUG : Using config file from "/<snip>/rclone.conf"
2024/09/10 13:13:20 DEBUG : local: detected overridden config - adding "{12rtk}" suffix to name
2024/09/10 13:13:20 DEBUG : fs cache: renaming cache item "src" to be canonical "local{12rtk}:/<snip>/src"
2024/09/10 13:13:20 DEBUG : Creating backend with remote "dst"
2024/09/10 13:13:20 DEBUG : local: detected overridden config - adding "{12rtk}" suffix to name
2024/09/10 13:13:20 DEBUG : fs cache: renaming cache item "dst" to be canonical "local{12rtk}:/<snip>/dst"
2024/09/10 13:13:20 DEBUG : file.txt: Need to transfer - File not found at Destination
2024/09/10 13:13:20 DEBUG : link.txt: Need to transfer - File not found at Destination
2024/09/10 13:13:20 DEBUG : Local file system at /<snip>/dst: Waiting for checks to finish
2024/09/10 13:13:20 DEBUG : Local file system at /<snip>/dst: Waiting for transfers to finish
2024/09/10 13:13:20 DEBUG : /<snip>/dst/link.txt.a28710be.partial: isCloned: true, error: <nil>
2024/09/10 13:13:20 DEBUG : link.txt.a28710be.partial: server-side cloned!
2024/09/10 13:13:20 DEBUG : /<snip>/dst/file.txt.a28710be.partial: isCloned: true, error: <nil>
2024/09/10 13:13:20 DEBUG : file.txt.a28710be.partial: server-side cloned!
2024/09/10 13:13:20 ERROR : link.txt: Failed to copy: object not found
2024/09/10 13:13:20 DEBUG : file.txt: md5 = d8e8fca2dc0f896fd7cb4cb0031ba249 OK
2024/09/10 13:13:20 DEBUG : file.txt.a28710be.partial: renamed to: file.txt
2024/09/10 13:13:20 INFO  : file.txt: Copied (server-side copy)
2024/09/10 13:13:20 ERROR : Attempt 1/3 failed with 1 errors and: object not found
2024/09/10 13:13:20 DEBUG : link.txt: Need to transfer - File not found at Destination
2024/09/10 13:13:20 DEBUG : file.txt: Size and modification time the same (differ by 0s, within tolerance 1ns)
2024/09/10 13:13:20 DEBUG : file.txt: Unchanged skipping
2024/09/10 13:13:20 DEBUG : Local file system at /<snip>/dst: Waiting for checks to finish
2024/09/10 13:13:20 DEBUG : Local file system at /<snip>/dst: Waiting for transfers to finish
2024/09/10 13:13:20 DEBUG : /<snip>/dst/link.txt.a28710be.partial: isCloned: false, error: couldn't copy from /<snip>/src/link.txt to /<snip>/dst/link.txt.a28710be.partial: errno -1
2024/09/10 13:13:20 ERROR : link.txt: Failed to copy: couldn't copy from /<snip>/src/link.txt to /<snip>/dst/link.txt.a28710be.partial: errno -1
2024/09/10 13:13:20 INFO  : link.txt.a28710be.partial: Removing failed copy
2024/09/10 13:13:20 ERROR : Attempt 2/3 failed with 1 errors and: couldn't copy from /<snip>/src/link.txt to /<snip>/dst/link.txt.a28710be.partial: errno -1
2024/09/10 13:13:20 DEBUG : link.txt: Need to transfer - File not found at Destination
2024/09/10 13:13:20 DEBUG : file.txt: Size and modification time the same (differ by 0s, within tolerance 1ns)
2024/09/10 13:13:20 DEBUG : file.txt: Unchanged skipping
2024/09/10 13:13:20 DEBUG : Local file system at /<snip>/dst: Waiting for checks to finish
2024/09/10 13:13:20 DEBUG : Local file system at /<snip>/dst: Waiting for transfers to finish
2024/09/10 13:13:20 DEBUG : /<snip>/dst/link.txt.a28710be.partial: isCloned: true, error: <nil>
2024/09/10 13:13:20 DEBUG : link.txt.a28710be.partial: server-side cloned!
2024/09/10 13:13:20 DEBUG : link.txt: md5 = d8e8fca2dc0f896fd7cb4cb0031ba249 OK
2024/09/10 13:13:20 DEBUG : link.txt.a28710be.partial: renamed to: link.txt
2024/09/10 13:13:20 INFO  : link.txt: Copied (server-side copy)
2024/09/10 13:13:20 ERROR : Attempt 3/3 succeeded
2024/09/10 13:13:20 INFO  : 
Transferred:   	         10 B / 10 B, 100%, 0 B/s, ETA -
Checks:                 2 / 2, 100%
Transferred:            2 / 2, 100%
Server Side Copies:     2 @ 10 B
Elapsed time:         0.0s

2024/09/10 13:13:20 DEBUG : 6 go routines active

Hmm, so far I am not able to reproduce this... but I am still on 14.5. I can try updating (been meaning to anyway) and see if that makes any difference.

Is your link.txt just a normal symlink like created with ln -s? Anything special about it?

It is literally just ln -s. Nothing else special.

The ones in the test from the other thread were Python os.symlink but similarly β€œvanilla”

I can replicate it. Exactly the same - 2 attempts ERROR and then Attempt 3/3 succeeded. Link is nothing fancy - regular ln -s

$ rclone --version
rclone v1.68.0
- os/version: darwin 14.6.1 (64 bit)
- os/kernel: 23.6.0 (x86_64)
- os/type: darwin
- os/arch: amd64
- go/version: go1.23.1
- go/linking: dynamic
- go/tags: cmount

$ tree src
src
β”œβ”€β”€ file.txt
└── link.txt -> file.txt

1 directory, 2 files

$ rclone copy src dst -vv --copy-links
2024/09/11 18:10:04 DEBUG : rclone: Version "v1.68.0" starting with parameters ["rclone" "copy" "src" "dst" "-vv" "--copy-links"]
2024/09/11 18:10:04 DEBUG : Creating backend with remote "src"
2024/09/11 18:10:04 DEBUG : Using config file from "/Users/kptsky/.config/rclone/rclone.conf"
2024/09/11 18:10:04 DEBUG : local: detected overridden config - adding "{12rtk}" suffix to name
2024/09/11 18:10:04 DEBUG : fs cache: renaming cache item "src" to be canonical "local{12rtk}:/Users/kptsky/Temp/test/test/src"
2024/09/11 18:10:04 DEBUG : Creating backend with remote "dst"
2024/09/11 18:10:04 DEBUG : local: detected overridden config - adding "{12rtk}" suffix to name
2024/09/11 18:10:04 DEBUG : fs cache: renaming cache item "dst" to be canonical "local{12rtk}:/Users/kptsky/Temp/test/test/dst"
2024/09/11 18:10:04 DEBUG : file.txt: Need to transfer - File not found at Destination
2024/09/11 18:10:04 DEBUG : link.txt: Need to transfer - File not found at Destination
2024/09/11 18:10:04 DEBUG : Local file system at /Users/kptsky/Temp/test/test/dst: Waiting for checks to finish
2024/09/11 18:10:04 DEBUG : Local file system at /Users/kptsky/Temp/test/test/dst: Waiting for transfers to finish
2024/09/11 18:10:04 DEBUG : /Users/kptsky/Temp/test/test/dst/link.txt.e66b5a62.partial: isCloned: true, error: <nil>
2024/09/11 18:10:04 DEBUG : link.txt.e66b5a62.partial: server-side cloned!
2024/09/11 18:10:04 ERROR : link.txt: Failed to copy: object not found
2024/09/11 18:10:04 DEBUG : /Users/kptsky/Temp/test/test/dst/file.txt.e66b5a62.partial: isCloned: true, error: <nil>
2024/09/11 18:10:04 DEBUG : file.txt.e66b5a62.partial: server-side cloned!
2024/09/11 18:10:04 DEBUG : file.txt: md5 = fe9dee1f3a0c22dfff0aec9838f7e70e OK
2024/09/11 18:10:04 DEBUG : file.txt.e66b5a62.partial: renamed to: file.txt
2024/09/11 18:10:04 INFO  : file.txt: Copied (server-side copy)
2024/09/11 18:10:04 ERROR : Attempt 1/3 failed with 1 errors and: object not found
2024/09/11 18:10:04 DEBUG : link.txt: Need to transfer - File not found at Destination
2024/09/11 18:10:04 DEBUG : Local file system at /Users/kptsky/Temp/test/test/dst: Waiting for checks to finish
2024/09/11 18:10:04 DEBUG : file.txt: Size and modification time the same (differ by 0s, within tolerance 1ns)
2024/09/11 18:10:04 DEBUG : file.txt: Unchanged skipping
2024/09/11 18:10:04 DEBUG : Local file system at /Users/kptsky/Temp/test/test/dst: Waiting for transfers to finish
2024/09/11 18:10:04 DEBUG : /Users/kptsky/Temp/test/test/dst/link.txt.e66b5a62.partial: isCloned: false, error: couldn't copy from /Users/kptsky/Temp/test/test/src/link.txt to /Users/kptsky/Temp/test/test/dst/link.txt.e66b5a62.partial: errno -1
2024/09/11 18:10:04 ERROR : link.txt: Failed to copy: couldn't copy from /Users/kptsky/Temp/test/test/src/link.txt to /Users/kptsky/Temp/test/test/dst/link.txt.e66b5a62.partial: errno -1
2024/09/11 18:10:04 INFO  : link.txt.e66b5a62.partial: Removing failed copy
2024/09/11 18:10:04 ERROR : Attempt 2/3 failed with 1 errors and: couldn't copy from /Users/kptsky/Temp/test/test/src/link.txt to /Users/kptsky/Temp/test/test/dst/link.txt.e66b5a62.partial: errno -1
2024/09/11 18:10:04 DEBUG : link.txt: Need to transfer - File not found at Destination
2024/09/11 18:10:04 DEBUG : Local file system at /Users/kptsky/Temp/test/test/dst: Waiting for checks to finish
2024/09/11 18:10:04 DEBUG : file.txt: Size and modification time the same (differ by 0s, within tolerance 1ns)
2024/09/11 18:10:04 DEBUG : file.txt: Unchanged skipping
2024/09/11 18:10:04 DEBUG : Local file system at /Users/kptsky/Temp/test/test/dst: Waiting for transfers to finish
2024/09/11 18:10:04 DEBUG : /Users/kptsky/Temp/test/test/dst/link.txt.e66b5a62.partial: isCloned: true, error: <nil>
2024/09/11 18:10:04 DEBUG : link.txt.e66b5a62.partial: server-side cloned!
2024/09/11 18:10:04 DEBUG : link.txt: md5 = fe9dee1f3a0c22dfff0aec9838f7e70e OK
2024/09/11 18:10:04 DEBUG : link.txt.e66b5a62.partial: renamed to: link.txt
2024/09/11 18:10:04 INFO  : link.txt: Copied (server-side copy)
2024/09/11 18:10:04 ERROR : Attempt 3/3 succeeded
2024/09/11 18:10:04 INFO  :
Transferred:   	         12 B / 12 B, 100%, 0 B/s, ETA -
Checks:                 2 / 2, 100%
Transferred:            2 / 2, 100%
Server Side Copies:     2 @ 12 B
Elapsed time:         0.0s

Thank you both! I think I have figured out how to reliably reproduce it now. I think there are actually two different bugs:

  1. --copy-links is erroneously behaving like --links, unless --local-no-clone is used.

In other words, the dst ends up with a link instead of a regular file. (Can you confirm whether you are seeing this too?)

  1. Creating a link to a relative path in the dst fails if the file it's pointing to doesn't exist yet.

I think I wasn't seeing this at first because I tried with an absolute path instead of relative.

I was also confused at first because whether a link is created before its target is subject to the whims of concurrency and ordering. So, in the above example where file comes before link alphabetically, I found that to make it deterministically fail I had to add:

--check-first --order-by name,desc --transfers 1

and to make it deterministically succeed I had to change desc to asc.

This would also explain why it fails but then succeeds on retry (which also confused me.)

Now that I think I know why it's happening I think I should be able to fix it. One thing I guess I'm not sure about is how we normally handle the scenario where we want to create a relative link in the dest to another dest file that doesn't exist yet -- I guess we probably just don't check whether it exists, and create it regardless?

Does that all generally sound right to you?

Thanks for all of the hard work! I am glad you were able to reproduce it. Honestly, I am still not 100% this is the bug I am hitting in my 3rd party tool but it's a bug either way.

Would you like me to put it on github?

I am not sure what the current practice is, but I would say that by Principle of Least Surprise, it should copy whether or not it's a broken link. Same thing with --links and .rclonelink files. It should happen regardless

1 Like

This fixes it for me. Are either of you able to test and confirm?

The same copy as before works now immediately.

$ git rev-parse --short HEAD
736c31803

$ ./rclone copy src dst -vv --copy-links
2024/09/16 16:52:47 DEBUG : rclone: Version "v1.69.0-DEV" starting with parameters ["/Volumes/DBSamsung-SSD-500-Temp/github-nielash-rclone/rclone" "copy" "src" "dst" "-vv" "--copy-links"]
2024/09/16 16:52:47 DEBUG : Creating backend with remote "src"
2024/09/16 16:52:47 DEBUG : Using config file from "/Users/kptsky/.config/rclone/rclone.conf"
2024/09/16 16:52:47 DEBUG : local: detected overridden config - adding "{12rtk}" suffix to name
2024/09/16 16:52:47 DEBUG : fs cache: renaming cache item "src" to be canonical "local{12rtk}:/Users/kptsky/Temp/test/test/src"
2024/09/16 16:52:47 DEBUG : Creating backend with remote "dst"
2024/09/16 16:52:47 DEBUG : local: detected overridden config - adding "{12rtk}" suffix to name
2024/09/16 16:52:47 DEBUG : fs cache: renaming cache item "dst" to be canonical "local{12rtk}:/Users/kptsky/Temp/test/test/dst"
2024/09/16 16:52:47 DEBUG : file.txt: Need to transfer - File not found at Destination
2024/09/16 16:52:47 DEBUG : link.txt: Need to transfer - File not found at Destination
2024/09/16 16:52:47 DEBUG : Local file system at /Users/kptsky/Temp/test/test/dst: Waiting for checks to finish
2024/09/16 16:52:47 DEBUG : Local file system at /Users/kptsky/Temp/test/test/dst: Waiting for transfers to finish
2024/09/16 16:52:47 DEBUG : /Users/kptsky/Temp/test/test/dst/file.txt.e66b5a62.partial: isCloned: false, error: <nil>
2024/09/16 16:52:47 DEBUG : file.txt.e66b5a62.partial: server-side cloned!
2024/09/16 16:52:47 DEBUG : /Users/kptsky/Temp/test/test/dst/link.txt.e66b5a62.partial: isCloned: false, error: <nil>
2024/09/16 16:52:47 DEBUG : link.txt.e66b5a62.partial: server-side cloned!
2024/09/16 16:52:47 DEBUG : file.txt: md5 = fe9dee1f3a0c22dfff0aec9838f7e70e OK
2024/09/16 16:52:47 DEBUG : link.txt: md5 = fe9dee1f3a0c22dfff0aec9838f7e70e OK
2024/09/16 16:52:47 DEBUG : file.txt.e66b5a62.partial: renamed to: file.txt
2024/09/16 16:52:47 INFO  : file.txt: Copied (server-side copy)
2024/09/16 16:52:47 DEBUG : link.txt.e66b5a62.partial: renamed to: link.txt
2024/09/16 16:52:47 INFO  : link.txt: Copied (server-side copy)
2024/09/16 16:52:47 INFO  :
Transferred:   	         12 B / 12 B, 100%, 0 B/s, ETA -
Transferred:            2 / 2, 100%
Server Side Copies:     2 @ 12 B
Elapsed time:         0.0s

2024/09/16 16:52:47 DEBUG : 6 go routines active

$ ll src/
total 8
-rw-r--r--@ 1 kptsky  staff     6B Sep 11 18:08 file.txt
lrwxr-xr-x@ 1 kptsky  staff     8B Sep 11 18:08 link.txt -> file.txt

$ ll dst/
total 16
-rw-r--r--@ 1 kptsky  staff     6B Sep 11 18:08 file.txt
-rw-r--r--@ 1 kptsky  staff     6B Sep 11 18:08 link.txt
1 Like

Is there a link to an executable or a build? I didn't see it on https://beta.rclone.org/. (and I don't have Go installed on this computer).

If not, I will test later this week when I can build it at home. Either way, thanks for looking at this. I am hoping it also addresses the issue in my 3rd party tool.

I have now added one here:
Executable: https://beta.rclone.org/branch/fix-macos-links/v1.69.0-beta.8308.b336dac90.fix-macos-links/
Source: GitHub - rclone/rclone at fix-macos-links

I also made a couple of improvements over the version @kapitainsky tried earlier, as I realized that in that version, while the bug was fixed, it was only copying rather than cloning. This version should fix that.

I hope so too! Let me know if you have a chance to try it out.

It's working!

Thank you so much

(If you got email notifications that it didn't work, I have since deleted those replies. I had messed up hard-coding the path to the beta in my test code)

1 Like

Glad to hear it! Thanks for testing, and also for reporting it in the first place!

I have opened a PR:

1 Like

This topic was automatically closed 3 days after the last reply. New replies are no longer allowed.