Rclone mount of BOX remote does not show same items as rclone lsd of remote

Suspected Bug
1

What is the problem you are having with rclone?

ls of an rclone_mount of a BOX remote only shows 1 directory. rclone lsd of the same remote shows 4 directories (as expected).

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

rclone --version
rclone v1.64.0
- os/version: centos 7.9.2009 (64 bit)
- os/kernel: 3.10.0-1160.36.2.el7.x86_64 (x86_64)
- os/type: linux
- os/arch: amd64
- go/version: go1.21.1
- go/linking: static
- go/tags: none

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

BOX

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

rclone mount of BOX remote A: -- shows only directory 000041

/work/rclone/bin/rclone mount --allow-other --attr-timeout=5m --buffer-size=0 --cache-dir=/work/rclone/a_moun/cache --config=/work/rclone/bin/test.conf --dir-cache-time=10m --log-file=/work/rclone/a_mount/rclone_mount.log --log-level=DEBUG --rc --rc-addr=127.0.0.1:5603 --read-only --transfers=12 --vfs-cache-max-age=1h --vfs-cache-mode=full --vfs-cache-poll-interval=10m --vfs-read-chunk-size=16M --vfs-read-chunk-size-limit=0 A: /work/rclone/a_mount/rclone_mount

ls -l /work/rclone/a_mount/rclone_mount/BCA_LOAD1/nightly_clone/TEST/TEST.CommEngine_Dev_Custbuild/2023/202310-October/202310-October-14/
total 0
drwxr-xr-x 1 eb888198 eb888198 0 Oct 14 11:54 000041

rclone lsd of the same remote -- shows directories 000041..000044

/work/rclone/bin/rclone -vv --config /work/rclone/bin/test.conf lsd A:BCA_LOAD1/nightly_clone/TEST/TEST.CommEngine_Dev_Custbuild/2023/202310-October/202310-October-14
2023/10/17 13:22:01 DEBUG : rclone: Version "v1.64.0" starting with parameters ["/work/rclone/bin/rclone" "-vv" "--config" "/work/rclone/bin/test.conf" "lsd" "A:BCA_LOAD1/nightly_clone/TEST/TEST.CommEngine_Dev_Custbuild/2023/202310-October/202310-October-14"]
2023/10/17 13:22:01 DEBUG : Creating backend with remote "A:BCA_LOAD1/nightly_clone/TEST/TEST.CommEngine_Dev_Custbuild/2023/202310-October/202310-October-14"
2023/10/17 13:22:01 DEBUG : Using config file from "/work/rclone/bin/test.conf"
          -1 2023-10-14 11:55:27        -1 000041
          -1 2023-10-14 16:57:36        -1 000042
          -1 2023-10-14 21:27:32        -1 000043
          -1 2023-10-15 01:46:09        -1 000044
2023/10/17 13:22:03 DEBUG : 6 go routines active

The rclone config contents with secrets removed.

[A]
type = box
token =

[B]
type = box
token =

[C]
type = box
token =

[ABC]
type = union
upstreams = A:BCA_LOAD1 B:BCA_CIBUILDS C:BCA_Daemon

A log from the command with the -vv flag

Log from rclone mount. The output for -vv with rclone lsd is above with the command output

