Moving files on rclone mount with FileZilla


#1

Anyone else has issues moving single files with FileZilla SFTP within a Rclone mount? Moving folders works but for some reason not single files.

Filezilla:
Status: Renaming ‘/media/GoogleG3/Unsorted/Misc/BBC.Hottest.Place.on.Earth.1of2.1080i.HDTV.MVGroup.mkv’ to ‘/media/GoogleG3/Miscellaneous/BBC.Hottest.Place.on.Earth.1of2.1080i.HDTV.MVGroup.mkv’
Command: mv “BBC.Hottest.Place.on.Earth.1of2.1080i.HDTV.MVGroup.mkv” “/media/GoogleG3/Miscellaneous/BBC.Hottest.Place.on.Earth.1of2.1080i.HDTV.MVGroup.mkv”
Error: mv /media/GoogleG3/Unsorted/Misc/BBC.Hottest.Place.on.Earth.1of2.1080i.HDTV.MVGroup.mkv /media/GoogleG3/Miscellaneous/BBC.Hottest.Place.on.Earth.1of2.1080i.HDTV.MVGroup.mkv: received failure with description ‘Failure’

Rclone:
mars 12 08:14:16 ubuntu rclone[243106]: 2018/03/12 08:14:16 DEBUG : Miscellaneous/: >Lookup: node=, err=no such file or directory
mars 12 08:14:16 ubuntu rclone[243106]: 2018/03/12 08:14:16 DEBUG : Miscellaneous/: Lookup: name=“BBC.Hottest.Place.on.Earth.1of2.1080i.HDTV.MVGroup.mkv”
mars 12 08:14:16 ubuntu rclone[243106]: 2018/03/12 08:14:16 DEBUG : Miscellaneous/: >Lookup: node=, err=no such file or directory
mars 12 08:14:16 ubuntu rclone[243106]: 2018/03/12 08:14:16 DEBUG : Miscellaneous/: Lookup: name=“BBC.Hottest.Place.on.Earth.1of2.1080i.HDTV.MVGroup.mkv”
mars 12 08:14:16 ubuntu rclone[243106]: 2018/03/12 08:14:16 DEBUG : Miscellaneous/: >Lookup: node=, err=no such file or directory


#2

Can you see if there are any ERROR logs and paste the log around that? I don’t see anything useful in that log.


#3

Can you try with another tool like WinSCP?

https://winscp.net/eng/download.php

WinSCP is working for me. If you have the same error with another tool, then something in your backend is wrong.


#4

Same issue with WinSCP. Hmm really strange. Moving local files and folder works. Moving folder on the mount works. But moving files does not.

Mount:
/usr/bin/rclone mount --log-level=DEBUG --debug-fuse --drive-use-trash=false GoogleG3: /media/GoogleG3/

WinSCP:

image

