Topic "WinSCP SCP downloads time out"

Author Message
weirdfish
[View user's profile]

Joined: 2010-02-10
Posts: 3
Until recently, I had been using Samba for file transfers to and fro my linux server, but since I went wireless, performance issues made me go back to scp and WinSCP.

Happy with the speed, I had the bright idea to upgrade the old version that was installed (still from the 4.x branch but I can't remember exactly which one), to 4.2.5.

From the very moment I made the upgrade I'd been unable to reliably transfer large files from my linux box which BTW runs on Debian/Squeeze AMD64, has dropbear as a SSH server but relies on openssh-client to provide SCP.

The GUI says "Host is not communicating for more than 15 seconds" the only choice left is to abort the transfer. I've made several attempts with multiple large (3-4GB) files and it always fails at about 476 MiB.

At debug level 2, this is the relevant portion of the logfile:

Code:

. 2010-02-10 17.09.25.953 [Background 2] Received 7569 bytes (0)
. 2010-02-10 17.09.25.953 [Background 2] Read 4096 bytes (7119 pending)
. 2010-02-10 17.09.25.953 [Background 2] Read 4096 bytes (3023 pending)
. 2010-02-10 17.09.25.953 [Background 2] Waiting for another 1073 bytes
. 2010-02-10 17.09.25.953 [Background 2] Looking for incoming data
. 2010-02-10 17.09.25.953 [Background 2] Looking for network events
. 2010-02-10 17.09.26.109 Session upkeep
. 2010-02-10 17.09.26.109 Looking for network events
. 2010-02-10 17.09.26.109 Timeout waiting for network events
. 2010-02-10 17.09.26.609 Session upkeep
. 2010-02-10 17.09.26.609 Looking for network events
. 2010-02-10 17.09.26.609 Timeout waiting for network events
. 2010-02-10 17.09.27.109 Session upkeep
. 2010-02-10 17.09.27.109 Looking for network events
. 2010-02-10 17.09.27.109 Timeout waiting for network events


At the same time I keep open a ssh session open which works perfectly fine. Transfers also work OK through Samba (just slower).

In the BTS pages of all the deb packages involved, there's no report on this matter.

Is it possible a bug was introduced in recent releases of WinSCP?
Advertisements
martin
[View user's profile]
Site Admin
Joined: 2002-12-10
Posts: 24555
Location: Prague, Czechia
I've sent you a debug version.
_________________
Martin Prikryl
weirdfish
[View user's profile]

Joined: 2010-02-10
Posts: 3
Thanks Martin, I've seen your mail but could not find the time to test it out. I'll get back to you ASAP Smile
weirdfish
[View user's profile]

Joined: 2010-02-10
Posts: 3
So here I am. Eventually I went down another road and couldn't really find the time to do the debugging, I'm sorry.

I did some more transfers using 4.1.6 though, things seem to work smoothly with that. Hope this helps somewhat.
DocEvil

Guest


Hi everyone, now I have the same problem. After a transfer from 476 MB the Transfer over SCP stops and i get a notification about a timeout from Server.

Server is a XBMC Installation, more Infos about the Distribution I use are here: http://openelec.tv/news/item/snapshot-r4519-released

The Distribution is equipped with dropbear as a SSH server, there is sftp available.

I Tried it with the official Build 4.2.9 an with the last public Beta. With both versions the same failure.

Anybody here to help me ?
Tounet

Guest


There seems some problems with scp transfers in last versions of WinSCP.


Is it possible that you investigate these SCP transfer problems ?

There is another subject about this ! http://winscp.net/forum/viewtopic.php?t=9161

I can confirm that's works well in 4.1.8.
martin
[View user's profile]
Site Admin
Joined: 2002-12-10
Posts: 24555
Location: Prague, Czechia
Tounet wrote:
There seems some problems with scp transfers in last versions of WinSCP.


Is it possible that you investigate these SCP transfer problems ?

There is another subject about this ! http://winscp.net/forum/viewtopic.php?t=9161

I can confirm that's works well in 4.1.8.

Can you send me an email, so I can send you back a debug version of WinSCP to track the problem? Please include link back to this topic in your email. Also note in this topic that you have sent the email. Thanks.

You will find my address (if you log in) in my forum profile.
_________________
Martin Prikryl
SineSwiper
[View user's profile]

Joined: 2012-01-10
Posts: 3
Location: Louisville, KY
Yeah, same problem here. Try to do a batch transfer of files in background mode. After I come back, it's only transferred around 15 minutes or so of data, and the "Host is not communicating for more than 15 seconds" prompt comes in. Background process stops at that point and it waits for me to click "Abort". There are two prompts, I'm guessing one for each B/G transfer process.

Here's a debug log:

Code:
> 2012-01-10 17:21:06.273 [Background 1] Type: SSH_FXP_LSTAT, Size: 94, Number: 3642887
< 2012-01-10 17:21:06.459 [Background 1] Type: SSH_FXP_STATUS, Size: 24, Number: 3642628
. 2012-01-10 17:21:06.459 [Background 1] Discarding reserved response
< 2012-01-10 17:21:06.610 [Background 1] Type: SSH_FXP_STATUS, Size: 29, Number: 3642887
< 2012-01-10 17:21:06.610 [Background 1] Status code: 2
. 2012-01-10 17:21:06.639 [Background 1] Checking existence of partially transfered file.
> 2012-01-10 17:21:06.639 [Background 1] Type: SSH_FXP_LSTAT, Size: 103, Number: 3643399
< 2012-01-10 17:21:06.800 [Background 1] Type: SSH_FXP_ATTRS, Size: 37, Number: 3643399
. 2012-01-10 17:21:06.800 [Background 1] Resuming file transfer.
. 2012-01-10 17:21:06.800 [Background 1] Opening remote file.
> 2012-01-10 17:21:06.800 [Background 1] Type: SSH_FXP_OPEN, Size: 111, Number: 3643651
< 2012-01-10 17:21:07.022 [Background 1] Type: SSH_FXP_HANDLE, Size: 13, Number: 3643651
> 2012-01-10 17:21:07.037 [Background 1] Type: SSH_FXP_WRITE, Size: 4121, Number: 3644166
. 2012-01-10 17:22:54.037 Initiating key re-exchange (timeout)
. 2012-01-10 17:22:54.552 Doing Diffie-Hellman group exchange
. 2012-01-10 17:22:55.054 Doing Diffie-Hellman key exchange with hash SHA-1
. 2012-01-10 17:22:55.689 Initialised AES-256 SDCTR client->server encryption
. 2012-01-10 17:22:55.721 Initialised HMAC-SHA1 client->server MAC algorithm
. 2012-01-10 17:22:55.721 Initialised zlib (RFC1950) compression
. 2012-01-10 17:22:55.721 Initialised AES-256 SDCTR server->client encryption
. 2012-01-10 17:22:55.721 Initialised HMAC-SHA1 server->client MAC algorithm
. 2012-01-10 17:22:55.721 Initialised zlib (RFC1950) decompression
. 2012-01-10 17:23:04.566 Cached directory change via "/home/user/data/directory" to "/home/user/data/directory".
. 2012-01-10 17:23:04.581 Getting current directory name.
. 2012-01-10 17:23:04.591 Directory content loaded from cache.
. 2012-01-10 17:23:07.610 Changing directory to "subdir".
. 2012-01-10 17:23:07.625 Getting real path for '/home/user/data/directory/subdir'
> 2012-01-10 17:23:07.625 Type: SSH_FXP_REALPATH, Size: 70, Number: 3707408
< 2012-01-10 17:23:07.626 Type: SSH_FXP_STATUS, Size: 24, Number: 4612
. 2012-01-10 17:23:07.626 Discarding reserved response
< 2012-01-10 17:23:07.850 Type: SSH_FXP_NAME, Size: 143, Number: 3707408
. 2012-01-10 17:23:07.916 Real path is '/home/user/data/directory/subdir'
. 2012-01-10 17:23:07.916 Trying to open directory "/home/user/data/directory/subdir".
> 2012-01-10 17:23:07.916 Type: SSH_FXP_LSTAT, Size: 70, Number: 3707911
< 2012-01-10 17:23:08.123 Type: SSH_FXP_ATTRS, Size: 37, Number: 3707911
. 2012-01-10 17:23:08.174 Getting current directory name.
. 2012-01-10 17:23:08.174 Listing directory "/home/user/data/directory/subdir".
> 2012-01-10 17:23:08.174 Type: SSH_FXP_OPENDIR, Size: 70, Number: 3708427
< 2012-01-10 17:23:08.380 Type: SSH_FXP_HANDLE, Size: 13, Number: 3708427
> 2012-01-10 17:23:08.436 Type: SSH_FXP_READDIR, Size: 13, Number: 3708684
< 2012-01-10 17:23:08.674 Type: SSH_FXP_NAME, Size: 408, Number: 3708684
> 2012-01-10 17:23:08.701 Type: SSH_FXP_READDIR, Size: 13, Number: 3708940
< 2012-01-10 17:23:08.946 Type: SSH_FXP_STATUS, Size: 28, Number: 3708940
< 2012-01-10 17:23:08.979 Status code: 1
> 2012-01-10 17:23:08.979 Type: SSH_FXP_CLOSE, Size: 13, Number: 3709700
. 2012-01-10 17:23:10.947 Cached directory change via ".." to "/home/user/data/directory".
. 2012-01-10 17:23:10.963 Getting current directory name.
. 2012-01-10 17:23:10.966 Directory content loaded from cache.
. 2012-01-10 18:22:55.715 Initiating key re-exchange (timeout)
. 2012-01-10 18:22:56.225 Doing Diffie-Hellman group exchange
. 2012-01-10 18:22:56.727 Doing Diffie-Hellman key exchange with hash SHA-1
. 2012-01-10 18:22:57.360 Initialised AES-256 SDCTR client->server encryption
. 2012-01-10 18:22:57.374 Initialised HMAC-SHA1 client->server MAC algorithm
. 2012-01-10 18:22:57.374 Initialised zlib (RFC1950) compression
. 2012-01-10 18:22:57.374 Initialised AES-256 SDCTR server->client encryption
. 2012-01-10 18:22:57.374 Initialised HMAC-SHA1 server->client MAC algorithm
. 2012-01-10 18:22:57.374 Initialised zlib (RFC1950) decompression
. 2012-01-10 18:33:19.975 [Background 2] Waiting for dispatching send buffer timed out, asking user what to do.
. 2012-01-10 18:33:22.319 [Background 2] Asking user:
. 2012-01-10 18:33:22.319 [Background 2] Host is not communicating for 15 seconds.
. 2012-01-10 18:33:22.319 [Background 2]
. 2012-01-10 18:33:22.319 [Background 2] Wait for another 15 seconds? ()
. 2012-01-10 18:33:22.319 [Background 1] Waiting for dispatching send buffer timed out, asking user what to do.
. 2012-01-10 18:33:22.319 [Background 1] Asking user:
. 2012-01-10 18:33:22.319 [Background 1] Host is not communicating for 15 seconds.
. 2012-01-10 18:33:22.319 [Background 1]
. 2012-01-10 18:33:22.319 [Background 1] Wait for another 15 seconds? ()
. 2012-01-10 19:22:57.467 Initiating key re-exchange (timeout)
. 2012-01-10 19:22:57.977 Doing Diffie-Hellman group exchange
. 2012-01-10 19:22:58.477 Doing Diffie-Hellman key exchange with hash SHA-1
. 2012-01-10 19:22:59.112 Initialised AES-256 SDCTR client->server encryption
. 2012-01-10 19:22:59.126 Initialised HMAC-SHA1 client->server MAC algorithm
. 2012-01-10 19:22:59.126 Initialised zlib (RFC1950) compression
. 2012-01-10 19:22:59.127 Initialised AES-256 SDCTR server->client encryption
. 2012-01-10 19:22:59.127 Initialised HMAC-SHA1 server->client MAC algorithm
. 2012-01-10 19:22:59.127 Initialised zlib (RFC1950) decompression
. 2012-01-10 20:22:59.619 Initiating key re-exchange (timeout)
. 2012-01-10 20:23:00.120 Doing Diffie-Hellman group exchange
. 2012-01-10 20:23:00.633 Doing Diffie-Hellman key exchange with hash SHA-1
. 2012-01-10 20:23:01.268 Initialised AES-256 SDCTR client->server encryption
. 2012-01-10 20:23:01.282 Initialised HMAC-SHA1 client->server MAC algorithm
. 2012-01-10 20:23:01.282 Initialised zlib (RFC1950) compression
. 2012-01-10 20:23:01.282 Initialised AES-256 SDCTR server->client encryption
. 2012-01-10 20:23:01.282 Initialised HMAC-SHA1 server->client MAC algorithm
. 2012-01-10 20:23:01.282 Initialised zlib (RFC1950) decompression
. 2012-01-10 21:23:01.323 Initiating key re-exchange (timeout)
. 2012-01-10 21:23:01.838 Doing Diffie-Hellman group exchange
. 2012-01-10 21:23:02.337 Doing Diffie-Hellman key exchange with hash SHA-1
. 2012-01-10 21:23:02.976 Initialised AES-256 SDCTR client->server encryption
. 2012-01-10 21:23:02.990 Initialised HMAC-SHA1 client->server MAC algorithm
. 2012-01-10 21:23:02.990 Initialised zlib (RFC1950) compression
. 2012-01-10 21:23:02.990 Initialised AES-256 SDCTR server->client encryption
. 2012-01-10 21:23:02.990 Initialised HMAC-SHA1 server->client MAC algorithm
. 2012-01-10 21:23:02.990 Initialised zlib (RFC1950) decompression
. 2012-01-10 22:03:40.750 [Background 2] Attempt to close connection due to fatal exception:
* 2012-01-10 22:03:41.727 [Background 2] Terminated by user.
. 2012-01-10 22:03:41.727 [Background 2] Closing connection.
. 2012-01-10 22:03:41.727 [Background 2] Sending special code: 12
. 2012-01-10 22:03:41.727 [Background 2] Sent EOF message
. 2012-01-10 22:03:42.952 [Background 1] Attempt to close connection due to fatal exception:
* 2012-01-10 22:03:45.267 [Background 1] Terminated by user.
. 2012-01-10 22:03:45.267 [Background 1] Closing connection.
. 2012-01-10 22:03:45.267 [Background 1] Sending special code: 12
. 2012-01-10 22:03:45.267 [Background 1] Sent EOF message
. 2012-01-10 22:03:45.267 [Background 2] Looking up host "host.example.com"
. 2012-01-10 22:03:45.270 [Background 2] Connecting to 99.111.22.254 port 22
. 2012-01-10 22:03:46.439 [Background 2] Server version: SSH-2.0-OpenSSH_5.9p1 Debian-2


After hitting Abort twice here, it just seems to hang. Let me know what else you need for testing and debugging.
martin
[View user's profile]
Site Admin
Joined: 2002-12-10
Posts: 24555
Location: Prague, Czechia
SineSwiper wrote:
Yeah, same problem here. Try to do a batch transfer of files in background mode. After I come back, it's only transferred around 15 minutes or so of data, and the "Host is not communicating for more than 15 seconds" prompt comes in. Background process stops at that point and it waits for me to click "Abort". There are two prompts, I'm guessing one for each B/G transfer process.

What version of WinSCP are you using?
_________________
Martin Prikryl
SineSwiper
[View user's profile]

Joined: 2012-01-10
Posts: 3
Location: Louisville, KY
Version 4.3.6 (Build 1655)
martin
[View user's profile]
Site Admin
Joined: 2002-12-10
Posts: 24555
Location: Prague, Czechia
SineSwiper wrote:
Version 4.3.6 (Build 1655)

Can you please try 5.0.5 beta?
_________________
Martin Prikryl
Vasek

Guest


Hi

I have the same problem as others.
I tested version 432, 436 and 505. Every version seems to has same problem.
If you have any idea, I can help with tests (... at volny.cz).

Vasek
martin
[View user's profile]
Site Admin
Joined: 2002-12-10
Posts: 24555
Location: Prague, Czechia
Vasek wrote:
I have the same problem as others.
I tested version 432, 436 and 505. Every version seems to has same problem.
If you have any idea, I can help with tests (... at volny.cz).

I have sent you an email.
_________________
Martin Prikryl
SineSwiper
[View user's profile]

Joined: 2012-01-10
Posts: 3
Location: Louisville, KY
prikryl wrote:
SineSwiper wrote:
Version 4.3.6 (Build 1655)

Can you please try 5.0.5 beta?

Done, and it works there. I like the beta, but any chance of a backport of the bug fix for the folks that want the stable release?
krikke
[View user's profile]

Joined: 2013-03-07
Posts: 2
Location: Helsinki, Finland
Hi,
any solution to this [500 million bytes] problem? 5.1.4 and 4.2.5 both behave badly. Where do I find an old working version?

krikke
krikke
[View user's profile]

Joined: 2013-03-07
Posts: 2
Location: Helsinki, Finland
OK, I found 4.1.9, which works. When will this be fixed in new versions?

krikke
dougc

Guest


thanks to krikke, winscp 4.1.9 works fine.

i had the same issue trying to scp from an Esx 5.5 machine, however from other boxes (centos 6) i succesfully transferred dvd - 4gb iso files with no issues, so i think the problem might be newer winscp talking to probably old ssh daemons on vmware boxes.

Regards
Advertisements

You can post new topics in this forum






Search Site

What is WinSCP?

It is award-winning SFTP client, SCP client, FTPS client and FTP client integrated into one software program for file transfer to FTP server or secure SFTP server. [More]

And it's free!

Donate

About donations

$9   $19   $49   $99

About donations

Recommend

WinSCP Privacy Policy

WinSCP License