Failed to copy: sftp: "Folder not found: c:\\ftpsites... SSH_FX_FAILURE

#1

I connected a remote SFTP source, which I am able to ls just fine. But when I try to sync or copy, I receive an error as rclone attempts to transfer each file. I'm running on OSX, and I believe the remote server is running on a Windows system win win_scp..

I am getting error like this:
rclone sync aiep:./ ~/home/Download/PEIA_CCP

2019/04/30 12:13:27 NOTICE: aaaaa_valley_hhhhhh_ccp/CCP_Valley_hhhhhh_190429.csv: Removing partially written file on error: sftp: "Folder not found: c:\ftpsites\aiep\valley_hhhhhh\CCP_Valley_hhhhhh_190429.csv" (SSH_FX_FAILURE)

2019/04/30 12:13:27 ERROR : rclone sync aiep:./ ~/home/Download/PEIA_CCP

2019/04/30 12:13:27 NOTICE: aaaaaaa_valley_hhhhhh_ccp/CCP_Valley_hhhhhh_190429.csv: Removing partially written file on error: sftp: "Folder not found: c:\ftpsites\aiep\valley_hhhhhh\CCP_Valley_hhhhhh_190429.csv" (SSH_FX_FAILURE)

2019/04/30 12:13:27 ERROR : aaaaaaa_valley_hhhhhh_ccp/CCP_Valley_hhhhhh_190429.csv: Failed to copy: sftp: "Folder not found: c:\ftpsites\aiep\valley_health\CCP_Valley_hhhhhh_190429.csv" (SSH_FX_FAILURE)

debug with -vv

rclone copy aiep:./ ~/home/Download/aiep_CCP -vv
2019/04/30 13:00:00 DEBUG : rclone: Version "v1.47.0" starting with parameters ["rclone" "copy" "aiep:./" "/Users/auser/home/Download/aiep_CCP" "-vv"]
2019/04/30 13:00:00 DEBUG : Using config file from "/Users/auser/.config/rclone/rclone.conf"
2019/04/30 13:00:03 DEBUG : aaaaaaa_iiiiicreek_ccp/CCP_iiiii_Creek_190429.csv: Sizes differ (src 1466472 vs dst 0)
2019/04/30 13:00:04 DEBUG : aaaaaaa_iiiiicreek_ccp/CCP_iiiii_Creek_190429.csv: Reopening on read failure after 0 bytes: retry 1/10: sftp: "Folder not found: c:\ftpsites\aiep\iiiiicreek\CCP_iiiii_Creek_190429.csv" (SSH_FX_FAILURE)
2019/04/30 13:00:05 DEBUG : aaaaaaa_iiiiicreek_ccp/CCP_iiiii_Creek_190429.csv: Reopening on read failure after 0 bytes: retry 2/10: sftp: "Folder not found: c:\ftpsites\aiep\iiiiicreek\CCP_iiiii_Creek_190429.csv" (SSH_FX_FAILURE)
2019/04/30 13:00:05 DEBUG : aaaaaaa_new_vvvvv_ccp/CCP_Newvvvvv_190429.csv: Modification times differ by 20h36m52.571731647s: 2019-04-29 15:36:37 -0400 EDT, 2019-04-30 12:13:29.571731647 -0400 EDT
2019/04/30 13:00:06 DEBUG : aaaaaaa_iiiiicreek_ccp/CCP_iiiii_Creek_190429.csv: Reopening on read failure after 0 bytes: retry 3/10: sftp: "Folder not found: c:\ftpsites\aiep\iiiiicreek\CCP_iiiii_Creek_190429.csv" (SSH_FX_FAILURE)
2019/04/30 13:00:06 DEBUG : aaaaaaa_mva_hhhhhh_ccp/CCP_MVA_190429.csv: Reopening on read failure after 0 bytes: retry 1/10: sftp: "Folder not found: c:\ftpsites\aiep\mva_hhhhhh_ccp\CCP_MVA_190429.csv" (SSH_FX_FAILURE)
2019/04/30 13:00:06 DEBUG : aaaaaaa_new_vvvvv_ccp/CCP_Newvvvvv_190429.csv: Reopening on read failure after 0 bytes: retry 1/10: sftp: "Folder not found: c:\ftpsites\aiep\new_vvvvv_ccp_program\CCP_Newvvvvv_190429.csv" (SSH_FX_FAILURE)
2019/04/30 13:00:06 DEBUG : aaaaaaa_iiiiicreek_ccp/CCP_iiiii_Creek_190429.csv: Reopening on read failure after 0 bytes: retry 4/10: sftp: "Folder not found: c:\ftpsites\aiep\iiiiicreek\CCP_iiiii_Creek_190429.csv" (SSH_FX_FAILURE)
2019/04/30 13:00:06 DEBUG : aaaaaaa_clay_bbbbbbbb_ccp/CCP_aaaaaaa_CLAYBATT_190429.CSV: Sizes differ (src 82474 vs dst 0)
2019/04/30 13:00:06 DEBUG : aaaaaaa_mva_hhhhhh_ccp/CCP_MVA_190429.csv: Reopening on read failure after 0 bytes: retry 2/10: sftp: "Folder not found: c:\ftpsites\aiep\mva_hhhhhh_ccp\CCP_MVA_190429.csv" (SSH_FX_FAILURE)
2019/04/30 13:00:06 INFO : Local file system at /Users/auser/home/Download/aiep_CCP: Waiting for checks to finish
2019/04/30 13:00:06 INFO : Local file system at /Users/auser/home/Download/aiep_CCP: Waiting for transfers to finish