. 2018-03-13 08:45:54.278 Looking for network events
. 2018-03-13 08:45:54.278 Timeout waiting for network events
. 2018-03-13 08:45:54.278 [Background 1] Session upkeep
. 2018-03-13 08:45:54.278 [Background 1] Looking for network events
. 2018-03-13 08:45:54.278 [Background 1] Timeout waiting for network events
. 2018-03-13 08:45:54.779 Session upkeep
. 2018-03-13 08:45:54.780 Looking for network events
. 2018-03-13 08:45:54.780 Timeout waiting for network events
. 2018-03-13 08:45:55.278 Session upkeep
. 2018-03-13 08:45:55.279 Looking for network events
. 2018-03-13 08:45:55.279 Timeout waiting for network events
. 2018-03-13 08:45:55.779 Session upkeep
. 2018-03-13 08:45:55.779 Looking for network events
. 2018-03-13 08:45:55.779 Timeout waiting for network events
. 2018-03-13 08:45:56.279 Session upkeep
. 2018-03-13 08:45:56.279 Looking for network events
. 2018-03-13 08:45:56.279 Timeout waiting for network events
. 2018-03-13 08:45:56.279 [Background 1] Session upkeep
. 2018-03-13 08:45:56.279 [Background 1] Looking for network events
. 2018-03-13 08:45:56.279 [Background 1] Timeout waiting for network events
. 2018-03-13 08:45:56.781 Session upkeep
. 2018-03-13 08:45:56.781 Looking for network events
. 2018-03-13 08:45:56.781 Timeout waiting for network events
. 2018-03-13 08:45:57.279 Session upkeep
. 2018-03-13 08:45:57.279 Looking for network events
. 2018-03-13 08:45:57.279 Timeout waiting for network events
. 2018-03-13 08:45:57.778 Session upkeep
. 2018-03-13 08:45:57.778 Looking for network events
. 2018-03-13 08:45:57.779 Timeout waiting for network events
. 2018-03-13 08:45:58.280 Session upkeep
. 2018-03-13 08:45:58.280 Looking for network events
. 2018-03-13 08:45:58.280 Timeout waiting for network events
. 2018-03-13 08:45:58.280 [Background 1] Session upkeep
. 2018-03-13 08:45:58.280 [Background 1] Looking for network events
. 2018-03-13 08:45:58.280 [Background 1] Timeout waiting for network events
. 2018-03-13 08:45:58.778 Session upkeep
. 2018-03-13 08:45:58.779 Looking for network events
. 2018-03-13 08:45:58.779 Timeout waiting for network events
. 2018-03-13 08:45:59.278 Session upkeep
. 2018-03-13 08:45:59.278 Looking for network events
. 2018-03-13 08:45:59.278 Timeout waiting for network events
. 2018-03-13 08:45:59.779 Session upkeep
. 2018-03-13 08:45:59.779 Looking for network events
. 2018-03-13 08:45:59.779 Timeout waiting for network events
. 2018-03-13 08:46:00.279 Session upkeep
. 2018-03-13 08:46:00.279 Looking for network events
. 2018-03-13 08:46:00.279 Timeout waiting for network events
. 2018-03-13 08:46:00.779 Session upkeep
. 2018-03-13 08:46:00.780 Looking for network events
. 2018-03-13 08:46:00.780 Timeout waiting for network events
. 2018-03-13 08:46:00.780 [Background 1] Session upkeep
. 2018-03-13 08:46:00.780 [Background 1] Looking for network events
. 2018-03-13 08:46:00.780 [Background 1] Timeout waiting for network events
. 2018-03-13 08:46:01.279 Session upkeep
. 2018-03-13 08:46:01.279 Looking for network events
. 2018-03-13 08:46:01.279 Timeout waiting for network events
. 2018-03-13 08:46:01.779 Session upkeep
. 2018-03-13 08:46:01.779 Looking for network events
. 2018-03-13 08:46:01.779 Timeout waiting for network events
. 2018-03-13 08:46:02.278 Session upkeep
. 2018-03-13 08:46:02.278 Looking for network events
. 2018-03-13 08:46:02.278 Timeout waiting for network events
. 2018-03-13 08:46:02.779 Session upkeep
. 2018-03-13 08:46:02.779 Looking for network events
. 2018-03-13 08:46:02.779 Timeout waiting for network events
. 2018-03-13 08:46:02.874 Moving file “TESTFILE2” to “/media/GoogleG3/TESTFOLDER2/TESTFILE2”.

