WinScp hangs when uploading files using sftp.

HI,

When I try to upload a file (about 8MB) using SFTP then it hangs
well before the complete part has been transferred.

The WinSCP application shows (Not Responding).

Note that I can transfer the same file without a problem
using cygwin's sftp command.

I have enabled logging (debug2) and pasted the begin and end of the log file (named C:\cts\top\winscp_problem\jvda@rodenbach1.log) here:
==================================================================
. 2008-04-08 16:15:11.588 --------------------------------------------------------------------------
. 2008-04-08 16:15:11.588 WinSCP Version 4.1.0 (Build 375) (OS 5.1.2600 Service Pack 2)
. 2008-04-08 16:15:11.588 Login time: dinsdag 8 april 2008 16:15:11
. 2008-04-08 16:15:11.588 --------------------------------------------------------------------------
. 2008-04-08 16:15:11.588 Session name: jvda@rodenbach
. 2008-04-08 16:15:11.588 Host name: rodenbach (Port: 22)
. 2008-04-08 16:15:11.588 User name: jvda (Password: Yes, Key file: No)
. 2008-04-08 16:15:11.588 Tunnel: No
. 2008-04-08 16:15:11.588 Transfer Protocol: SFTP (SCP)
. 2008-04-08 16:15:11.588 Ping type: -, Ping interval: 30 sec; Timeout: 15 sec
. 2008-04-08 16:15:11.588 Proxy: none
. 2008-04-08 16:15:11.588 SSH protocol version: 2; Compression: No
. 2008-04-08 16:15:11.588 Bypass authentication: No
. 2008-04-08 16:15:11.588 Try agent: Yes; Agent forwarding: No; TIS/CryptoCard: No; KI: Yes; GSSAPI: No
. 2008-04-08 16:15:11.588 Ciphers: aes,blowfish,3des,WARN,arcfour,des; Ssh2DES: No
. 2008-04-08 16:15:11.588 SSH Bugs: -,-,-,-,-,-,-,-
. 2008-04-08 16:15:11.588 SFTP Bugs: -,-
. 2008-04-08 16:15:11.588 Return code variable: Autodetect; Lookup user groups: Yes
. 2008-04-08 16:15:11.588 Shell: default, EOL: 0
. 2008-04-08 16:15:11.588 Clear aliases: Yes, Unset nat.vars: Yes, Resolve symlinks: Yes
. 2008-04-08 16:15:11.588 LS: ls -la, Ign LS warn: Yes, Scp1 Comp: No
. 2008-04-08 16:15:11.588 Local directory: default, Remote directory: home, Update: No, Cache: Yes
. 2008-04-08 16:15:11.588 Cache directory changes: Yes, Permanent: Yes
. 2008-04-08 16:15:11.588 DST mode: 1
. 2008-04-08 16:15:11.588 --------------------------------------------------------------------------
. 2008-04-08 16:15:11.628 Looking up host "rodenbach"
. 2008-04-08 16:15:11.738 Connecting to 194.253.89.130 port 22
. 2008-04-08 16:15:11.769 Selecting events 63 for socket 1204
. 2008-04-08 16:15:11.769 Waiting for the server to continue with the initialisation
. 2008-04-08 16:15:11.769 Looking for incoming data
. 2008-04-08 16:15:11.769 Looking for network events
. 2008-04-08 16:15:11.769 Detected network event
. 2008-04-08 16:15:11.769 Enumerating network events for socket 1204
. 2008-04-08 16:15:11.769 Enumerated 2 network events making 2 cumulative events for socket 1204
. 2008-04-08 16:15:11.769 Handling network write event on socket 1204 with error 0
. 2008-04-08 16:15:11.769 Looking for network events
. 2008-04-08 16:15:11.919 Detected network event
. 2008-04-08 16:15:11.919 Enumerating network events for socket 1204
. 2008-04-08 16:15:11.919 Enumerated 17 network events making 17 cumulative events for socket 1204
. 2008-04-08 16:15:11.919 Handling network read event on socket 1204 with error 0
. 2008-04-08 16:15:11.919 Server version: SSH-2.0-OpenSSH_3.6.1p2-pwexp22
. 2008-04-08 16:15:11.919 We claim version: SSH-2.0-WinSCP_release_4.1
. 2008-04-08 16:15:11.959 SSPI: acquired credentials for: BE02506@T99RXVNL
. 2008-04-08 16:15:11.959 Constructed service principal name 'host/rodenbach'
. 2008-04-08 16:15:11.959 GSSKEX disabled: No credentials are available in the security package

. 2008-04-08 16:15:11.959 Using SSH protocol version 2
. 2008-04-08 16:15:11.959 Handling network connect event on socket 1204 with error 0
. 2008-04-08 16:15:11.959 Waiting for the server to continue with the initialisation
. 2008-04-08 16:15:11.959 Looking for incoming data
. 2008-04-08 16:15:11.959 Looking for network events
....


======= The end of the log file =====================================
> 2008-04-08 16:18:05.989 7A,4F,77,4F,4F,EE,24,C7,C8,2D,F4,CD,CC,F5,BA,B1,71,A0,7B,53,5E,64,F4,F7,25,
> 2008-04-08 16:18:05.989 2E,08,79,AE,58,E6,14,28,FD,FD,7A,15,23,B7,55,DC,DC,D8,D5,16,5A,17,41,1B,7A,
> 2008-04-08 16:18:05.989 47,9A,FD,5C,BE,63,52,16,FB,83,25,EE,73,F5,FF,7B,6F,AF,5F,D0,D1,19,59,D0,D1,
> 2008-04-08 16:18:05.989 D8,59,5B,
. 2008-04-08 16:18:05.999 Sent 30757 bytes
. 2008-04-08 16:18:05.999 There are 32960 bytes remaining in the send buffer
. 2008-04-08 16:18:05.999 Looking for network events
. 2008-04-08 16:18:05.999 Detected network event
. 2008-04-08 16:18:05.999 Enumerating network events for socket 1204
. 2008-04-08 16:18:05.999 Enumerated 1 network events making 1 cumulative events for socket 1204
. 2008-04-08 16:18:05.999 Handling network read event on socket 1204 with error 0
. 2008-04-08 16:18:05.999 Received 28 bytes (0)
. 2008-04-08 16:18:05.999 Read 4 bytes (24 pending)
. 2008-04-08 16:18:05.999 Read 24 bytes (0 pending)
< 2008-04-08 16:18:05.999 Type: SSH_FXP_STATUS, Size: 24, Number: 33798
< 2008-04-08 16:18:05.999 65,00,00,84,06,00,00,00,00,00,00,00,07,53,75,63,63,65,73,73,00,00,00,00,
< 2008-04-08 16:18:05.999 Status/error code: 0
. 2008-04-08 16:18:05.999 There are 32960 bytes remaining in the send buffer, need to send at least another 192 bytes
. 2008-04-08 16:18:05.999 Looking for network events
. 2008-04-08 16:18:05.999 Detected network event
. 2008-04-08 16:18:05.999 Enumerating network events for socket 1204
. 2008-04-08 16:18:05.999 Enumerated 0 network events making 0 cumulative events for socket 1204
. 2008-04-08 16:18:05.999 There are 32960 bytes remaining in the send buffer
. 2008-04-08 16:18:05.999 There are 32960 bytes remaining in the send buffer, need to send at least another 192 bytes
. 2008-04-08 16:18:05.999 Looking for network events
. 2008-04-08 16:18:06.099 Timeout waiting for network events
. 2008-04-08 16:18:06.099 There are 32960 bytes remaining in the send buffer
. 2008-04-08 16:18:06.099 There are 32960 bytes remaining in the send buffer, need to send at least another 192 bytes
. 2008-04-08 16:18:06.099 Looking for network events
. 2008-04-08 16:18:06.199 Timeout waiting for network events
. 2008-04-08 16:18:06.199 There are 32960 bytes remaining in the send buffer
. 2008-04-08 16:18:06.199 There are 32960 bytes remaining in the send buffer, need to send at least another 192 bytes
. 2008-04-08 16:18:06.199 Looking for network events
. 2008-04-08 16:18:06.299 Timeout waiting for network events
. 2008-04-08 16:18:06.299 There are 32960 bytes remaining in the send buffer
. 2008-04-08 16:18:06.299 There are 32960 bytes remaining in the send buffer, need to send at least another 192 bytes
. 2008-04-08 16:18:06.299 Looking for network events
. 2008-04-08 16:18:06.400 Timeout waiting for network events
. 2008-04-08 16:18:06.400 There are 32960 bytes remaining in the send buffer
. 2008-04-08 16:18:06.400 There are 32960 bytes remaining in the send buffer, need to send at least another 192 bytes
. 2008-04-08 16:18:06.400 Looking for network events
. 2008-04-08 16:18:06.500 Timeout waiting for network events
. 2008-04-08 16:18:06.500 There are 32960 bytes remaining in the send buffer
. 2008-04-08 16:18:06.500 There are 32960 bytes remaining in the send buffer, need to send at least another 192 bytes
. 2008-04-08 16:18:06.500 Looking for network events
. 2008-04-08 16:18:06.530 Detected network event
. 2008-04-08 16:18:06.530 Enumerating network events for socket 1204
. 2008-04-08 16:18:06.530 Enumerated 1 network events making 1 cumulative events for socket 1204
. 2008-04-08 16:18:06.530 Handling network read event on socket 1204 with error 0
. 2008-04-08 16:18:06.530 Received 28 bytes (0)
. 2008-04-08 16:18:06.530 Read 4 bytes (24 pending)
. 2008-04-08 16:18:06.530 Read 24 bytes (0 pending)
< 2008-04-08 16:18:06.530 Type: SSH_FXP_STATUS, Size: 24, Number: 34054
< 2008-04-08 16:18:06.530 65,00,00,85,06,00,00,00,00,00,00,00,07,53,75,63,63,65,73,73,00,00,00,00,
< 2008-04-08 16:18:06.530 Status/error code: 0
. 2008-04-08 16:18:06.530 There are 32960 bytes remaining in the send buffer
. 2008-04-08 16:18:06.530 There are 32960 bytes remaining in the send buffer, need to send at least another 192 bytes
. 2008-04-08 16:18:06.530 Looking for network events
. 2008-04-08 16:18:06.540 Detected network event
. 2008-04-08 16:18:06.540 Enumerating network events for socket 1204
. 2008-04-08 16:18:06.540 Enumerated 1 network events making 1 cumulative events for socket 1204
. 2008-04-08 16:18:06.540 Handling network read event on socket 1204 with error 0
. 2008-04-08 16:18:06.540 There are 32960 bytes remaining in the send buffer
. 2008-04-08 16:18:06.540 There are 32960 bytes remaining in the send buffer, need to send at least another 192 bytes
. 2008-04-08 16:18:06.540 Looking for network events
. 2008-04-08 16:18:06.640 Timeout waiting for network events
. 2008-04-08 16:18:06.640 There are 32960 bytes remaining in the send buffer
. 2008-04-08 16:18:06.640 There are 32960 bytes remaining in the send buffer, need to send at least another 192 bytes
. 2008-04-08 16:18:06.640 Looking for network events
. 2008-04-08 16:18:06.740 Timeout waiting for network events
. 2008-04-08 16:18:06.740 There are 32960 bytes remaining in the send buffer
. 2008-04-08 16:18:06.740 There are 32960 bytes remaining in the send buffer, need to send at least another 192 bytes
. 2008-04-08 16:18:06.740 Looking for network events
. 2008-04-08 16:18:06.850 Timeout waiting for network events
. 2008-04-08 16:18:06.850 There are 32960 bytes remaining in the send buffer
. 2008-04-08 16:18:06.850 There are 32960 bytes remaining in the send buffer, need to send at least another 192 bytes
. 2008-04-08 16:18:06.850 Looking for network events
. 2008-04-08 16:18:06.950 Timeout waiting for network events
. 2008-04-08 16:18:06.950 There are 32960 bytes remaining in the send buffer
. 2008-04-08 16:18:06.950 There are 32960 bytes remaining in the send buffer, need to send at least another 192 bytes
. 2008-04-08 16:18:06.950 Looking for network events
. 2008-04-08 16:18:07.051 Timeout waiting for network events
. 2008-04-08 16:18:07.051 There are 32960 bytes remaining in the send buffer
. 2008-04-08 16:18:07.051 There are 32960 bytes remaining in the send buffer, need to send at least another 192 bytes
. 2008-04-08 16:18:07.051 Looking for network events
. 2008-04-08 16:18:07.151 Timeout waiting for network events
. 2008-04-08 16:18:07.151 There are 32960 bytes remaining in the send buffer
. 2008-04-08 16:18:07.151 There are 32960 bytes remaining in the send buffer, need to send at least another 192 bytes
. 2008-04-08 16:18:07.151 Looking for network events
. 2008-04-08 16:18:07.251 Timeout waiting for network events
. 2008-04-08 16:18:07.251 There are 32960 bytes remaining in the send buffer
. 2008-04-08 16:18:07.251 There are 32960 bytes remaining in the send buffer, need to send at least another 192 bytes
. 2008-04-08 16:18:07.251 Looking for network events
. 2008-04-08 16:18:07.351 Timeout waiting for network events
. 2008-04-08 16:18:07.351 There are 32960 bytes remaining in the send buffer
. 2008-04-08 16:18:07.351 There are 32960 bytes remaining in the send buffer, need to send at least another 192 bytes
. 2008-04-08 16:18:07.351 Looking for network events
. 2008-04-08 16:18:07.451 Timeout waiting for network events
. 2008-04-08 16:18:07.451 There are 32960 bytes remaining in the send buffer
. 2008-04-08 16:18:07.451 There are 32960 bytes remaining in the send buffer, need to send at least another 192 bytes
. 2008-04-08 16:18:07.451 Looking for network events
. 2008-04-08 16:18:07.591 Timeout waiting for network events
. 2008-04-08 16:18:07.591 There are 32960 bytes remaining in the send buffer
. 2008-04-08 16:18:07.591 There are 32960 bytes remaining in the send buffer, need to send at least another 192 bytes
. 2008-04-08 16:18:07.591 Looking for network events
. 2008-04-08 16:18:07.722 Timeout waiting for network events
. 2008-04-08 16:18:07.722 There are 32960 bytes remaining in the send buffer
. 2008-04-08 16:18:07.722 There are 32960 bytes remaining in the send buffer, need to send at least another 192 bytes
. 2008-04-08 16:18:07.722 Looking for network events
. 2008-04-08 16:18:07.822 Timeout waiting for network events
. 2008-04-08 16:18:07.822 There are 32960 bytes remaining in the send buffer
. 2008-04-08 16:18:07.822 There are 32960 bytes remaining in the send buffer, need to send at least another 192 bytes
. 2008-04-08 16:18:07.822 Looking for network events
....

Can you email me a complete log file?

Hi,

To be sure I have just sent the complete log file for a second time:
Because 6 days ago, I have also sent it - using a different e-mail account
and it might be lost.

Thanks in advance
Jan.

Hi,
I'm experiencing same issue with WinSCP hanging while transfering data over SFTP protocol. WinSCP version : 2009-08-18 13:14:18.219 WinSCP Version 4.1.9 (Build 416)
...
. 2009-08-18 13:14:19.109 Using SFTP protocol.
. 2009-08-18 13:14:19.109 Doing startup conversation with host.
> 2009-08-18 13:14:19.109 Type: SSH_FXP_INIT, Size: 5, Number: -1
> 2009-08-18 13:14:19.109 01,00,00,00,05,
. 2009-08-18 13:14:19.109 Sent 9 bytes
. 2009-08-18 13:14:19.109 There are 0 bytes remaining in the send buffer
. 2009-08-18 13:14:19.109 Looking for network events
. 2009-08-18 13:14:19.109 Timeout waiting for network events
. 2009-08-18 13:14:19.109 Waiting for another 4 bytes
. 2009-08-18 13:14:19.109 Looking for incoming data
. 2009-08-18 13:14:19.109 Looking for network events
. 2009-08-18 13:14:19.188 Detected network event
. 2009-08-18 13:14:19.188 Enumerating network events for socket 572
. 2009-08-18 13:14:19.188 Enumerated 1 network events making 1 cumulative events for socket 572
. 2009-08-18 13:14:19.188 Handling network read event on socket 572 with error 0
. 2009-08-18 13:14:19.188 Received 99 bytes (0)
. 2009-08-18 13:14:19.188 Read 4 bytes (95 pending)
. 2009-08-18 13:14:19.188 Read 95 bytes (0 pending)
< 2009-08-18 13:14:19.188 Type: SSH_FXP_VERSION, Size: 95, Number: -1
< 2009-08-18 13:14:19.188 02,00,00,00,03,00,00,00,18,70,6F,73,69,78,2D,72,65,6E,61,6D,65,40,6F,70,65,

...
< 2009-08-18 13:16:29.581 66,0D,0A,31,31,36,0D,0A,25,25,45,4F,46,0D,0A,
> 2009-08-18 13:16:29.581 Type: SSH_FXP_READ, Size: 25, Number: 179973
> 2009-08-18 13:16:29.581 05,00,02,BF,05,00,00,00,04,00,00,00,00,00,00,00,00,01,4B,3E,62,00,00,7F,F3,
. 2009-08-18 13:16:29.581 Sent 29 bytes
. 2009-08-18 13:16:29.581 There are 0 bytes remaining in the send buffer
. 2009-08-18 13:16:29.581 Looking for network events
. 2009-08-18 13:16:29.581 Timeout waiting for network events
. 2009-08-18 13:16:29.581 Waiting for another 4 bytes
. 2009-08-18 13:16:29.581 Looking for incoming data
. 2009-08-18 13:16:29.581 Looking for network events
. 2009-08-18 13:16:44.581 Timeout waiting for network events
. 2009-08-18 13:16:44.581 Waiting for data timed out, asking user what to do.
. 2009-08-18 13:16:44.581 Asking user:
. 2009-08-18 13:16:44.581 Host has not answered for 15 seconds.
. 2009-08-18 13:16:44.581
. 2009-08-18 13:16:44.581 Wait for another 15 seconds? ()
. 2009-08-18 13:16:44.643 Session upkeep
. 2009-08-18 13:16:44.643 Looking for network events
. 2009-08-18 13:16:44.643 Timeout waiting for network events
. 2009-08-18 13:16:45.097 Pooling for data in case they finally arrives
. 2009-08-18 13:16:45.097 Looking for network events
. 2009-08-18 13:16:45.097 Timeout waiting for network events
. 2009-08-18 13:16:45.112 Session upkeep
. 2009-08-18 13:16:45.112 Looking for network events
. 2009-08-18 13:16:45.112 Timeout waiting for network events
. 2009-08-18 13:16:45.597 Pooling for data in case they finally arrives
. 2009-08-18 13:16:45.597 Looking for network events
. 2009-08-18 13:16:45.597 Timeout waiting for network events
. 2009-08-18 13:16:45.612 Session upkeep
. 2009-08-18 13:16:45.612 Looking for network events
. 2009-08-18 13:16:45.612 Timeout waiting for network events
. 2009-08-18 13:16:46.097 Pooling for data in case they finally arrives
. 2009-08-18 13:16:46.097 Looking for network events
. 2009-08-18 13:16:46.097 Timeout waiting for network events
. 2009-08-18 13:16:46.112 Session upkeep
. 2009-08-18 13:16:46.112 Looking for network events
. 2009-08-18 13:16:46.112 Timeout waiting for network events
. 2009-08-18 13:16:46.597 Pooling for data in case they finally arrives
. 2009-08-18 13:16:46.597 Looking for network events
. 2009-08-18 13:16:46.597 Timeout waiting for network events
....

Skywalkie

Skywalkie wrote:

I'm experiencing same issue with WinSCP hanging while transfering data over SFTP protocol. WinSCP version : 2009-08-18 13:14:18.219 WinSCP Version 4.1.9 (Build 416)

Can you try the latest 4.2.3 beta release?

I have also experienced this issue. I have upgraded to the latest version (v4.2.3), and it's still an issue. It doesn't matter if I'm using the GUI or the commandline. When I use the GUI, the dialog box sits there for however long the timeout is set for (I've tried the default 15 second and also 30 seconds), then I get the error, but I also see that the file has been transferred. So, to sum it up the file transfer errors out, but the file seems to get transferred correctly - I can download the file back, do a file compare, and see no differences in the two files.

Below is some information from the log:

> 2009-08-31 09:40:04.665 2E,39,2E,39,2E,39,36,2E,33,2E,32,2E,32,22,0A,
. 2009-08-31 09:40:09.666 Sent 1644 bytes
. 2009-08-31 09:40:09.666 There are 0 bytes remaining in the send buffer
. 2009-08-31 09:40:09.666 Looking for network events
. 2009-08-31 09:40:09.666 Timeout waiting for network events
. 2009-08-31 09:40:13.120 Session upkeep
. 2009-08-31 09:40:13.120 Looking for network events
. 2009-08-31 09:40:13.120 Detected network event
. 2009-08-31 09:40:13.120 Enumerating network events for socket 544
. 2009-08-31 09:40:13.120 Enumerated 1 network events making 1 cumulative events for socket 544
. 2009-08-31 09:40:13.120 Handling network read event on socket 544 with error 0
. 2009-08-31 09:40:13.120 Received 53 bytes (0)
. 2009-08-31 09:40:13.120 Read 4 bytes (49 pending)
. 2009-08-31 09:40:13.120 Read 49 bytes (0 pending)
< 2009-08-31 09:40:13.120 Type: SSH_FXP_STATUS, Size: 49, Number: 2822
< 2009-08-31 09:40:13.120 65,00,00,0B,06,00,00,00,00,00,00,00,20,54,68,65,20,77,72,69,74,65,20,63,6F,
< 2009-08-31 09:40:13.120 6D,70,6C,65,74,65,64,20,73,75,63,63,65,73,73,66,75,6C,6C,79,00,00,00,00,
< 2009-08-31 09:40:13.120 Status/error code: 0
. 2009-08-31 09:40:15.168 Session upkeep
. 2009-08-31 09:40:15.168 Looking for network events
. 2009-08-31 09:40:15.168 Timeout waiting for network events
. 2009-08-31 09:40:15.668 Session upkeep
. 2009-08-31 09:40:15.668 Looking for network events
. 2009-08-31 09:40:15.668 Timeout waiting for network events
. 2009-08-31 09:40:16.152 Session upkeep
. 2009-08-31 09:40:16.152 Looking for network events
. 2009-08-31 09:40:16.152 Timeout waiting for network events
. 2009-08-31 09:40:16.668 Session upkeep
. 2009-08-31 09:40:16.668 Looking for network events
. 2009-08-31 09:40:16.668 Timeout waiting for network events
. 2009-08-31 09:40:17.168 Session upkeep
. 2009-08-31 09:40:17.168 Looking for network events
. 2009-08-31 09:40:17.168 Timeout waiting for network events
. 2009-08-31 09:40:17.700 Session upkeep
. 2009-08-31 09:40:17.700 Looking for network events
. 2009-08-31 09:40:17.700 Timeout waiting for network events
. 2009-08-31 09:40:18.184 Session upkeep
. 2009-08-31 09:40:18.184 Looking for network events
. 2009-08-31 09:40:18.184 Timeout waiting for network events
. 2009-08-31 09:40:18.716 Session upkeep
. 2009-08-31 09:40:18.716 Looking for network events
. 2009-08-31 09:40:18.716 Timeout waiting for network events

Then it just keeps the last 3 lines.

Can you post (or send me) a complete log file?

Here's the interesting part: the file I am trying to send is a text file, with an extension of .pay. If I add .txt to it, so that is is now .pay.txt, it works! Then, I went back and renamed the file to .pay, and used option transfer ascii, but that didn't help. I also tried it with extension .pa, but had the same results. Looks like there is something magical about the extension .txt.

rhugh wrote:

Here's the interesting part: the file I am trying to send is a text file, with an extension of .pay. If I add .txt to it, so that is is now .pay.txt, it works! Then, I went back and renamed the file to .pay, and used option transfer ascii, but that didn't help. I also tried it with extension .pa, but had the same results. Looks like there is something magical about the extension .txt.

So please send me a full log file for uploading the .txt using ascii mode and separate log file for uploading .pay using ascii mode. Thanks.