#2

rclone version shows what?

if you run the same command with -vv on it, can you share those results?

#3

rclone version

rclone v1.47.0

  • os/arch: darwin/amd64

  • go version: go1.12.4

I added the debug option info to the original post.

#4

What does your rclone.conf look like for that? I just did a test on my Mac to a Linux host with SFTP and copied a few files over.

#5

Hi Animostiy022,

It looks like this:
[aiep]

type = sftp

host = ftp.thehost.com

user = User.name

port = 22

pass = {password}

use_insecure_cipher = true

disable_hashcheck = false

I had previously not had disable_hashcheck , but it did the same thing.

#6

I have a pretty similar config:

[SFTP]
type = sftp
host = home.thehost.us
user = felix
port = 4022
pass = password
use_insecure_cipher = true

Can you do a ls on a single file that you know is there like:

rclone ls -vv aiep: aaaaaaa_iiiiicreek_ccp/CCP_iiiii_Creek_190429.csv

I think that is the path from reading the logs, but not quite sure.

And if you test via a scp command on the same host/path, can you share that too?

I just did a test file copy:

scp felix@home:hosts .
hosts
#7

I can access the sftp server just fine from the command line on my mac and in other sftp clients… here are the results of the -vv on ls:

rclone ls -vv aiep:aaaaaa_valley_hhhhh_ccp/CCP_Valley_hhhhh_190429.csv
2019/04/30 15:02:18 DEBUG : rclone: Version “v1.47.0” starting with parameters [“rclone” “ls” “-vv” “aiep:aaaaaaa_valley_hhhhh_ccp/CCP_Valley_hhhhh_190429.csv”]
2019/04/30 15:02:18 DEBUG : Using config file from “/Users/auser/.config/rclone/rclone.conf”
2368268 CCP_Valley_hhhhh_190429.csv
2019/04/30 15:02:19 DEBUG : 12 go routines active
2019/04/30 15:02:19 DEBUG : rclone: Version “v1.47.0” finishing with parameters [“rclone” “ls” “-vv” “aiep:aaaaaa_valley_hhhhh_ccp/CCP_Valley_hhhhh_190429.csv”]

#8

What was weird for me were these paths:
sftp: “Folder not found: c:\ftpsites\aiep\mva_hhhhhh_ccp\CCP_MVA_190429.csv”

I don’t know where the c:\ftpsites came from…

#9

So when you run that you get those errors?

What does rclone ls aiep: -vv do?

#10

That is a strange error… It makes me wonder if rclone is mis-identifying files as directories…

That didn’t print the file did it? So it looks like rclone tried to list it as a directory.

Are these files (on the server) maybe symlinks (or junction points) on windows - that might explain what is going on.

Which server is it?

#11

rclone ls aiep: -vv
2019/05/01 09:38:58 DEBUG : rclone: Version “v1.47.0” starting with parameters [“rclone” “ls” “aiep:” “-vv”]
2019/05/01 09:38:58 DEBUG : Using config file from “/Users/anthonyvollmer/.config/rclone/rclone.conf”
2368268 aaaaaaa_valley_hhhhhh_ccp/CCP_Valley_hhhhhh_190429.csv
0 aaaaaaa_mva_hhhhhh_ccp/CCP_MVA_190429.csv
204078 aaaaaaa_rainelle_ccp/CCP_aaaaaaa_RAINELLE_190429.CSV
1466472 aaaaaaa_iiiiicreek_ccp/CCP_iiiii_Creek_190429.csv
0 aaaaaaa_new_rrrrr_ccp/CCP_Newrrrrr_190429.csv
82474 aaaaaaa_clay_battelle_ccp/CCP_aaaaaaa_CLAYBATT_190429.CSV
0 aaaaaaa_st_george_ccp/CCP_aaaaaaa_STGEORGE_190429.CSV
2019/05/01 09:39:01 DEBUG : 75 go routines active
2019/05/01 09:39:01 DEBUG : rclone: Version “v1.47.0” finishing with parameters [“rclone” “ls” “aiep:” “-vv”]

#12

No it did not print the file. I pasted the entire output.

I don’t know if the files are symlinks on Windows, looking at the error it was my first thought, having looked through other error reports and posts in forums, etc.

The server is an associate company where I get files waiting for me to process. I believe the server is Win_SCP as I had once tried to ssh to it instead of SFTP and it gave an error , WinSCP: this is end-of-file:0 when I pressed enter. I have no issues when connecting via SFTP.

#13

Could you repeat that with lsf -R instead so rclone lsf -R aiep: -vv and post the output? That will tell us whether rclone things they are files or directories.

I don’t know if a different SFTP client might tell you.

Ah OK!

#14

rclone lsf -R aiep: -vv
2019/05/01 19:13:52 DEBUG : rclone: Version “v1.47.0” starting with parameters [“rclone” “lsf” “-R” “aiep:” “-vv”]
2019/05/01 19:13:52 DEBUG : Using config file from “/Users/auser/.config/rclone/rclone.conf”
aaaaaaa/
aaaaaaa_ccccccreek_ccp/
aaaaaaa_clay_battelle_ccp/
aaaaaaa_mva_hhhhhh_ccp/
aaaaaaa_new_rrrrr_ccp/
aaaaaaa_rainelle_ccp/
aaaaaaa_st_george_ccp/
aaaaaaa_valley_hhhhhh_ccp/
aaaaaaa_valley_hhhhhh_ccp/CCP_Valley_hhhhhh_190429.csv
aaaaaaa_mva_hhhhhh_ccp/CCP_MVA_190429.csv
aaaaaaa_st_george_ccp/CCP_aaaaaaa_STGEORGE_190429.CSV
aaaaaaa_rainelle_ccp/CCP_aaaaaaa_RAINELLE_190429.CSV
aaaaaaa_clay_battelle_ccp/CCP_aaaaaaa_CLAYBATT_190429.CSV
aaaaaaa_new_rrrrr_ccp/CCP_Newrrrrr_190429.csv
aaaaaaa_ccccccreek_ccp/CCP_ccccc_Creek_190429.csv
2019/05/01 19:13:57 DEBUG : 75 go routines active
2019/05/01 19:13:57 DEBUG : rclone: Version “v1.47.0” finishing with parameters [“rclone” “lsf” “-R” “aiep:” “-vv”]

#15

I did a debug on sftp from command line:
OpenSSH_7.9p1, LibreSSL 2.7.3

debug1: Local version string SSH-2.0-OpenSSH_7.9
debug1: Remote protocol version 2.0, remote software version WS_FTP-SSH_7.5.1
debug1: no match: WS_FTP-SSH_7.5.1
debug3: fd 5 is O_NONBLOCK

debug2: compression ctos: none,zlib@openssh.com,zlib
debug2: compression stoc: none,zlib@openssh.com,zlib
debug2: languages ctos:
debug2: languages stoc:
debug2: first_kex_follows 0
debug2: reserved 0
debug2: peer server KEXINIT proposal
debug2: KEX algorithms: diffie-hellman-group1-sha1,diffie-hellman-group14-sha1
debug2: host key algorithms: ssh-dss,ssh-rsa
debug2: ciphers ctos: 3des-cbc,blowfish-cbc,aes256-cbc,aes128-cbc,cast128-cbc
debug2: ciphers stoc: 3des-cbc,blowfish-cbc,aes256-cbc,aes128-cbc,cast128-cbc
debug2: MACs ctos: hmac-sha1,hmac-sha1-96,hmac-md5,hmac-md5-96
debug2: MACs stoc: hmac-sha1,hmac-sha1-96,hmac-md5,hmac-md5-96
debug2: compression ctos: none
debug2: compression stoc: none
debug2: languages ctos:
debug2: languages stoc:
debug2: first_kex_follows 0
debug2: reserved 0
debug1: kex: algorithm: diffie-hellman-group14-sha1
debug1: kex: host key algorithm: ssh-rsa

#16

That looks sensible…

After tracing through the code, I think what is happening is when the sftp library attempts to read from the file it gets the error sftp: “Folder not found: c:\ftpsites\aiep\iiiiicreek\CCP_iiiii_Creek_190429.csv” (SSH_FX_FAILURE)

From the listings, rclone thinks it is a file, but when the upstream library reads it things it is a folder, or the server thinks it is a folder.

Could you try doing this from a command line sftp client on the “aiep_CCP” directory? I used the one that comes with ubuntu

$ sftp sftptest@localhost
Connected to sftptest@localhost.
sftp> ls -l
lrwxrwxrwx    1 root     root           13 Jan 28 17:08 dangling_link
-rw-r--r--    1 sftptest sftptest        6 Dec 30 16:13 hello[brackends].txt
drwxrwxr-x    7 sftptest sftptest     4096 Nov 28 09:58 restic
drwxr-xr-x    2 sftptest sftptest     4096 Dec 30 16:13 subdir
drwxr-xr-x    3 sftptest sftptest     4096 Dec 30 16:51 test

That should show exactly what type of thing the sftp server thinks things are.

Is there any chance I could get access to the sftp server? I’m guessing not, but if it is OK then please DM me!

#17

I didn’t see the aiep_CCP directory you were refering to, to I did an ls -l from the home/root where I login to and also inside the aaaaaaa_iiiiiicreek_ccp directory… I really appreciate all the help looking into this. Unfortunately, the server isn’t mine.

sftp> ls -l
drwx—r-x 2 ftpadmin ftpadmin 0 Apr 27 04:00 aaaaaaa
drwx—r-x 2 ftpadmin ftpadmin 0 Apr 29 11:14 aaaaaaa_iiiiicreek_ccp
drwx—r-x 2 ftpadmin ftpadmin 0 Apr 29 11:14 aaaaaaa_clay_battelle_ccp
drwx—r-x 2 ftpadmin ftpadmin 0 Apr 29 11:14 aaaaaaa_mva_hhhhhh_ccp
drwx—r-x 2 ftpadmin ftpadmin 0 Apr 29 11:14 aaaaaaa_new_rrrrr_ccp
drwx—r-x 2 ftpadmin ftpadmin 0 Apr 29 11:14 aaaaaaa_rainelle_ccp
drwx—r-x 2 ftpadmin ftpadmin 0 Apr 29 11:14 aaaaaaa_st_george_ccp
drwx—r-x 2 ftpadmin ftpadmin 0 Apr 29 11:14 aaaaaaa_valley_hhhhhh_ccp
sftp>

sftp> ls -l
-rwxr-xrwx 1 ftpadmin ftpadmin 1466472 Apr 29 11:14 CCP_iiiii_Creek_190429.csv
sftp>

#18

Thanks for that, unfortunately those look normal!

I’ve compiled a version of the sftp library with debugging. This will print lots of hex numbers!

https://beta.rclone.org/branch/v1.47.0-032-g5c0574ea-fix-sftp-folder-beta/ (uploaded in 15-30 mins)

Can you find the minimum thing which prints the “Folder not found” error.

Something like this might do it

rclone copyto  --low-level-retries 1 --retries 1 -vv aiep:aaaaaa_valley_hhhhh_ccp/CCP_Valley_hhhhh_190429.csv /tmp/z.csv

Then paste the debug stream!

Once we’ve got that I’ll probably ask for help upstream.

#19

./rclone copyto --low-level-retries 1 --retries 1 -vv aiep:aaaaaaa_valley_hhhhh_ccp/CCP_Valley_hhhhh_190429.csv ~/Downloads/z.csv
2019/05/02 13:00:24 DEBUG : rclone: Version “v1.47.0-032-g5c0574ea-fix-sftp-folder-beta” starting with parameters ["./rclone" “copyto” “–low-level-retries” “1” “–retries” “1” “-vv” “aiep:aaaaaaa_valley_hhhhh_ccp/CCP_Valley_hhhhh_190429.csv” “/Users/auser/Downloads/z.csv”]
2019/05/02 13:00:24 DEBUG : Using config file from “/Users/auser/.config/rclone/rclone.conf”
2019/05/02 13:00:24 send packet: SSH_FXP_INIT 5 bytes 00000003
2019/05/02 13:00:24 recv packet: SSH_FXP_VERSION 5 bytes 00000003
2019/05/02 13:00:24 send packet: SSH_FXP_STAT 63 bytes 0000000100000036616c65646164655f76616c6c65795f6865616c74685f6363702f4343505f56616c6c65795f4865616c74685f3139303432392e637376
2019/05/02 13:00:24 recv packet: SSH_FXP_ATTRS 29 bytes 000000010000003d000000000024230c000081ef5cc6dc835cc6dc83
2019/05/02 13:00:24 send packet: SSH_FXP_STAT 63 bytes 0000000200000036616c65646164655f76616c6c65795f6865616c74685f6363702f4343505f56616c6c65795f4865616c74685f3139303432392e637376
2019/05/02 13:00:24 recv packet: SSH_FXP_ATTRS 29 bytes 000000020000003d000000000024230c000081ef5cc6dc835cc6dc83
2019/05/02 13:00:24 DEBUG : CCP_Valley_hhhhh_190429.csv: Couldn’t find file - need to transfer
2019/05/02 13:00:25 send packet: SSH_FXP_OPEN 71 bytes 0000000300000036616c65646164655f76616c6c65795f6865616c74685f6363702f4343505f56616c6c65795f4865616c74685f3139303432392e6373760000000100000000
2019/05/02 13:00:25 recv packet: SSH_FXP_HANDLE 12 bytes 0000000300000003323535
2019/05/02 13:00:25 send packet: SSH_FXP_FSTAT 12 bytes 0000000400000003323535
2019/05/02 13:00:25 recv packet: SSH_FXP_STATUS 94 bytes 00000004000000040000004d466f6c646572206e6f7420666f756e643a20633a5c66747073697465735c706569615c76616c6c65795f6865616c74685c4343505f56616c6c65795f4865616c74685f3139303432392e63737600000000
2019/05/02 13:00:25 send packet: SSH_FXP_CLOSE 12 bytes 0000000500000003323535
2019/05/02 13:00:25 recv packet: SSH_FXP_STATUS 17 bytes 00000005000000000000000000000000
2019/05/02 13:00:25 DEBUG : CCP_Valley_hhhhh_190429.csv: Reopening on read failure after 0 bytes: retry 1/1: sftp: “Folder not found: c:\ftpsites\aiep\valley_hhhhh\CCP_Valley_hhhhh_190429.csv” (SSH_FX_FAILURE)
2019/05/02 13:00:25 DEBUG : CCP_Valley_hhhhh_190429.csv: Reopen failed after 0 bytes read: failed to reopen: too many retries
2019/05/02 13:00:25 NOTICE: z.csv: Removing partially written file on error: sftp: “Folder not found: c:\ftpsites\aiep\valley_hhhhh\CCP_Valley_hhhhh_190429.csv” (SSH_FX_FAILURE)
2019/05/02 13:00:25 ERROR : CCP_Valley_hhhhh_190429.csv: Failed to copy: sftp: “Folder not found: c:\ftpsites\aiep\valley_hhhhh\CCP_Valley_hhhhh_190429.csv” (SSH_FX_FAILURE)
2019/05/02 13:00:25 ERROR : Attempt 1/1 failed with 2 errors and: sftp: “Folder not found: c:\ftpsites\aiep\valley_hhhhh\CCP_Valley_hhhhh_190429.csv” (SSH_FX_FAILURE)
2019/05/02 13:00:25 Failed to copyto: sftp: “Folder not found: c:\ftpsites\aiep\valley_hhhhh\CCP_Valley_hhhhh_190429.csv” (SSH_FX_FAILURE)

#20

Thank you for that - that is very helpful.

I opened an upstream issue to ask the SFTP experts exactly what it means!

1 Like