2018-03-13 08:46:02.874 Type: SSH_FXP_RENAME, Size: 87, Number: 27410
2018-03-13 08:46:02.874 12,00,00,6B,12,00,00,00,25,2F,6D,65,64,69,61,2F,47,6F,6F,67,6C,65,47,33,2F,
2018-03-13 08:46:02.874 54,45,53,54,46,4F,4C,44,45,52,31,2F,54,45,53,54,46,49,4C,45,32,00,00,00,25,
2018-03-13 08:46:02.874 2F,6D,65,64,69,61,2F,47,6F,6F,67,6C,65,47,33,2F,54,45,53,54,46,4F,4C,44,45,
2018-03-13 08:46:02.874 52,32,2F,54,45,53,54,46,49,4C,45,32,
. 2018-03-13 08:46:02.874 Sent 91 bytes
. 2018-03-13 08:46:02.874 There are 0 bytes remaining in the send buffer
. 2018-03-13 08:46:02.874 Looking for network events
. 2018-03-13 08:46:02.874 Timeout waiting for network events
. 2018-03-13 08:46:02.874 Read 4 bytes (24 pending)
. 2018-03-13 08:46:02.874 Read 24 bytes (0 pending)
< 2018-03-13 08:46:02.874 Type: SSH_FXP_STATUS, Size: 24, Number: 27140
< 2018-03-13 08:46:02.874 65,00,00,6A,04,00,00,00,00,00,00,00,07,53,75,63,63,65,73,73,00,00,00,00,
. 2018-03-13 08:46:02.874 Discarding reserved response
. 2018-03-13 08:46:02.874 Waiting for another 4 bytes
. 2018-03-13 08:46:02.874 Looking for incoming data
. 2018-03-13 08:46:02.874 Looking for network events
. 2018-03-13 08:46:03.244 Detected network event
. 2018-03-13 08:46:03.244 Enumerating network events for socket 1944
. 2018-03-13 08:46:03.244 Enumerated 1 network events making 1 cumulative events for socket 1944
. 2018-03-13 08:46:03.244 Handling network read event on socket 1944 with error 0
. 2018-03-13 08:46:03.244 Received 28 bytes (0)
. 2018-03-13 08:46:03.244 Read 4 bytes (24 pending)
. 2018-03-13 08:46:03.244 Read 24 bytes (0 pending)
< 2018-03-13 08:46:03.244 Type: SSH_FXP_STATUS, Size: 24, Number: 27410
< 2018-03-13 08:46:03.244 65,00,00,6B,12,00,00,00,04,00,00,00,07,46,61,69,6C,75,72,65,00,00,00,00,
< 2018-03-13 08:46:03.244 Status code: 4, Message: 27410, Server: Failure, Language:
. 2018-03-13 08:46:03.245 Asking user:
. 2018-03-13 08:46:03.245 Error moving file ‘TESTFILE2’ to ‘/media/GoogleG3/TESTFOLDER2/TESTFILE2’. (“General failure (server should provide error description).
. 2018-03-13 08:46:03.245 Error code: 4
. 2018-03-13 08:46:03.245 Error message from server: Failure
. 2018-03-13 08:46:03.245
. 2018-03-13 08:46:03.245 Common reasons for the Error code 4 are:
. 2018-03-13 08:46:03.245 - Renaming a file to a name of already existing file.
. 2018-03-13 08:46:03.245 - Creating a directory that already exists.
. 2018-03-13 08:46:03.245 - Moving a remote file to a different filesystem (HDD).
. 2018-03-13 08:46:03.245 - Uploading a file to a full filesystem (HDD).
. 2018-03-13 08:46:03.245 - Exceeding a user disk quota.”)
. 2018-03-13 08:46:03.280 Session upkeep
. 2018-03-13 08:46:03.280 Looking for network events
. 2018-03-13 08:46:03.280 Timeout waiting for network events
. 2018-03-13 08:46:03.280 [Background 1] Session upkeep
. 2018-03-13 08:46:03.280 [Background 1] Looking for network events
. 2018-03-13 08:46:03.280 [Background 1] Timeout waiting for network events
. 2018-03-13 08:46:03.779 Session upkeep
. 2018-03-13 08:46:03.779 Looking for network events
. 2018-03-13 08:46:03.779 Timeout waiting for network events
. 2018-03-13 08:46:04.279 Session upkeep
. 2018-03-13 08:46:04.279 Looking for network events
. 2018-03-13 08:46:04.279 Timeout waiting for network events
. 2018-03-13 08:46:04.778 Session upkeep
. 2018-03-13 08:46:04.779 Looking for network events
. 2018-03-13 08:46:04.779 Timeout waiting for network events
. 2018-03-13 08:46:05.279 Session upkeep
. 2018-03-13 08:46:05.279 Looking for network events
. 2018-03-13 08:46:05.279 Timeout waiting for network events
. 2018-03-13 08:46:05.780 Session upkeep
. 2018-03-13 08:46:05.780 Looking for network events
. 2018-03-13 08:46:05.780 Timeout waiting for network events
. 2018-03-13 08:46:05.780 [Background 1] Session upkeep
. 2018-03-13 08:46:05.780 [Background 1] Looking for network events
. 2018-03-13 08:46:05.780 [Background 1] Timeout waiting for network events
. 2018-03-13 08:46:06.279 Session upkeep
. 2018-03-13 08:46:06.279 Looking for network events
. 2018-03-13 08:46:06.279 Timeout waiting for network events
. 2018-03-13 08:46:06.780 Session upkeep
. 2018-03-13 08:46:06.780 Looking for network events
. 2018-03-13 08:46:06.780 Timeout waiting for network events
. 2018-03-13 08:46:07.279 Session upkeep
. 2018-03-13 08:46:07.279 Looking for network events
. 2018-03-13 08:46:07.279 Timeout waiting for network events
. 2018-03-13 08:46:07.779 Session upkeep
. 2018-03-13 08:46:07.779 Looking for network events
. 2018-03-13 08:46:07.779 Timeout waiting for network events
. 2018-03-13 08:46:08.278 Session upkeep
. 2018-03-13 08:46:08.278 Looking for network events
. 2018-03-13 08:46:08.278 Timeout waiting for network events
. 2018-03-13 08:46:08.278 [Background 1] Session upkeep
. 2018-03-13 08:46:08.278 [Background 1] Looking for network events
. 2018-03-13 08:46:08.278 [Background 1] Timeout waiting for network events
. 2018-03-13 08:46:08.780 Session upkeep
. 2018-03-13 08:46:08.780 Looking for network events
. 2018-03-13 08:46:08.780 Timeout waiting for network events
. 2018-03-13 08:46:09.280 Session upkeep
. 2018-03-13 08:46:09.280 Looking for network events
. 2018-03-13 08:46:09.280 Timeout waiting for network events
. 2018-03-13 08:46:09.780 Session upkeep
. 2018-03-13 08:46:09.780 Looking for network events
. 2018-03-13 08:46:09.780 Timeout waiting for network events
. 2018-03-13 08:46:10.278 Session upkeep
. 2018-03-13 08:46:10.278 Looking for network events
. 2018-03-13 08:46:10.278 Timeout waiting for network events
. 2018-03-13 08:46:10.781 Session upkeep
. 2018-03-13 08:46:10.781 Looking for network events
. 2018-03-13 08:46:10.781 Timeout waiting for network events
. 2018-03-13 08:46:10.781 [Background 1] Session upkeep
. 2018-03-13 08:46:10.781 [Background 1] Looking for network events
. 2018-03-13 08:46:10.781 [Background 1] Timeout waiting for network events
. 2018-03-13 08:46:11.280 Session upkeep
. 2018-03-13 08:46:11.280 Looking for network events
. 2018-03-13 08:46:11.280 Timeout waiting for network events
. 2018-03-13 08:46:11.780 Session upkeep
. 2018-03-13 08:46:11.780 Looking for network events
. 2018-03-13 08:46:11.780 Timeout waiting for network events
. 2018-03-13 08:46:12.278 Session upkeep
. 2018-03-13 08:46:12.278 Looking for network events
. 2018-03-13 08:46:12.278 Timeout waiting for network events

