File Transfer Delay to complete after file sent ok received.

Hello, I am transferring files to my ftp server via a local network and I am noticing it is taking a very long time for files to complete, yet I see them transferring very fast via my FTP server program (GENE6 FTP Server)

What happens, at least with 15MB file, it takes about 2 seconds to receive the
[R] 226 File sent ok.
but the transfer bar does not indicate it has finished, it thinks its transferring still when the file has completed, it takes anywhere from 20 seconds for this to complete sending (it says 800k/s) and on a 500MB file it was taking many minutes.
the speed varies to gt the file received ok message. But it doesn't make sense, because the transfer has already completed when file sent ok is received, but the transfer bar in fxp shows its still going and at a much slower rate then what the ftp server reports.

R] 250-Begin
[R] type=file;size=15000000;modify=20130408003313; /admin/G/file.part34.rar
[R] 250 End.
[L] MLST file.part34.rar
[L] 550 File or directory not found.
[R] PASV
[R] 227 Entering Passive Mode (192,168,1,99,7,142)
[L] PORT 192,168,1,99,7,142
[L] 200 Port command successful.
[L] STOR file.part34.rar
[L] 150 Opening data connection for file.part34.rar
[R] RETR file.part34.rar
[R] 150 Data connection accepted from 192.168.1.99:443; transfer starting for /admin/G/file.part34.rar (15000000 bytes)
[R] 226 File sent ok.


Let me know if you have any questions. This is really slowing down what I am trying to copy over to the server.

Regards,
Vincent

Severity is higher then minimal ... Medium-High

What specific version/build of FlashFXP are you using?

Are both of the FTP servers running Gene6?

When you perform a site to site transfer FlashFXP has to wait until both servers have signaled that the transfer is complete.

The status log you provided only shows that the sending server has finished sending the file, which means the receiving server is still receiving the data.

The sending server returned
[R] 226 File sent ok.

Now FlashFXP is waiting for the receiving server to signal that it has received the file.
Which would look something like this
[L] 226 File received ok.

Once FlashFXP has received signals from both servers it then completes the transfer and shows the transfer complete status.

Perhaps the receiving server is performing additional processing on the file such as anti-virus scanning or maybe its not as fast as the server sending the file.

Hi,

I did some testing based on what you said and I think you have helped me figure out what the delay is. Both sending and receiving servers are the same server (using Gene6FTP). I am restoring data that I lost on my NAS. So Source is a folder on the FTP server linked to a standalone hdd, and target is a network share to a NAS. Anyway, I am doing this because the NAS I run it through an sfv file checker. and it seems that's what's delaying the transfer. More details below:


15/07/13 10:23:29, 650, 192.168.1.99, temp, 250-Begin
15/07/13 10:23:29, 650, 192.168.1.99, temp, type=file;size=15000000;modify=20110425084310; /admin/G/recover/file.r14
15/07/13 10:23:29, 650, 192.168.1.99, temp, 250 End.
15/07/13 10:23:29, 649, 192.168.1.99, temp, MLST file.r14
15/07/13 10:23:29, 649, 192.168.1.99, temp, 550 File or directory not found.
15/07/13 10:23:29, 650, 192.168.1.99, temp, PASV
15/07/13 10:23:29, 650, 192.168.1.99, temp, 227 Entering Passive Mode (192,168,1,99,5,125)
15/07/13 10:23:29, 649, 192.168.1.99, temp, PORT 192,168,1,99,5,125
15/07/13 10:23:29, 649, 192.168.1.99, temp, 200 Port command successful.
15/07/13 10:23:29, 649, 192.168.1.99, temp, STOR file.r14
15/07/13 10:23:29, 649, 192.168.1.99, temp, asked to upload '/files/file.r14' -> '\\N7700\incoming\incoming\incoming\files\file.r14 ' resuming at 0 --> Access allowed.
15/07/13 10:23:29, 649, 192.168.1.99, temp, 150 Opening data connection for file.r14
15/07/13 10:23:29, 650, 192.168.1.99, temp, RETR file.r14
15/07/13 10:23:29, 650, 192.168.1.99, temp, asked to download '/admin/G/recover/file.r14' -> 'G:\recover\file.r14' from 0 --> Access allowed.
15/07/13 10:23:29, 650, 192.168.1.99, temp, 150 Data connection accepted from 192.168.1.99:443; transfer starting for /admin/G/recover/file.r14 (15000000 bytes)
15/07/13 10:23:30, 650, 192.168.1.99, temp, finished downloading '/admin/G/recover/file.r14' -> 'G:\recover\file.r14' from 0 to 15000000 (00:00:01 - 14648.438 KBytes/s).
15/07/13 10:23:30, 650, 192.168.1.99, temp, 226 File sent ok.
15/07/13 10:26:14, 649, 192.168.1.99, temp, 226-
15/07/13 10:26:14, 649, 192.168.1.99, temp, .--------------------------------------------------------------------.
15/07/13 10:26:14, 649, 192.168.1.99, temp, | + File: ok! |
15/07/13 10:26:14, 649, 192.168.1.99, temp, |-=[T O P - U S E R S]=-------------. |
15/07/13 10:26:14, 649, 192.168.1.99, temp, | `-----==-------------===--------|
15/07/13 10:26:14, 649, 192.168.1.99, temp, | 1 temp@OpsNoBan 214.6M 15F 30.6% 11565KBs |
15/07/13 10:26:14, 649, 192.168.1.99, temp, |- - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - |
15/07/13 10:26:14, 649, 192.168.1.99, temp, | 1 Total 214.6M 15F 30.6% 11565KBs |
15/07/13 10:26:14, 649, 192.168.1.99, temp, | |
15/07/13 10:26:14, 649, 192.168.1.99, temp, |-=[T O P - G R O U P]=-------------. |
15/07/13 10:26:14, 649, 192.168.1.99, temp, | `-----==-------------===--------|
15/07/13 10:26:14, 649, 192.168.1.99, temp, | 1 OpsNoBan 214.6M 15F 30.6% 11565KBs |
15/07/13 10:26:14, 649, 192.168.1.99, temp, |- - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - |
15/07/13 10:26:14, 649, 192.168.1.99, temp, | 1 Total 214.6M 15F 30.6% 11565KBs |
15/07/13 10:26:14, 649, 192.168.1.99, temp, | |
15/07/13 10:26:14, 649, 192.168.1.99, temp, `--------------------------------------------------------[ 15/49 ]---´
15/07/13 10:26:14, 649, 192.168.1.99, temp, 226 File received ok.
15/07/13 10:26:14, 649, 192.168.1.99, temp, MFMT 20110425084310 /files/file.r14
15/07/13 10:26:14, 649, 192.168.1.99, temp, 213 Modify=20110425084310; /files/file.r14


When I disable the scripts, this is what I expect to see

[R] PORT 192,168,1,99,12,74
[R] 200 Port command successful.
[R] STOR file.r44
[R] 150 Opening data connection for file.r44
[L] RETR file.r44
[L] 150 Data connection accepted from 192.168.1.99:443; transfer starting for /admin/G/recover/file.r44 (15000000 bytes)
[L] 226 File sent ok.
[R] 226 File received ok.
FXP: file.r44 14.31 MB in 2 seconds (8.66 MB/s)

I did realize I had the script enabled for both the entire server and the user in question. This seems to also slow things down, and when I only have it enabled one of the two, it goes a little quicker,,, still not 2 seconds. Guess that's the cost of living with this script.... Will have to try to figure out how to speed it up (didn't write the script myself).

What's weird is the sfv checker acknowledges that it transferred very quick as its output shows over 10MB/s. Must be in how it keeps track of what files are missing and such...

I think this can be closed, unless you have any other thoughts.