2023/10/17 13:19:48 DEBUG : rclone: Version "v1.64.0" starting with parameters ["/work/rclone/bin/rclone" "mount" "--allow-other" "--attr-timeout=5m" "--buffer-size=0" "--cache-dir=/work/rclone/a_mount/cache" "--config=/work/rclone/bin/test.conf" "--dir-cache-time=10m" "--log-file=/work/rclone/a_mount/rclone_mount.log" "--log-level=DEBUG" "--rc" "--rc-addr=127.0.0.1:5603" "--read-only" "--transfers=12" "--vfs-cache-max-age=1h" "--vfs-cache-mode=full" "--vfs-cache-poll-interval=10m" "--vfs-read-chunk-size=16M" "--vfs-read-chunk-size-limit=0" "A:" "/work/rclone/a_mount/rclone_mount"]
2023/10/17 13:19:48 NOTICE: Serving remote control on http://127.0.0.1:5603/
2023/10/17 13:19:48 DEBUG : Creating backend with remote "A:"
2023/10/17 13:19:48 DEBUG : Using config file from "/work/rclone/bin/test.conf"
2023/10/17 13:19:48 DEBUG : vfs cache: root is "/work/rclone/a_mount/cache"
2023/10/17 13:19:48 DEBUG : vfs cache: data root is "/work/rclone/a_mount/cache/vfs/A"
2023/10/17 13:19:48 DEBUG : vfs cache: metadata root is "/work/rclone/a_mount/cache/vfsMeta/A"
2023/10/17 13:19:48 DEBUG : Creating backend with remote "/work/rclone/a_mount/cache/vfs/A/"
2023/10/17 13:19:48 DEBUG : fs cache: renaming cache item "/work/rclone/a_mount/cache/vfs/A/" to be canonical "/work/rclone/a_mount/cache/vfs/A"
2023/10/17 13:19:48 DEBUG : Creating backend with remote "/work/rclone/a_mount/cache/vfsMeta/A/"
2023/10/17 13:19:48 DEBUG : fs cache: renaming cache item "/work/rclone/a_mount/cache/vfsMeta/A/" to be canonical "/work/rclone/a_mount/cache/vfsMeta/A"
2023/10/17 13:19:48 INFO  : vfs cache: cleaned: objects 0 (was 0) in use 0, to upload 0, uploading 0, total size 0 (was 0)
2023/10/17 13:19:48 DEBUG : box root '': Mounting on "/work/rclone/a_mount/rclone_mount"
2023/10/17 13:19:48 DEBUG : : Root:
2023/10/17 13:19:48 DEBUG : : >Root: node=/, err=<nil>
2023/10/17 13:20:29 DEBUG : /: Lookup: name="BCA_LOAD1"
2023/10/17 13:20:29 DEBUG : /: >Lookup: node=BCA_LOAD1/, err=<nil>
2023/10/17 13:20:29 DEBUG : BCA_LOAD1/: Attr:
2023/10/17 13:20:29 DEBUG : BCA_LOAD1/: >Attr: attr=valid=5m0s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2023/10/17 13:20:29 DEBUG : BCA_LOAD1/: Lookup: name="nightly_clone"
2023/10/17 13:20:30 DEBUG : BCA_LOAD1/: >Lookup: node=BCA_LOAD1/nightly_clone/, err=<nil>
2023/10/17 13:20:30 DEBUG : BCA_LOAD1/nightly_clone/: Attr:
2023/10/17 13:20:30 DEBUG : BCA_LOAD1/nightly_clone/: >Attr: attr=valid=5m0s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2023/10/17 13:20:30 DEBUG : BCA_LOAD1/nightly_clone/: Lookup: name="TEST"
2023/10/17 13:20:30 DEBUG : BCA_LOAD1/nightly_clone/: >Lookup: node=BCA_LOAD1/nightly_clone/TEST/, err=<nil>
2023/10/17 13:20:30 DEBUG : BCA_LOAD1/nightly_clone/TEST/: Attr:
2023/10/17 13:20:30 DEBUG : BCA_LOAD1/nightly_clone/TEST/: >Attr: attr=valid=5m0s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2023/10/17 13:20:30 DEBUG : BCA_LOAD1/nightly_clone/TEST/: Lookup: name="TEST.CommEngine_Dev_Custbuild"
2023/10/17 13:20:30 DEBUG : BCA_LOAD1/nightly_clone/TEST/: >Lookup: node=BCA_LOAD1/nightly_clone/TEST/TEST.CommEngine_Dev_Custbuild/, err=<nil>
2023/10/17 13:20:30 DEBUG : BCA_LOAD1/nightly_clone/TEST/TEST.CommEngine_Dev_Custbuild/: Attr:
2023/10/17 13:20:30 DEBUG : BCA_LOAD1/nightly_clone/TEST/TEST.CommEngine_Dev_Custbuild/: >Attr: attr=valid=5m0s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2023/10/17 13:20:30 DEBUG : BCA_LOAD1/nightly_clone/TEST/TEST.CommEngine_Dev_Custbuild/: Lookup: name="2023"
2023/10/17 13:20:31 DEBUG : BCA_LOAD1/nightly_clone/TEST/TEST.CommEngine_Dev_Custbuild/: >Lookup: node=BCA_LOAD1/nightly_clone/TEST/TEST.CommEngine_Dev_Custbuild/2023/, err=<nil>
2023/10/17 13:20:31 DEBUG : BCA_LOAD1/nightly_clone/TEST/TEST.CommEngine_Dev_Custbuild/2023/: Attr:
2023/10/17 13:20:31 DEBUG : BCA_LOAD1/nightly_clone/TEST/TEST.CommEngine_Dev_Custbuild/2023/: >Attr: attr=valid=5m0s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2023/10/17 13:20:31 DEBUG : BCA_LOAD1/nightly_clone/TEST/TEST.CommEngine_Dev_Custbuild/2023/: Lookup: name="202310-October"
2023/10/17 13:20:31 DEBUG : BCA_LOAD1/nightly_clone/TEST/TEST.CommEngine_Dev_Custbuild/2023/: >Lookup: node=BCA_LOAD1/nightly_clone/TEST/TEST.CommEngine_Dev_Custbuild/2023/202310-October/, err=<nil>
2023/10/17 13:20:31 DEBUG : BCA_LOAD1/nightly_clone/TEST/TEST.CommEngine_Dev_Custbuild/2023/202310-October/: Attr:
2023/10/17 13:20:31 DEBUG : BCA_LOAD1/nightly_clone/TEST/TEST.CommEngine_Dev_Custbuild/2023/202310-October/: >Attr: attr=valid=5m0s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2023/10/17 13:20:31 DEBUG : BCA_LOAD1/nightly_clone/TEST/TEST.CommEngine_Dev_Custbuild/2023/202310-October/: Lookup: name="202310-October-14"
2023/10/17 13:20:31 DEBUG : BCA_LOAD1/nightly_clone/TEST/TEST.CommEngine_Dev_Custbuild/2023/202310-October/: >Attr: attr=valid=5m0s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2023/10/17 13:20:31 DEBUG : BCA_LOAD1/nightly_clone/TEST/TEST.CommEngine_Dev_Custbuild/2023/202310-October/: Lookup: name="202310-October-14"
2023/10/17 13:20:31 DEBUG : BCA_LOAD1/nightly_clone/TEST/TEST.CommEngine_Dev_Custbuild/2023/202310-October/: >Lookup: node=BCA_LOAD1/nightly_clone/TEST/TEST.CommEngine_Dev_Custbuild/2023/202310-October/202310-October-14/, err=<nil>
2023/10/17 13:20:31 DEBUG : BCA_LOAD1/nightly_clone/TEST/TEST.CommEngine_Dev_Custbuild/2023/202310-October/202310-October-14/: Attr:
2023/10/17 13:20:31 DEBUG : BCA_LOAD1/nightly_clone/TEST/TEST.CommEngine_Dev_Custbuild/2023/202310-October/202310-October-14/: >Attr: attr=valid=5m0s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2023/10/17 13:20:31 DEBUG : BCA_LOAD1/nightly_clone/TEST/TEST.CommEngine_Dev_Custbuild/2023/202310-October/202310-October-14/: ReadDirAll:
2023/10/17 13:20:32 DEBUG : BCA_LOAD1/nightly_clone/TEST/TEST.CommEngine_Dev_Custbuild/2023/202310-October/202310-October-14/: >ReadDirAll: item=3, err=<nil>
2023/10/17 13:20:32 DEBUG : BCA_LOAD1/nightly_clone/TEST/TEST.CommEngine_Dev_Custbuild/2023/202310-October/202310-October-14/: Lookup: name="000041"
2023/10/17 13:20:32 DEBUG : BCA_LOAD1/nightly_clone/TEST/TEST.CommEngine_Dev_Custbuild/2023/202310-October/202310-October-14/: >Lookup: node=BCA_LOAD1/nightly_clone/TEST/TEST.CommEngine_Dev_Custbuild/2023/202310-October/202310-October-14/000041/, err=<nil>
2023/10/17 13:20:32 DEBUG : BCA_LOAD1/nightly_clone/TEST/TEST.CommEngine_Dev_Custbuild/2023/202310-October/202310-October-14/000041/: Attr:
2023/10/17 13:20:32 DEBUG : BCA_LOAD1/nightly_clone/TEST/TEST.CommEngine_Dev_Custbuild/2023/202310-October/202310-October-14/000041/: >Attr: attr=valid=5m0s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2023/10/17 13:20:48 DEBUG : box root '': Checking for changes on remote (next_stream_position: "30400995058739235")
2023/10/17 13:20:48 DEBUG : box root '': Received 290 events, resulting in 0 paths and 0 notifications
2023/10/17 13:20:48 DEBUG : box root '': Checking for changes on remote (next_stream_position: "30400995058795401")
2023/10/17 13:21:48 DEBUG : box root '': Checking for changes on remote (next_stream_position: "30400995058795648")
2023/10/17 13:21:48 DEBUG : box root '': Received 211 events, resulting in 0 paths and 0 notifications
2023/10/17 13:21:48 DEBUG : box root '': Checking for changes on remote (next_stream_position: "30400995058855424")
2023/10/17 13:22:48 DEBUG : box root '': Checking for changes on remote (next_stream_position: "30400995058855684")
2023/10/17 13:22:48 DEBUG : box root '': Received 109 events, resulting in 0 paths and 0 notifications
2023/10/17 13:22:48 DEBUG : box root '': Checking for changes on remote (next_stream_position: "30400995058915432")
2023/10/17 13:22:48 DEBUG : box root '': Received 13 events, resulting in 0 paths and 0 notifications
2023/10/17 13:22:48 DEBUG : box root '': Checking for changes on remote (next_stream_position: "30400995058915619")
2023/10/17 13:22:48 DEBUG : box root '': Received 15 events, resulting in 0 paths and 0 notifications
2023/10/17 13:22:48 DEBUG : box root '': Checking for changes on remote (next_stream_position: "30400995058915800")
2023/10/17 13:23:48 DEBUG : box root '': Checking for changes on remote (next_stream_position: "30400995058915976")
2023/10/17 13:23:48 DEBUG : box root '': Received 244 events, resulting in 0 paths and 0 notifications
2023/10/17 13:23:48 DEBUG : box root '': Checking for changes on remote (next_stream_position: "30400995058975411")
2023/10/17 13:24:48 DEBUG : box root '': Checking for changes on remote (next_stream_position: "30400995058975649")
2023/10/17 13:24:48 DEBUG : box root '': Received 220 events, resulting in 0 paths and 0 notifications
2023/10/17 13:24:48 DEBUG : box root '': Checking for changes on remote (next_stream_position: "30400995059035398")
2023/10/17 13:24:48 DEBUG : box root '': Received 13 events, resulting in 0 paths and 0 notifications
2023/10/17 13:24:48 DEBUG : box root '': Checking for changes on remote (next_stream_position: "30400995059035609")
2023/10/17 13:25:02 DEBUG : /: Attr:
2023/10/17 13:25:02 DEBUG : /: >Attr: attr=valid=5m0s ino=0 size=0 mode=drwxr-xr-x, err=<nil>
2023/10/17 13:25:04 DEBUG : /: ReadDirAll:
2023/10/17 13:25:04 DEBUG : /: >ReadDirAll: item=7, err=<nil>
2

