Interoperability with WinSSHD. "Unknown File not found" error.

[chris nolan]

Since updating to version 4.4, I have not been able to upload a file to my SFTP server. Downloads work properly.

Whenever I attempt to upload a file, I get an Error box that just says "Unknown File not found." It provides a try again button, but this repeats the failure. Looking at the SFTP server, I just see the successful connection, but no attempted transfer. This happens whether I upload by clicking the Upload button or by dragging and dropping the file onto the window.

The Log Drawer doesn't seem to have anything helpful, but here it is:

SSH_FXP_OPENDIR
SSH_FXP_HANDLE
SSH_FXP_READDIR
SSH_FXP_NAME
drwxrwx---   1 no-user  no-group        0 Jan  1  1970 ..
-rwxrwx---   1 no-user  no-group    12292 Sep 26  2011 .DS_Store
drwxrwx---   1 no-user  no-group        0 Dec  1  2009 .Spotlight-V100
drwxrwx---   1 no-user  no-group        0 Dec  1  2009 .Trash
drwxrwx---   1 no-user  no-group        0 Oct 28 18:43 Dropbox
-rwxrwx---   1 no-user  no-group   202518 Oct 29 13:55 ORIGreport.csv
drwxrwx---   1 no-user  no-group        0 Sep 23 23:13 WINDOWS
SSH_FXP_READDIR
SSH_FXP_STATUS
SSH_FXP_CLOSE
SSH_FXP_STATUS

After the download fails, the Transfer window displays "Upload Complete 0 B of 0 B" and a green circle.

It appears that replacing an existing file works properly, but uploading a new file causes this problem.

I can provide other logs or diagnostic help if needed. The SFTP server is WinSSHD v 5.26. Uploads worked prior to the update to 4.4 and other SFTP clients are still uploading successfully.

After several retries, I was able to get one file to successfully upload, but I have not been able to reproduce this success.

[dkocher]

Please attach the cyberduck.log file from the ​AppData directory.

[chris nolan]

Log uploaded. In the interest of a clean log, here is the process I used: I renamed my original log, then opened Cyberduck 4.3, successfully uploaded a file, upgraded to 4.4, then tried to upload a new file and failed.

I will also upload the original log which has many more examples of failures, but also some successes due to downgrading to to 4.3 for testing.

[dkocher]

Thanks for providing the logs. Would it be possible for you to ​enable debug logging which will reveal the cause of this exception.

[dkocher]

Thanks for the debug log.

[dkocher]