Rclone log:

2018/03/13 08:46:01 DEBUG : fuse: <- Lookup [ID=0x9a Node=0x1 Uid=1000 Gid=1000 Pid=134127] “TESTFOLDER2”
2018/03/13 08:46:01 DEBUG : /: Lookup: name=“TESTFOLDER2”
2018/03/13 08:46:01 DEBUG : /: >Lookup: node=TESTFOLDER2/, err=
2018/03/13 08:46:01 DEBUG : TESTFOLDER2/: Attr:
2018/03/13 08:46:01 DEBUG : TESTFOLDER2/: >Attr: attr=valid=1m0s ino=0 size=0 mode=drwxrwxr-x, err=
2018/03/13 08:46:01 DEBUG : fuse: -> [ID=0x9a] Lookup 0x5 gen=0 valid=1m0s attr={valid=1m0s ino=10319871201436744962 size=0 mode=drwxrwxr-x}
2018/03/13 08:46:01 DEBUG : fuse: <- Lookup [ID=0x9b Node=0x5 Uid=1000 Gid=1000 Pid=134127] “TESTFILE2”
2018/03/13 08:46:01 DEBUG : TESTFOLDER2/: Lookup: name=“TESTFILE2”
2018/03/13 08:46:01 DEBUG : GoogleG3: Saved new token in config file
2018/03/13 08:46:01 DEBUG : TESTFOLDER2/: >Lookup: node=, err=no such file or directory
2018/03/13 08:46:01 DEBUG : fuse: -> [ID=0x9b] Lookup error=ENOENT
2018/03/13 08:46:01 DEBUG : fuse: <- Link [ID=0x9c Node=0x5 Uid=1000 Gid=1000 Pid=134127] node 4 to “TESTFILE2”
2018/03/13 08:46:01 DEBUG : fuse: -> [ID=0x9c] Link error=EIO