The item there says there are 3 items in the list for the directory, which is the 1 being returned the "." and ".." for the other 2.

Are those files uploaded via some other process?

Why did you make that 5 minutes?

3

They are uploaded with rclone to BOX but on other systems using a different configuration file and remotes.

We were experiencing problems with 'rate limit exceeded' due to too many calls to BOX API. This was an attempt to reduce the calls to BOX.

The directories were created several days ago -- why would this timeout affect what shows up in the listing?

4

Ooof - That's a great way to lose data :frowning: If you have multiple remotes doing things, you have a very high chance of corruption.

rclone mount

For that specific issue we've got logs for, when were the files uploaded? The log from the debug shows it asked box and box said only 3 items.

5

I am not following how corruption would occur. Yes, we have multiple processes uploading to BOX using rclone copy. Each process is uploading to a unique directory on BOX.

The rclone mount is read-only and is only used for retrieving from BOX. It is never used to upload to BOX.

I restarted the rclone mount and removed 'attr-timeout=5m' but I still see the same behavior. It seems odd since we are now 3 days past when the data was uploaded to BOX.

The directory timestamps indicate when the data was uploaded to BOX. It was on 2023-10-14 to 2023-10-15 between 11:55 and 01:46

2023/10/17 13:22:01 DEBUG : Using config file from "/work/rclone/bin/test.conf"
          -1 2023-10-14 11:55:27        -1 000041
          -1 2023-10-14 16:57:36        -1 000042
          -1 2023-10-14 21:27:32        -1 000043
          -1 2023-10-15 01:46:09        -1 000044