856	2013-10-29 17:28:01,957 [background-1] INFO  ch.cyberduck.core.Session - /U/attach_1.pdf
857	2013-10-29 17:28:01,957 [background-1] INFO  ch.cyberduck.core.Session - SSH_FXP_OPENDIR
858	2013-10-29 17:28:01,973 [Thread-0] DEBUG Ch.Cyberduck.Core.Local.LocalImpl - File C:\Users\Chris\Desktop\attach_1.pdf exists
859	2013-10-29 17:28:01,993 [Thread-0] DEBUG Ch.Cyberduck.Core.Local.LocalImpl - File C:\Users\Chris\Desktop\attach_1.pdf exists
860	2013-10-29 17:28:02,006 [background-1] INFO  ch.cyberduck.core.Session - SSH_FXP_HANDLE
861	2013-10-29 17:28:02,006 [background-1] INFO  ch.cyberduck.core.Session - SSH_FXP_READDIR
862	2013-10-29 17:28:02,008 [Thread-0] DEBUG Ch.Cyberduck.Core.Local.LocalImpl - File C:\Users\Chris\Desktop\attach_1.pdf exists
863	2013-10-29 17:28:02,036 [Thread-0] DEBUG Ch.Cyberduck.Core.Local.LocalImpl - File C:\Users\Chris\Desktop\attach_1.pdf exists
864	2013-10-29 17:28:02,058 [background-1] INFO  ch.cyberduck.core.Session - SSH_FXP_NAME
865	2013-10-29 17:28:02,058 [background-1] INFO  ch.cyberduck.core.Session - drwxrwx---   1 no-user  no-group        0 Jan  1  1970 ..
866	2013-10-29 17:28:02,058 [background-1] INFO  ch.cyberduck.core.Session - -rwxrwx---   1 no-user  no-group    12292 Sep 26  2011 .DS_Store
867	2013-10-29 17:28:02,058 [background-1] INFO  ch.cyberduck.core.Session - drwxrwx---   1 no-user  no-group        0 Dec  1  2009 .Spotlight-V100
868	2013-10-29 17:28:02,058 [background-1] INFO  ch.cyberduck.core.Session - drwxrwx---   1 no-user  no-group        0 Dec  1  2009 .Trash
869	2013-10-29 17:28:02,058 [background-1] INFO  ch.cyberduck.core.Session - -rwxrwx---   1 no-user  no-group    35097 Oct 29 20:36 barrie.png
870	2013-10-29 17:28:02,058 [background-1] INFO  ch.cyberduck.core.Session - drwxrwx---   1 no-user  no-group        0 Oct 29 21:16 Dropbox
871	2013-10-29 17:28:02,058 [background-1] INFO  ch.cyberduck.core.Session - drwxrwx---   1 no-user  no-group        0 Sep 23 23:13 WINDOWS
872	2013-10-29 17:28:02,058 [background-1] INFO  ch.cyberduck.core.Session - SSH_FXP_READDIR
873	2013-10-29 17:28:02,098 [Thread-0] DEBUG Ch.Cyberduck.Core.Local.LocalImpl - File C:\Users\Chris\Desktop\attach_1.pdf exists
874	2013-10-29 17:28:02,118 [background-1] INFO  ch.cyberduck.core.Session - SSH_FXP_STATUS
875	2013-10-29 17:28:02,118 [background-1] INFO  ch.cyberduck.core.Session - SSH_FXP_CLOSE
876	2013-10-29 17:28:02,161 [Thread-0] DEBUG Ch.Cyberduck.Core.Local.LocalImpl - File C:\Users\Chris\Desktop\attach_1.pdf exists
877	2013-10-29 17:28:02,174 [background-1] INFO  ch.cyberduck.core.Session - SSH_FXP_STATUS
878	2013-10-29 17:28:02,174 [background-1] INFO  ch.cyberduck.core.Cache - Caching 2-/U
879	2013-10-29 17:28:02,175 [background-1] DEBUG Ch.Cyberduck.Core.I18n.LocaleImpl - Caching bundle Error
880	2013-10-29 17:28:02,177 [background-1] WARN  ch.cyberduck.core.threading.SessionBackgroundAction - Failure executing background action: null File not found

The issue is that we our check if the remote file exists gives a false positive. We are requeseting the canonical path from the SFTP server for a path which is expected to fail if the file does not exist but it succeeds instead. This is an interoperability issue with WinSSHD then.

[dkocher]

In more detail we expect a SSH_FXP_STATUS response for a canonicalize request for a given path with SSH_FXP_REALPATH that does not exist. If it does not return a failure status code we make the false assumption there is a file already on the server to override.

[dkocher]

From ​SSH File Transfer Protocol

The SSH_FXP_REALPATH request can be used to have the server canonicalize any given path name to an absolute path. This is useful for converting path names containing ".." components or relative pathnames without a leading slash into absolute paths. The format of the request is as follows:

byte SSH_FXP_REALPATH uint32 request-id string original-path [UTF-8] byte control-byte [optional] string compose-path[0..n] [optional]

original-path

The first component of the path which the client wishes resolved into a absolute canonical path. This may be the entire path.

control-byte

SSH_FXP_REALPATH_NO_CHECK 0x00000001 SSH_FXP_REALPATH_STAT_IF 0x00000002 SSH_FXP_REALPATH_STAT_ALWAYS 0x00000003

This field is optional, and if it is not present in the packet, it is assumed to be SSH_FXP_REALPATH_NO_CHECK.

If SSH_FXP_REALPATH_NO_CHECK is specified, the server MUST NOT fail the request if the path does not exist, is hidden, or the user does not have access to the path or some component thereof. In addition, the path MUST NOT resolve symbolic links. This allows paths to be composed for the SSH_FXP_REMOVE command to remove symbolic links.

As we fail to provide the optional SSH_FXP_REALPATH_NO_CHECK, the default is not fail which indicates WinSSHD works according to the specs but OpenSSH (against we test) is not.

[dkocher]

Switched to use SSH_FXP_STAT. In r13690.

[dkocher]

#7517 closed as duplicate.

[dkocher]

#7617 closed as duplicate.

[dkocher]

#7620 closed as duplicate.