#5

I get the exact same error message if I try to do anything on a --read-only remote.

Can you explicit mount your remote with --allow-other and try again, please?


#6

I mount my gdrive with the following flags and get exactly the same error as @aj1252

rclone_beta mount -vv --allow-non-empty --allow-other --buffer-size 32M --dir-cache-time 8760h --poll-interval 24h --vfs-cache-mode writes --vfs-cache-max-age 0m remote: /path/to/mount

I can’t:

  1. move files
  2. rename files

It doesn’t matter which version I use stable 1.39 or beta.


#7

Already tried --allow-other --allow-root --default-permissions with the same result.
And from multiple computers and internet connections.

Just to clarify; I only have issues moving files when connecting to the server remotely via SFTP, locally it works as expected.

And its nothing new, been having this since I started using rclone (1.37?) with multiple ubuntu installations.


#8

I see…

It looks like your sftp daemon (or maybe FileZilla/WinSCP) is doing the rename by making a a hardlink… rclone doesn’t support hard links.

I tried this on an rclone mount

$ ln  ~/mnt/tmp/file.txt   ~/mnt/tmp/file.txt.link
ln: failed to create hard link '/home/ncw/mnt/tmp/file.txt.link' => '/home/ncw/mnt/tmp/file.txt': Input/output error

And it appears to give the same error