2023/10/17 13:22:03 DEBUG : 6 go routines active

It may be that this is a BOX problem because I see something similar if I visit the location in a web browser.
I see two entries for the year '2023' in the same folder. One of the '2023' folders contains only the 000041 directory and the other contains the four directories 000041..000044

I am not sure why there are duplicate entries in the BOX folder in a web browser.

6

I'm not 100% familiar with your flow. If you have two mounts, file.txt is modified on A at 00:01 and B had that file in cache, it would not notice the change until 5 minutes. If you modify it in that time, B has the old file, changes it and uploads and anything A was done is lost since the attributes are being cached for 5 minutes so the B doesn't know A changed it as it's cached.

With read only, I'd think no corruption occurs since it's just reading but the problem gets a bit worse. You read a file at 00:01 and upload it at 00:02, the mount doesn't know the file changed since it's cached for 5 minutes and that would could cause some issues. Not sure all the exact edge cases as I never touch that flag :slight_smile:

Hmm. I figured that was what you were going to say. The only thing I can see in the log is BOX is returning 3, which makes me agree with you that the API is giving you bad details back. What's super odd is that at the same time, rclone lsd gives you the right answer back, correct?

That's the flow that doesn't make sense to me. Maybe someone else sees something.

rclone ls remote: gives 4 directories
rclone mount running an ls only sees 1 directory.

