Random disconnects/aborts.
There seems to be no real pattern with this. When I log into some servers, depending on the user I am logging in as it will keep disconnecting. It of course works perfectly fine with other FTP/SFTP clients and this issue is localized to WinSCP.
To explain it in more detail, sometime when I try to change directory or open a file, it will lag for 2 or so minutes (WinSCP says 15 seconds, but its longer then that). Then I will get an error that defaults to "abort" with a 60 second timer. It will then abort and reconnect, then if it was a file upload, finish and if not fail.
The fact that uploading a file or changing directories makes me think that this is a critical flaw in how WinSCP handles things, most likely to do with how quick it can diagnose problems and attempt to reconnect, other clients do this quickly and efficiently, WinSCP takes to long to figure it out and then asks user for input (witch is pointless).
Sorry if that seemed extreme, I love the way WinSCP runs (FileZilla drives me nuts having to right click and select edit, rather then just click).
This problem has not been fixed since I started using WinSCP (its to the point I am used to it). So it has been around for well over a year on multiple computers, so its impossible that this has not been seen before. I could list out many more bugs (like SSH key support) but that I will do later in a different post.
This bug also makes synchronizing a folder not only hard, but impossible, it will always fail on the scan.
Now for the log info and other things.
First, it seems that CentOS connections are the most common to cause this problem, on SFTP. These servers are typically running CPanel or Plesk, so the control of the SSH config is extremely limited (shared environments).
I will finish this with a guess. It seems the that application itsself, when running commands in a specific environment takes to long to parse returns, or freezes up on the return, creating a synchronous environment leading to WinSCP not keeping the session up while trying to run a command on the server. This is a guess though in hopes it might shed some light on this.
To explain it in more detail, sometime when I try to change directory or open a file, it will lag for 2 or so minutes (WinSCP says 15 seconds, but its longer then that). Then I will get an error that defaults to "abort" with a 60 second timer. It will then abort and reconnect, then if it was a file upload, finish and if not fail.
The fact that uploading a file or changing directories makes me think that this is a critical flaw in how WinSCP handles things, most likely to do with how quick it can diagnose problems and attempt to reconnect, other clients do this quickly and efficiently, WinSCP takes to long to figure it out and then asks user for input (witch is pointless).
Sorry if that seemed extreme, I love the way WinSCP runs (FileZilla drives me nuts having to right click and select edit, rather then just click).
This problem has not been fixed since I started using WinSCP (its to the point I am used to it). So it has been around for well over a year on multiple computers, so its impossible that this has not been seen before. I could list out many more bugs (like SSH key support) but that I will do later in a different post.
This bug also makes synchronizing a folder not only hard, but impossible, it will always fail on the scan.
Now for the log info and other things.
First, it seems that CentOS connections are the most common to cause this problem, on SFTP. These servers are typically running CPanel or Plesk, so the control of the SSH config is extremely limited (shared environments).
. 2014-01-06 10:25:39.240 Session upkeep . 2014-01-06 10:25:39.739 Session upkeep . 2014-01-06 10:25:40.239 Session upkeep . 2014-01-06 10:25:40.740 Session upkeep . 2014-01-06 10:25:41.239 Session upkeep . 2014-01-06 10:25:41.433 Changing directory to "games". . 2014-01-06 10:25:41.433 Getting real path for '/usr/games' > 2014-01-06 10:25:41.433 Type: SSH_FXP_REALPATH, Size: 19, Number: 7921168 . 2014-01-06 10:25:41.433 Sent 23 bytes . 2014-01-06 10:25:41.433 There are 0 bytes remaining in the send buffer . 2014-01-06 10:25:41.433 Read 4 bytes (24 pending) . 2014-01-06 10:25:41.433 Read 24 bytes (0 pending) < 2014-01-06 10:25:41.433 Type: SSH_FXP_STATUS, Size: 24, Number: 7920900 . 2014-01-06 10:25:41.433 Discarding reserved response . 2014-01-06 10:25:41.433 Waiting for another 4 bytes . 2014-01-06 10:25:41.490 Detected network event . 2014-01-06 10:25:41.663 Received 45 bytes (0) . 2014-01-06 10:25:41.663 Read 4 bytes (41 pending) . 2014-01-06 10:25:41.663 Read 41 bytes (0 pending) < 2014-01-06 10:25:41.663 Type: SSH_FXP_NAME, Size: 41, Number: 7921168 . 2014-01-06 10:25:41.663 Real path is '/usr/games' . 2014-01-06 10:25:41.663 Trying to open directory "/usr/games". > 2014-01-06 10:25:41.663 Type: SSH_FXP_LSTAT, Size: 19, Number: 7921415 . 2014-01-06 10:25:41.663 Sent 23 bytes . 2014-01-06 10:25:41.663 There are 0 bytes remaining in the send buffer . 2014-01-06 10:25:41.663 Waiting for another 4 bytes . 2014-01-06 10:25:41.724 Detected network event . 2014-01-06 10:25:41.724 Received 41 bytes (0) . 2014-01-06 10:25:41.724 Read 4 bytes (37 pending) . 2014-01-06 10:25:41.724 Read 37 bytes (0 pending) < 2014-01-06 10:25:41.724 Type: SSH_FXP_ATTRS, Size: 37, Number: 7921415 . 2014-01-06 10:25:41.724 Getting current directory name. . 2014-01-06 10:25:41.724 Listing directory "/usr/games". > 2014-01-06 10:25:41.724 Type: SSH_FXP_OPENDIR, Size: 19, Number: 7921675 . 2014-01-06 10:25:41.724 Sent 23 bytes . 2014-01-06 10:25:41.724 There are 0 bytes remaining in the send buffer . 2014-01-06 10:25:41.724 Waiting for another 4 bytes . 2014-01-06 10:25:41.781 Detected network event . 2014-01-06 10:25:41.782 Received 17 bytes (0) . 2014-01-06 10:25:41.782 Read 4 bytes (13 pending) . 2014-01-06 10:25:41.782 Read 13 bytes (0 pending) < 2014-01-06 10:25:41.782 Type: SSH_FXP_HANDLE, Size: 13, Number: 7921675 > 2014-01-06 10:25:41.782 Type: SSH_FXP_READDIR, Size: 13, Number: 7921932 . 2014-01-06 10:25:41.782 Sent 17 bytes . 2014-01-06 10:25:41.782 There are 0 bytes remaining in the send buffer . 2014-01-06 10:25:41.782 Waiting for another 4 bytes . 2014-01-06 10:25:56.783 Waiting for data timed out, asking user what to do. . 2014-01-06 10:25:57.240 Session upkeep . 2014-01-06 10:25:57.265 Asking user: . 2014-01-06 10:25:57.265 **Host is not communicating for 15 seconds. . 2014-01-06 10:25:57.265 . 2014-01-06 10:25:57.265 Wait for another 15 seconds?** () . 2014-01-06 10:25:57.739 Session upkeep . 2014-01-06 10:25:58.239 Session upkeep . 2014-01-06 10:25:58.740 Session upkeep . 2014-01-06 10:25:59.239 Session upkeep . 2014-01-06 10:25:59.739 Session upkeep . 2014-01-06 10:26:00.240 Session upkeep . 2014-01-06 10:26:00.739 Session upkeep . 2014-01-06 10:26:00.756 Detected network event . 2014-01-06 10:26:00.757 Data has arrived, closing query to user. . 2014-01-06 10:26:00.760 Network error: Software caused connection abort * 2014-01-06 10:26:00.762 (ESshFatal) Network error: Software caused connection abort * 2014-01-06 10:26:00.762 Error listing directory '/usr/games'. * 2014-01-06 10:26:00.762 Error changing directory to 'games'.
I will finish this with a guess. It seems the that application itsself, when running commands in a specific environment takes to long to parse returns, or freezes up on the return, creating a synchronous environment leading to WinSCP not keeping the session up while trying to run a command on the server. This is a guess though in hopes it might shed some light on this.
