Topic "WinSCP fails to resume file upload over FTP in active mode"

Author Message
dma_k
[View user's profile]

Joined: 2010-04-26
Posts: 13
Dear WinSCP community,

I observe the malfunctioning of WinSCP v5.9.4 (b7333) when uploading the file over FTP to remote server in active mode. In my experiment I did the following:

  • I have started the upload of file to FTP server.
  • At about 80% I have disconnected the client's WiFi. After 10s waiting WinSCP shows the dialog with 5s auto-reconnection option. [OK so far]
  • After WinSCP connects to remote server and tries to resume the upload. However (I think) it fails to manage the control connection properly and "thinks" that connection is aborted, and keeps on reconnecting in endless loop. [WRONG] Also the progress indicator is reset to zero.

Log is as following:
Code:
. 2017-04-15 17:13:42.320 File: 'D:\aaa.psd' [2011-10-03T07:04:59.653Z] [119967267]
. 2017-04-15 17:13:42.320 Copying "D:\aaa.psd" to remote directory started.
. 2017-04-15 17:13:42.320 Binary transfer mode selected.
. 2017-04-15 17:13:42.320 Starting upload of D:\aaa.psd
> 2017-04-15 17:13:42.320 TYPE I
< 2017-04-15 17:13:42.330 200 Type set to I
> 2017-04-15 17:13:42.330 PORT 10,0,0,5,197,32
< 2017-04-15 17:13:42.330 200 PORT command successful
> 2017-04-15 17:13:42.330 STOR aaa.psd
< 2017-04-15 17:13:42.330 150 Opening BINARY mode data connection for aaa.psd
. 2017-04-15 17:13:43.367 Increasing send buffer from 262144 to 524288
. 2017-04-15 17:13:53.460 Session upkeep
...
. 2017-04-15 17:14:43.674 Session upkeep
. 2017-04-15 17:15:00.731 Timeout detected. (data connection)
. 2017-04-15 17:15:00.731 Copying files to remote side failed.
. 2017-04-15 17:15:00.731 Got reply 1004 to the command 4
. 2017-04-15 17:15:00.731 Connection was lost, asking what to do.
. 2017-04-15 17:15:00.731 Asking user:
. 2017-04-15 17:15:00.731 Lost connection. ("Timeout detected. (data connection)","Copying files to remote side failed.")

Retry after 5 seconds has started:
Code:
. 2017-04-15 17:15:05.819 Connecting to 10.0.0.100 ...
. 2017-04-15 17:15:05.829 Connected with 10.0.0.100. Waiting for welcome message...
< 2017-04-15 17:15:05.849 220 FTP server
> 2017-04-15 17:15:05.849 USER test
< 2017-04-15 17:15:05.849 331 Password required for test
. 2017-04-15 17:15:05.849 Using remembered password.
> 2017-04-15 17:15:05.849 PASS *******
< 2017-04-15 17:15:05.977 230 User test logged in
> 2017-04-15 17:15:05.977 SYST
< 2017-04-15 17:15:05.977 215 UNIX Type: L8
> 2017-04-15 17:15:05.977 FEAT
< 2017-04-15 17:15:05.987 211-Features:
< 2017-04-15 17:15:05.997  SITE MKDIR
< 2017-04-15 17:15:05.997  REST STREAM
< 2017-04-15 17:15:05.997  UTF8
< 2017-04-15 17:15:05.997  MDTM
< 2017-04-15 17:15:05.997  SITE COPY
...
< 2017-04-15 17:15:05.997 211 End
> 2017-04-15 17:15:05.997 OPTS UTF8 ON
< 2017-04-15 17:15:05.997 200 UTF8 set to on
. 2017-04-15 17:15:05.997 Connected
. 2017-04-15 17:15:05.997 Got reply 1 to the command 1
. 2017-04-15 17:15:05.997 Doing startup conversation with host.
> 2017-04-15 17:15:05.997 PWD
< 2017-04-15 17:15:06.007 257 "/home/test" is the current directory
. 2017-04-15 17:15:06.007 Got reply 1 to the command 16
. 2017-04-15 17:15:06.007 Changing directory to "/home/test".
> 2017-04-15 17:15:06.007 CWD /home/test
< 2017-04-15 17:15:06.007 250 CWD command successful
. 2017-04-15 17:15:06.007 Got reply 1 to the command 16
. 2017-04-15 17:15:06.007 Getting current directory name.
> 2017-04-15 17:15:06.007 PWD
< 2017-04-15 17:15:06.007 257 "/home/test" is the current directory
. 2017-04-15 17:15:06.007 Got reply 1 to the command 16
. 2017-04-15 17:15:06.007 Startup conversation with host finished.
. 2017-04-15 17:15:06.017 File: 'D:\aaa.psd' [2011-10-03T07:04:59.653Z] [119967267]
. 2017-04-15 17:15:06.017 Copying "D:\aaa.psd" to remote directory started.
. 2017-04-15 17:15:06.017 Binary transfer mode selected.
. 2017-04-15 17:15:06.017 Starting upload of D:\aaa.psd
> 2017-04-15 17:15:06.017 TYPE A
< 2017-04-15 17:15:06.017 200 Type set to A
> 2017-04-15 17:15:06.017 PORT 10,0,0,5,200,0
< 2017-04-15 17:15:06.017 200 PORT command successful
> 2017-04-15 17:15:06.017 MLSD
< 2017-04-15 17:15:06.027 150 Opening ASCII mode data connection for MLSD
. 2017-04-15 17:15:06.027 Data connection closed
. 2017-04-15 17:15:06.027 modify=20170415151340;perm=flcdmpe;type=cdir;unique=2AU2925AE;UNIX.group=100;UNIX.mode=0750;UNIX.owner=1000; .
. 2017-04-15 17:15:06.027 modify=20170415140003;perm=flcdmpe;type=pdir;unique=2AU2210;UNIX.group=100;UNIX.mode=0755;UNIX.owner=1000; ..
. 2017-04-15 17:15:06.027 modify=20170415151444;perm=adfrw;size=96656350;type=file;unique=2AU2A5BD6;UNIX.group=100;UNIX.mode=0644;UNIX.owner=1000; aaa.psd
< 2017-04-15 17:15:06.027 226 Transfer complete
> 2017-04-15 17:15:06.027 TYPE I
< 2017-04-15 17:15:06.027 200 Type set to I
> 2017-04-15 17:15:06.027 PORT 10,0,0,5,200,1
< 2017-04-15 17:15:06.027 200 PORT command successful
> 2017-04-15 17:15:06.027 REST 96656350
< 2017-04-15 17:15:06.027 350 Restarting at 96656350. Send STORE or RETRIEVE to initiate transfer
> 2017-04-15 17:15:06.027 STOR aaa.psd
< 2017-04-15 17:15:06.037 150 Opening BINARY mode data connection for aaa.psd
. 2017-04-15 17:15:21.016 Timeout detected. (control connection)
. 2017-04-15 17:15:21.016 Copying files to remote side failed.
. 2017-04-15 17:15:21.016 Got reply 1004 to the command 4
. 2017-04-15 17:15:21.016 Connection was lost, asking what to do.
. 2017-04-15 17:15:21.016 Asking user:
. 2017-04-15 17:15:21.016 Lost connection. ("Timeout detected. (control connection)","Copying files to remote side failed.")
. 2017-04-15 17:15:27.433 Connecting to 10.0.0.100 ...
. 2017-04-15 17:15:27.433 Connected with 10.0.0.100. Waiting for welcome message...
< 2017-04-15 17:15:27.433 220 FTP server
> 2017-04-15 17:15:27.433 USER test
< 2017-04-15 17:15:27.433 331 Password required for test
. 2017-04-15 17:15:27.433 Using remembered password.
> 2017-04-15 17:15:27.433 PASS *******
< 2017-04-15 17:15:27.534 230 User test logged in
> 2017-04-15 17:15:27.534 SYST
< 2017-04-15 17:15:27.534 215 UNIX Type: L8
> 2017-04-15 17:15:27.534 FEAT
< 2017-04-15 17:15:27.544 211-Features:
< 2017-04-15 17:15:05.997  SITE MKDIR
< 2017-04-15 17:15:05.997  REST STREAM
< 2017-04-15 17:15:05.997  UTF8
< 2017-04-15 17:15:05.997  MDTM
< 2017-04-15 17:15:05.997  SITE COPY
...
< 2017-04-15 17:15:27.564 211 End
> 2017-04-15 17:15:27.564 OPTS UTF8 ON
< 2017-04-15 17:15:27.564 200 UTF8 set to on
. 2017-04-15 17:15:27.564 Connected
. 2017-04-15 17:15:27.564 Got reply 1 to the command 1
. 2017-04-15 17:15:27.574 Doing startup conversation with host.
> 2017-04-15 17:15:27.574 PWD
< 2017-04-15 17:15:27.584 257 "/home/test" is the current directory
. 2017-04-15 17:15:27.584 Got reply 1 to the command 16
. 2017-04-15 17:15:27.584 Changing directory to "/home/test".
> 2017-04-15 17:15:27.584 CWD /home/test
< 2017-04-15 17:15:27.584 250 CWD command successful
. 2017-04-15 17:15:27.584 Got reply 1 to the command 16
. 2017-04-15 17:15:27.584 Getting current directory name.
> 2017-04-15 17:15:27.584 PWD
< 2017-04-15 17:15:27.584 257 "/home/test" is the current directory
. 2017-04-15 17:15:27.584 Got reply 1 to the command 16
. 2017-04-15 17:15:27.584 Startup conversation with host finished.
. 2017-04-15 17:15:27.604 File: 'D:\aaa.psd' [2011-10-03T07:04:59.653Z] [119967267]
. 2017-04-15 17:15:27.604 Copying "D:\aaa.psd" to remote directory started.
. 2017-04-15 17:15:27.604 Binary transfer mode selected.
. 2017-04-15 17:15:27.604 Starting upload of D:\aaa.psd
> 2017-04-15 17:15:27.604 TYPE A
< 2017-04-15 17:15:27.614 200 Type set to A
> 2017-04-15 17:15:27.614 PORT 10,0,0,5,200,33
< 2017-04-15 17:15:27.614 200 PORT command successful
> 2017-04-15 17:15:27.614 MLSD
< 2017-04-15 17:15:27.614 150 Opening ASCII mode data connection for MLSD
. 2017-04-15 17:15:27.624 Data connection closed
. 2017-04-15 17:15:27.624 modify=20170415151340;perm=flcdmpe;type=cdir;unique=2AU2925AE;UNIX.group=100;UNIX.mode=0750;UNIX.owner=1000; .
. 2017-04-15 17:15:27.624 modify=20170415140003;perm=flcdmpe;type=pdir;unique=2AU2210;UNIX.group=100;UNIX.mode=0755;UNIX.owner=1000; ..
. 2017-04-15 17:15:27.624 modify=20170415151444;perm=adfrw;size=96656350;type=file;unique=2AU2A5BD6;UNIX.group=100;UNIX.mode=0644;UNIX.owner=1000; aaa.psd
< 2017-04-15 17:15:27.624 226 Transfer complete
> 2017-04-15 17:15:27.624 TYPE I
< 2017-04-15 17:15:27.624 200 Type set to I
> 2017-04-15 17:15:27.624 PORT 10,0,0,5,200,34
< 2017-04-15 17:15:27.624 200 PORT command successful
> 2017-04-15 17:15:27.624 REST 96656350
< 2017-04-15 17:15:27.624 350 Restarting at 96656350. Send STORE or RETRIEVE to initiate transfer
> 2017-04-15 17:15:27.624 STOR aaa.psd
< 2017-04-15 17:15:27.634 150 Opening BINARY mode data connection for aaa.psd
. 2017-04-15 17:15:42.309 Timeout detected. (control connection)
. 2017-04-15 17:15:42.309 Copying files to remote side failed.
. 2017-04-15 17:15:42.309 Got reply 1004 to the command 4
. 2017-04-15 17:15:42.309 Connection was lost, asking what to do.
. 2017-04-15 17:15:42.309 Asking user:
. 2017-04-15 17:15:42.309 Lost connection. ("Timeout detected. (control connection)","Copying files to remote side failed.")
. 2017-04-15 17:15:47.412 Connecting to 10.0.0.100 ...
. 2017-04-15 17:15:47.412 Connected with 10.0.0.100. Waiting for welcome message...


The problem does not happen in passive mode. Another client (FileZilla) manages the situation in active mode just fine.

Last edited by dma_k on 2017-04-18 21:11; edited 1 time in total
martin◆
[View user's profile]
Site Admin
Joined: 2002-12-10
Posts: 26889
Location: Prague, Czechia
Thanks for your report. I cannot reproduce the problem.
I have sent you an email with a debug version of WinSCP to the address you have used to register on this forum.
martin◆
[View user's profile]
Site Admin
Joined: 2002-12-10
Posts: 26889
Location: Prague, Czechia
This issue has been added to the tracker:
https://winscp.net/tracker/show_bug.cgi?id=1520
Advertisements

You can post new topics in this forum

Search

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