7

I am coming to the opinion that something weird is happening on BOX and we need to open a case with them.
I see a folder that contains two '2023' folders, each with a different BOX ID. I see all 000041..000044 directories if I follow the first 2023 folder. I see only the 000041 directory if I follow the second 2023 folder.

My guess is that for some reason 'rclone lsd' is getting the first '2023' folder and 'rclone mount' is getting the second '2023' folder.

I don't want to mark this topic as closed yet but it should be put on hold as an rclone problem.

8

That might be it as Box (from what I read) doesn't allow duplicates, but seems it does?

I know from Google, you'd get duplicate in source messages.

9

Theoretically, it shouldn't happen. They aren't duplicates because they have different BOX IDs but you usually can't create two items in a folder with the same name. I get an error if I try to do that through the BOX python SDK. Somehow duplicate name entries were created, but with different IDs. BOX cares about IDs, not names.

10

Ah, ok.

I wasn't sure on that as I know on Google, I never had a duplicate made ever, but others did.

11

There is similar thread opened few days ago:

Unfortunately not much solid data from there but two people noticing similar behaviour (with two different remotes) make me worry a bit.

@emboehm - would you mind to try previous version of rclone? v1.63? or v1.62?

12

We saw this same behavior with v1.60.0.

I renamed the duplicate folders. The rclone mount now sees the correct number of folders.

I don't see the need to try additional versions. There are several versions between v1.60.0 and v1.64.0. I see we are now up to v1.64.2

I think this occurred due to some sort of race condition on BOX when uploading the data with rsync copy that resulted in two folders with the same name but different BOX IDs

Here's json data to show what I am talking about:

{"Path":"TEST.CommEngine_Dev_Custbuild/2023.delete_me/202310-October/202310-October-14.2.delete_me/000041","Name":"000041","Size":-1,"MimeType":"inode/directory","ModTime":"2023-10-14T11:54:37-07:00","IsDir":true,"ID":"230727577505"},
{"Path":"TEST.CommEngine_Dev_Custbuild/2023.delete_me/202310-October/202310-October-14.1.delete_me/000041","Name":"000041","Size":-1,"MimeType":"inode/directory","ModTime":"2023-10-14T11:54:38-07:00","IsDir":true,"ID":"230725448751"},
{"Path":"TEST.CommEngine_Dev_Custbuild/2023/202310-October/202310-October-14/000041","Name":"000041","Size":-1,"MimeType":"inode/directory","ModTime":"2023-10-14T11:55:27-07:00","IsDir":true,"ID":"230726115965"},

You can observe that all these '000041' directories have different IDs. The first two also demonstrate a duplicate 2023 directory and duplicate 202310-October-14 directories.

I am not sure why 'rclone lsd' found the data and 'rclone mount' didn't but I don't see it as a bug in rclone.

1 Like
13

Thank you for investigating it further. It indeed points into duplicates issues - which is ok (at least from rclone perspective)

14

To the moderators:

Should I move this topic from Suspected Bug to Help and Support?

15

Nah - It's fine.

I can show an example from GD which allows duplicates.

lsd just returns normal as it doesn't care about duplicates.

[felix@gemini ~]$ rclone lsd GD:
          -1 2023-01-20 11:23:52        -1 Dupes
          -1 2023-03-07 17:15:49        -1 TestCopy
          -1 2023-10-19 09:04:27        -1 blah
          -1 2022-12-13 14:36:36        -1 blah
          -1 2022-06-30 15:11:37        -1 crypt
          -1 2022-10-13 10:24:21        -1 linkdir
          -1 2022-10-13 10:24:21        -1 test2
          -1 2022-10-13 10:24:26        -1 test3
          -1 2023-01-30 11:02:00        -1 testshare

So I get 2 'blah's in there.

The mount though will only show one.

[felix@gemini ~]$ cd test
[felix@gemini test]$ ls
2GB.bin  blah  blah.txt  crypt  Dupes  hosts  Joeisms.docx  linkdir  RootTestDoc.docx  test  test2  test3  TestCopy  testshare

While there are actually two there. My count should 16+2 items as I have 16 directory/files with the dupe, plus "." and ".." but I only get 17 back meaning the duplicate directory gets dropped.