2018/03/13 12:08:47 DEBUG : fuse: <- Lookup [ID=0xc9 Node=0x1 Uid=502 Gid=502 Pid=18866] "file.txt.link"
2018/03/13 12:08:47 DEBUG : /: Lookup: name="file.txt.link"
2018/03/13 12:08:47 DEBUG : /: >Lookup: node=<nil>, err=no such file or directory
2018/03/13 12:08:47 DEBUG : fuse: -> [ID=0xc9] Lookup error=ENOENT
2018/03/13 12:08:47 DEBUG : fuse: <- Lookup [ID=0xca Node=0x1 Uid=502 Gid=502 Pid=18866] "file.txt"
2018/03/13 12:08:47 DEBUG : /: Lookup: name="file.txt"
2018/03/13 12:08:47 DEBUG : /: >Lookup: node=file.txt, err=<nil>
2018/03/13 12:08:47 DEBUG : file.txt: Attr: 
2018/03/13 12:08:47 DEBUG : file.txt: >Attr: a=valid=0s ino=0 size=6 mode=-rw-rw-r--, err=<nil>
2018/03/13 12:08:47 DEBUG : fuse: -> [ID=0xca] Lookup 0x6 gen=10 valid=0s attr={valid=0s ino=16823064711478305268 size=6 mode=-rw-rw-r--}
2018/03/13 12:08:47 DEBUG : fuse: <- Forget [ID=0xcb Node=0x6 Uid=0 Gid=0 Pid=0] 1
2018/03/13 12:08:47 DEBUG : fuse: -> [ID=0xcb] Forget
2018/03/13 12:08:47 DEBUG : fuse: <- Forget [ID=0xcc Node=0x3 Uid=0 Gid=0 Pid=0] 1
2018/03/13 12:08:47 DEBUG : fuse: -> [ID=0xcc] Forget
2018/03/13 12:08:47 DEBUG : fuse: <- Lookup [ID=0xcd Node=0x1 Uid=502 Gid=502 Pid=18866] "file.txt"
2018/03/13 12:08:47 DEBUG : /: Lookup: name="file.txt"
2018/03/13 12:08:47 DEBUG : /: >Lookup: node=file.txt, err=<nil>
2018/03/13 12:08:47 DEBUG : file.txt: Attr: 
2018/03/13 12:08:47 DEBUG : file.txt: >Attr: a=valid=0s ino=0 size=6 mode=-rw-rw-r--, err=<nil>
2018/03/13 12:08:47 DEBUG : fuse: -> [ID=0xcd] Lookup 0x3 gen=11 valid=0s attr={valid=0s ino=16823064711478305268 size=6 mode=-rw-rw-r--}
2018/03/13 12:08:47 DEBUG : fuse: <- Getattr [ID=0xce Node=0x3 Uid=502 Gid=502 Pid=18866] 0x0 fl=0
2018/03/13 12:08:47 DEBUG : file.txt: Attr: 
2018/03/13 12:08:47 DEBUG : file.txt: >Attr: a=valid=0s ino=0 size=6 mode=-rw-rw-r--, err=<nil>
2018/03/13 12:08:47 DEBUG : fuse: -> [ID=0xce] Getattr valid=0s ino=16823064711478305268 size=6 mode=-rw-rw-r--
2018/03/13 12:08:47 DEBUG : fuse: <- Lookup [ID=0xcf Node=0x1 Uid=502 Gid=502 Pid=18866] "file.txt"
2018/03/13 12:08:47 DEBUG : /: Lookup: name="file.txt"
2018/03/13 12:08:47 DEBUG : /: >Lookup: node=file.txt, err=<nil>
2018/03/13 12:08:47 DEBUG : file.txt: Attr: 
2018/03/13 12:08:47 DEBUG : file.txt: >Attr: a=valid=0s ino=0 size=6 mode=-rw-rw-r--, err=<nil>
2018/03/13 12:08:47 DEBUG : fuse: -> [ID=0xcf] Lookup 0x6 gen=12 valid=0s attr={valid=0s ino=16823064711478305268 size=6 mode=-rw-rw-r--}
2018/03/13 12:08:47 DEBUG : fuse: <- Forget [ID=0xd0 Node=0x6 Uid=0 Gid=0 Pid=0] 1
2018/03/13 12:08:47 DEBUG : fuse: -> [ID=0xd0] Forget
2018/03/13 12:08:47 DEBUG : fuse: <- Lookup [ID=0xd1 Node=0x1 Uid=502 Gid=502 Pid=18866] "file.txt"
2018/03/13 12:08:47 DEBUG : /: Lookup: name="file.txt"
2018/03/13 12:08:47 DEBUG : fuse: <- Forget [ID=0xd2 Node=0x3 Uid=0 Gid=0 Pid=0] 1
2018/03/13 12:08:47 DEBUG : fuse: -> [ID=0xd2] Forget
2018/03/13 12:08:47 DEBUG : /: >Lookup: node=file.txt, err=<nil>
2018/03/13 12:08:47 DEBUG : file.txt: Attr: 
2018/03/13 12:08:47 DEBUG : file.txt: >Attr: a=valid=0s ino=0 size=6 mode=-rw-rw-r--, err=<nil>
2018/03/13 12:08:47 DEBUG : fuse: -> [ID=0xd1] Lookup 0x3 gen=13 valid=0s attr={valid=0s ino=16823064711478305268 size=6 mode=-rw-rw-r--}
2018/03/13 12:08:47 DEBUG : fuse: <- Lookup [ID=0xd3 Node=0x1 Uid=502 Gid=502 Pid=18866] "file.txt.link"
2018/03/13 12:08:47 DEBUG : /: Lookup: name="file.txt.link"
2018/03/13 12:08:47 DEBUG : /: >Lookup: node=<nil>, err=no such file or directory
2018/03/13 12:08:47 DEBUG : fuse: -> [ID=0xd3] Lookup error=ENOENT
2018/03/13 12:08:47 DEBUG : fuse: <- Link [ID=0xd4 Node=0x1 Uid=502 Gid=502 Pid=18866] node 3 to "file.txt.link"
2018/03/13 12:08:47 DEBUG : fuse: -> [ID=0xd4] Link error=EIO

I managed to reproduce this problem with FileZilla and openssh sftp daemon. Though not with the standard sftp command line client

Hmm, this makes me think that rclone is returning the wrong error code (EIO rather than ENOSYS which means not supported) for Link commands (well it is the FUSE library actually), so give this a go

https://beta.rclone.org/v1.39-234-g066eb016-mount-link-fix/ (uploaded in 15-30 mins)

It worked in my very limited testing and it is a very simple change…


#9

This new version works! Thanks a lot. Also extra credit for deb packages :slight_smile:


#10

Great! I’ve merged the fix to master now so it will be in betas from now on.

Glad you like them :slight_smile: