sftp: Fstat returns error "Folder not found: c:\xxx\yyy.csv" (SSH_FX_FAILURE) on a file

An rclone user has reported that rclone with a certain sftp server reports the error "Folder not found: c:\xxx\yyy.csv" (SSH_FX_FAILURE). As far as I can work out this is being generated by the Read() call on an open file, though looking at the trace below it seems to come from Fstat on the open file - not sure what is calling that.

The user reports that other sftp clients work just fine.

I turned on debugging and sent the user a binary to try.

Here is rclone logs interleaved with sftp debugs

./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

Rclone has identified the file as needing to transfer

2019/05/02 13:00:24 DEBUG : CCP_Valley_hhhhh_190429.csv: Couldn’t find file - need to transfer

Now we open it

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

However the SSH_FXP_FSTAT returned an error. I don’t know why! Rclone doesn’t directly call Stat() on the handle returned - I’m not sure where that gets called.

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)

I attempted to decode the sftp debug using the RFC but it wasn’t making sense, so I’m asking for help here.

Thanks in advance!

About this issue

Original URL
State: closed
Created 5 years ago
Comments: 18 (13 by maintainers)

Commits related to this issue

Use Stat rather than Fstat in File.WriteTo to work around server bugs Before this change in File.WriteTo() we used Fstat to discover the length of the file being transferred. It appears that some SF... — committed to ncw/sftp by ncw 5 years ago
vendor: update github.com/pkg/sftp to fix sftp client issues See: https://forum.rclone.org/t/failed-to-copy-sftp-folder-not-found-c-ftpsites-ssh-fx-failure/9778 See: https://github.com/pkg/sftp/issue... — committed to rclone/rclone by ncw 5 years ago
vendor: update github.com/pkg/sftp to fix sftp client issues See: https://forum.rclone.org/t/failed-to-copy-sftp-folder-not-found-c-ftpsites-ssh-fx-failure/9778 See: https://github.com/pkg/sftp/issue... — committed to id01/rclone by ncw 5 years ago

Most upvoted comments

Of course you are right about the filesize and I think your solution is fine. I’ll take it for now to resolve the issue. It still bugs me that it is needed though as it doesn’t really seem like it should be, it should receive an EOF and finish up just like ReadFrom. But I don’t have the time to play with it right now and your PR fixes it.

eikenb on May 23, 2019

Does this slightly less hacky patch work for you?

Yep it does indeed (at least as well as my hacky patch did).

~I’m seeing some other issues relating to copy not working (but sync is fine) but I don’t think these are related to this issue specifically.~ Ignore that, I was being a tool…

jfautley on May 20, 2019

I am seeing a very similar sounding issue, but on downloading files from an external SFTP server (over which I have no control). This is also using rclone but the issue appears to be with the behavior of the underlying sftp module.

The SFTP server in question (“SSH-2.0-SSHD-CORE-0.13.0”, for those playing along at home) returns an SSH_FX_FAILURE error for the stat call. A quick-n-dirty hack was to remove the call to stat and set fileSize to f.c.maxPacket. I would suggest that if the stat call returns an error, just set the fileSize=maxPacket and let the download continue.

If this is an appropriate fix, I’m happy to raise a PR.

jfautley on May 20, 2019

The directories and file already exist on the client where it is being downloaded to, on the server where it is being downloaded from or both?

The directories and files exist on the server. Rclone will create directories as needed on the client before it downloads the file.

PS While investigating this problem I had a deeper look at the source and discovered it could be an sftp server! That encouraged me to write rclone serve sftp which can server any of rclone’s supported cloud providers (including local disk) as sftp. The library was a joy to work with, so thank you very much for that 😃

ncw on May 16, 2019