Forum » Support and Bug Reports »

WinSCP SCP downloads time out

weirdfish
Joined:: 2010-02-10
Posts:: 3

WinSCP SCP downloads time out

2010-02-10 18:56

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:

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

Reply with quote

martin◆ Site Admin
Joined:: 2002-12-10
Posts:: 41,506
Location:: Prague, Czechia

Re: WinSCP SCP downloads time out

2010-02-14

I've sent you a debug version.

Reply with quote

weirdfish

2010-02-15 17:17

Thanks Martin, I've seen your mail but could not find the time to test it out. I'll get back to you ASAP :)

Reply with quote

weirdfish

2010-02-24 19:29

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.

Reply with quote

DocEvil Guest

2010-12-23 00:54

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: <invalid hyperlink removed by admin>

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 ?

Reply with quote

Tounet Guest

Same probleme on Esxi Host

2011-12-07 19:41

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 ! https://winscp.net/forum/viewtopic.php?t=9161

I can confirm that's works well in 4.1.8.

Reply with quote

martin◆ Site Admin
Joined:: 2002-12-10
Posts:: 41,506
Location:: Prague, Czechia

Re: Same probleme on Esxi Host

2011-12-09

Tounet wrote:

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

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.

Reply with quote

SineSwiper
Joined:: 2012-01-10
Posts:: 3
Location:: Louisville, KY

2012-01-11 04:10

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:

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

Reply with quote

martin◆ Site Admin
Joined:: 2002-12-10
Posts:: 41,506
Location:: Prague, Czechia

2012-01-12

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?

Reply with quote

SineSwiper

2012-01-15 05:30

Version 4.3.6 (Build 1655)

Reply with quote

martin◆ Site Admin

2012-01-16

SineSwiper wrote:

Version 4.3.6 (Build 1655)

Can you please try 5.0.5 beta?

Reply with quote

Vasek Guest

WinSCP stops when copy 477MiB from big file (VMDK f.e.)

2012-01-17 13:25

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

Reply with quote

martin◆ Site Admin
Joined:: 2002-12-10
Posts:: 41,506
Location:: Prague, Czechia

Re: WinSCP stops when copy 477MiB from big file (VMDK f.e.)

2012-01-19

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.

Reply with quote

SineSwiper
Joined:: 2012-01-10
Posts:: 3
Location:: Louisville, KY

2012-01-24 04:36

martin 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?

Reply with quote

krikke
Joined:: 2013-03-07
Posts:: 2
Location:: Helsinki, Finland

2013-03-07 10:35

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

Reply with quote

krikke

2013-03-07 12:11

OK, I found 4.1.9, which works. When will this be fixed in new versions?

krikke

Reply with quote

dougc Guest

2013-12-19 14:21

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

Reply with quote

You can post new topics in this forum