[felix@gemini ~]$ rclone mount GD: /home/felix/test -vv
2023/10/19 09:05:05 DEBUG : Setting --config "/opt/rclone/rclone.conf" from environment variable RCLONE_CONFIG="/opt/rclone/rclone.conf"
2023/10/19 09:05:05 DEBUG : rclone: Version "v1.64.2-DEV" starting with parameters ["rclone" "mount" "GD:" "/home/felix/test" "-vv"]
2023/10/19 09:05:05 DEBUG : Creating backend with remote "GD:"
2023/10/19 09:05:05 DEBUG : Using config file from "/opt/rclone/rclone.conf"
2023/10/19 09:05:05 DEBUG : Google drive root '': Mounting on "/home/felix/test"
2023/10/19 09:05:05 DEBUG : : Root:
2023/10/19 09:05:05 DEBUG : : >Root: node=/, err=<nil>
2023/10/19 09:05:09 DEBUG : /: Attr:
2023/10/19 09:05:09 DEBUG : /: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2023/10/19 09:05:10 DEBUG : /: ReadDirAll:
2023/10/19 09:05:10 DEBUG : /: >ReadDirAll: item=17, err=<nil>
2023/10/19 09:05:10 DEBUG : /: Lookup: name="2GB.bin"
2023/10/19 09:05:10 DEBUG : /: >Lookup: node=2GB.bin, err=<nil>
2023/10/19 09:05:10 DEBUG : 2GB.bin: Attr:
2023/10/19 09:05:10 DEBUG : 2GB.bin: >Attr: a=valid=1s ino=0 size=2000000000 mode=-rw-rw-r--, err=<nil>
2023/10/19 09:05:10 DEBUG : /: Lookup: name="Dupes"
2023/10/19 09:05:10 DEBUG : /: >Lookup: node=Dupes/, err=<nil>
2023/10/19 09:05:10 DEBUG : Dupes/: Attr:
2023/10/19 09:05:10 DEBUG : Dupes/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2023/10/19 09:05:10 DEBUG : /: Lookup: name="Joeisms.docx"
2023/10/19 09:05:10 DEBUG : /: >Lookup: node=Joeisms.docx, err=<nil>
2023/10/19 09:05:10 DEBUG : Joeisms.docx: Attr:
2023/10/19 09:05:10 DEBUG : Joeisms.docx: >Attr: a=valid=1s ino=0 size=0 mode=-rw-rw-r--, err=<nil>
2023/10/19 09:05:10 DEBUG : /: Lookup: name="RootTestDoc.docx"
2023/10/19 09:05:10 DEBUG : /: >Lookup: node=RootTestDoc.docx, err=<nil>
2023/10/19 09:05:10 DEBUG : RootTestDoc.docx: Attr:
2023/10/19 09:05:10 DEBUG : RootTestDoc.docx: >Attr: a=valid=1s ino=0 size=0 mode=-rw-rw-r--, err=<nil>
2023/10/19 09:05:10 DEBUG : /: Lookup: name="TestCopy"
2023/10/19 09:05:10 DEBUG : /: >Lookup: node=TestCopy/, err=<nil>
2023/10/19 09:05:10 DEBUG : TestCopy/: Attr:
2023/10/19 09:05:10 DEBUG : TestCopy/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2023/10/19 09:05:10 DEBUG : /: Lookup: name="blah"
2023/10/19 09:05:10 DEBUG : /: >Lookup: node=blah/, err=<nil>
2023/10/19 09:05:10 DEBUG : blah/: Attr:
2023/10/19 09:05:10 DEBUG : blah/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2023/10/19 09:05:10 DEBUG : /: Lookup: name="blah.txt"
2023/10/19 09:05:10 DEBUG : /: >Lookup: node=blah.txt, err=<nil>
2023/10/19 09:05:10 DEBUG : blah.txt: Attr:
2023/10/19 09:05:10 DEBUG : blah.txt: >Attr: a=valid=1s ino=0 size=206 mode=-rw-rw-r--, err=<nil>
2023/10/19 09:05:10 DEBUG : /: Lookup: name="crypt"
2023/10/19 09:05:10 DEBUG : /: >Lookup: node=crypt/, err=<nil>
2023/10/19 09:05:10 DEBUG : crypt/: Attr:
2023/10/19 09:05:10 DEBUG : crypt/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2023/10/19 09:05:10 DEBUG : /: Lookup: name="hosts"
2023/10/19 09:05:10 DEBUG : /: >Lookup: node=hosts, err=<nil>
2023/10/19 09:05:10 DEBUG : hosts: Attr:
2023/10/19 09:05:10 DEBUG : hosts: >Attr: a=valid=1s ino=0 size=445 mode=-rw-rw-r--, err=<nil>
2023/10/19 09:05:10 DEBUG : /: Lookup: name="linkdir"
2023/10/19 09:05:10 DEBUG : /: >Lookup: node=linkdir/, err=<nil>
2023/10/19 09:05:10 DEBUG : linkdir/: Attr:
2023/10/19 09:05:10 DEBUG : linkdir/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2023/10/19 09:05:10 DEBUG : /: Lookup: name="test"
2023/10/19 09:05:10 DEBUG : /: >Lookup: node=test, err=<nil>
2023/10/19 09:05:10 DEBUG : test: Attr:
2023/10/19 09:05:10 DEBUG : test: >Attr: a=valid=1s ino=0 size=4 mode=-rw-rw-r--, err=<nil>
2023/10/19 09:05:10 DEBUG : /: Lookup: name="test2"
2023/10/19 09:05:10 DEBUG : /: >Lookup: node=test2/, err=<nil>
2023/10/19 09:05:10 DEBUG : test2/: Attr:
2023/10/19 09:05:10 DEBUG : test2/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2023/10/19 09:05:10 DEBUG : /: Lookup: name="test3"
2023/10/19 09:05:10 DEBUG : /: >Lookup: node=test3/, err=<nil>
2023/10/19 09:05:10 DEBUG : test3/: Attr:
2023/10/19 09:05:10 DEBUG : test3/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
2023/10/19 09:05:10 DEBUG : /: Lookup: name="testshare"
2023/10/19 09:05:10 DEBUG : /: >Lookup: node=testshare/, err=<nil>
2023/10/19 09:05:10 DEBUG : testshare/: Attr:
2023/10/19 09:05:10 DEBUG : testshare/: >Attr: attr=valid=1s ino=0 size=0 mode=drwxrwxr-x, err=<nil>
^C2023/10/19 09:05:17 INFO  : Signal received: interrupt
2023/10/19 09:05:17 ERROR : /home/felix/test: Unmounted rclone mount
2023/10/19 09:05:17 INFO  : Exiting...

You can run a dry-run with dedupe to see all your dupes and run dedupe to clean it up.

[felix@gemini ~]$ rclone dedupe GD: -v
2023/10/19 09:08:30 INFO  : Google drive root '': Looking for duplicate names using interactive mode.
2023/10/19 09:08:31 INFO  : blah: Merging contents of duplicate directories
2023/10/19 09:08:31 INFO  : blah: merging "one"
2023/10/19 09:08:32 INFO  : blah: merging "three"
2023/10/19 09:08:33 INFO  : blah: merging "two"
2023/10/19 09:08:33 INFO  : blah: merging "hosts"
2023/10/19 09:08:34 INFO  : blah: removing empty directory
2023/10/19 09:08:34 INFO  : blah/one: Merging contents of duplicate directories
2023/10/19 09:08:34 INFO  : blah/one: merging "hosts"
2023/10/19 09:08:35 INFO  : blah/one: removing empty directory
2023/10/19 09:08:37 NOTICE: blah/two: Found 2 files with duplicate names
2023/10/19 09:08:37 NOTICE: blah/two: Deleting 1/2 identical duplicates (md5 d41d8cd98f00b204e9800998ecf8427e)
2023/10/19 09:08:37 INFO  : blah/two: Deleted
2023/10/19 09:08:37 NOTICE: blah/two: All duplicates removed
2023/10/19 09:08:37 NOTICE: blah/one/hosts: Found 2 files with duplicate names
2023/10/19 09:08:37 NOTICE: blah/one/hosts: Deleting 1/2 identical duplicates (md5 f0b78c96a144844b9258ea1f50f0e940)
2023/10/19 09:08:37 INFO  : blah/one/hosts: Deleted
2023/10/19 09:08:37 NOTICE: blah/one/hosts: All duplicates removed
2023/10/19 09:08:37 NOTICE: blah/three: Found 2 files with duplicate names
2023/10/19 09:08:37 NOTICE: blah/three: Deleting 1/2 identical duplicates (md5 d41d8cd98f00b204e9800998ecf8427e)
2023/10/19 09:08:38 INFO  : blah/three: Deleted
2023/10/19 09:08:38 NOTICE: blah/three: All duplicates removed
2023/10/19 09:08:38 NOTICE: blah/hosts: Found 2 files with duplicate names
2023/10/19 09:08:38 NOTICE: blah/hosts: Deleting 1/2 identical duplicates (md5 f0b78c96a144844b9258ea1f50f0e940)
2023/10/19 09:08:38 INFO  : blah/hosts: Deleted
2023/10/19 09:08:38 NOTICE: blah/hosts: All duplicates removed
16

Is the observation then that rclone mount appears to do dedupe and rclone ls does not?

17

I don't want to get too caught up on wording as it's not quite deduping per se.

The rclone ls isn't actually running on an OS per se, so you can have duplicates. Most modern OSes, you can't have duplicates so when it lists and detects dupes, it tends to throw one out. Not ideal, but trying to translate that to an OS that doesn't allow duplicates, I'm not sure what the proper 'fix' is.

18

Thanks for the explanation. That clarifies why we are seeing what we are seeing.

19

In my case there wasn't duplicates, but the first part of the names are identical (first 4 chars).

20

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