Large file copy - file already exists

Come here to discuss FileZilla and FTP in general

Moderator: Project members

Post Reply
Message
Author
treb0r
500 Command not understood
Posts: 3
Joined: 2020-10-30 15:02
First name: Robert
Last name: Smith

Large file copy - file already exists

#1 Post by treb0r » 2020-10-30 16:04

Hi - I hope someone can help me here. I'm trying to transfer a 500 GB DB.bak file over the LAN from a virtual server to a USB 3.0 iStorage device attached to a physical server - both on the same VLAN, AV and F/W disabled
I've been trying various options over the last 3 weeks but need a reliable and fast solution so I installed FZ client v3.49.1 x64 onto the VM and FZ server 0.9.60 beta onto the server.
My first transfer attempt was looking good, bouncing off the 1Gb/s NIC limit until 40GB in when the transfer timed out. I've seen this before as the destination server seems to cache about 5GB of data in RAM whilst writing to SSD and trying to flush the cache. It gets in a muddle, stops receiving data then the source times out.
So - I set a receive limit of 75000 MiB/s in FZ server and it was again looking good. The file transfer estimate looked spot on - 2.5 hours averaging 57MB/s which I'm happy with, then at the last minute it popped up a box saying duplicate file exists. When I checked the file size at destination it was only 261 GB. So, I'm wondering what happened to the other 239 GB of data as it told me the transfer was 99% complete?
I saw a REST message in the log when the message popped up which I believe is resume transfer? I would include the logs but I just downloaded and installed v3.51.0 x64 and lost them all - now attempting another upload...

treb0r
500 Command not understood
Posts: 3
Joined: 2020-10-30 15:02
First name: Robert
Last name: Smith

Re: Large file copy - file already exists

#2 Post by treb0r » 2020-10-30 16:22

Doh! logs are on the server not client! Just wondering if the beta version is stable? I can't see an archive of previous versions and the next newest copy we have is v0.9.52.0 from 2015.

000006)30/10/2020 12:03:25 - tppice (192.168.32.11)> TYPE I
(000006)30/10/2020 12:03:25 - tppice (192.168.32.11)> 200 Type set to I
(000006)30/10/2020 12:03:25 - tppice (192.168.32.11)> PASV
(000006)30/10/2020 12:03:25 - tppice (192.168.32.11)> 227 Entering Passive Mode (172,16,100,18,247,216)
(000006)30/10/2020 12:03:25 - tppice (192.168.32.11)> STOR ice.bak
(000006)30/10/2020 12:03:25 - tppice (192.168.32.11)> 150 Opening data channel for file upload to server of "/ice.bak"
(000007)30/10/2020 12:46:58 - (not logged in) (192.168.34.85)> Connected on port 21, sending welcome message...
(000007)30/10/2020 12:46:58 - (not logged in) (192.168.34.85)> 220-FileZilla Server 0.9.60 beta
(000007)30/10/2020 12:46:58 - (not logged in) (192.168.34.85)> 220-written by Tim Kosse (tim.kosse@filezilla-project.org)
(000007)30/10/2020 12:46:58 - (not logged in) (192.168.34.85)> 220 Please visit https://filezilla-project.org/
(000007)30/10/2020 12:46:58 - (not logged in) (192.168.34.85)> disconnected.
(000008)30/10/2020 14:27:26 - (not logged in) (192.168.32.11)> Connected on port 21, sending welcome message...
(000008)30/10/2020 14:27:26 - (not logged in) (192.168.32.11)> 220-FileZilla Server 0.9.60 beta
(000008)30/10/2020 14:27:26 - (not logged in) (192.168.32.11)> 220-written by Tim Kosse (tim.kosse@filezilla-project.org)
(000008)30/10/2020 14:27:26 - (not logged in) (192.168.32.11)> 220 Please visit https://filezilla-project.org/
(000008)30/10/2020 14:27:26 - (not logged in) (192.168.32.11)> AUTH TLS
(000008)30/10/2020 14:27:26 - (not logged in) (192.168.32.11)> 502 Explicit TLS authentication not allowed
(000008)30/10/2020 14:27:26 - (not logged in) (192.168.32.11)> AUTH SSL
(000008)30/10/2020 14:27:26 - (not logged in) (192.168.32.11)> 502 Explicit TLS authentication not allowed
(000008)30/10/2020 14:27:26 - (not logged in) (192.168.32.11)> USER tppice
(000008)30/10/2020 14:27:26 - (not logged in) (192.168.32.11)> 331 Password required for tppice
(000008)30/10/2020 14:27:26 - (not logged in) (192.168.32.11)> PASS ************
(000008)30/10/2020 14:27:26 - tppice (192.168.32.11)> 230 Logged on
(000008)30/10/2020 14:27:26 - tppice (192.168.32.11)> CWD /
(000008)30/10/2020 14:27:26 - tppice (192.168.32.11)> 250 CWD successful. "/" is current directory.
(000008)30/10/2020 14:27:26 - tppice (192.168.32.11)> TYPE I
(000008)30/10/2020 14:27:26 - tppice (192.168.32.11)> 200 Type set to I
(000008)30/10/2020 14:27:26 - tppice (192.168.32.11)> PASV
(000008)30/10/2020 14:27:26 - tppice (192.168.32.11)> 227 Entering Passive Mode (172,16,100,18,248,233)
(000008)30/10/2020 14:27:26 - tppice (192.168.32.11)> MLSD
(000008)30/10/2020 14:27:26 - tppice (192.168.32.11)> 150 Opening data channel for directory listing of "/"
(000008)30/10/2020 14:27:26 - tppice (192.168.32.11)> 226 Successfully transferred "/"
(000008)30/10/2020 14:27:26 - tppice (192.168.32.11)> PASV
(000008)30/10/2020 14:27:26 - tppice (192.168.32.11)> 227 Entering Passive Mode (172,16,100,18,211,53)
(000008)30/10/2020 14:27:26 - tppice (192.168.32.11)> REST 268488720392
(000008)30/10/2020 14:27:26 - tppice (192.168.32.11)> 350 Rest supported. Restarting at 268488720392
(000008)30/10/2020 14:27:26 - tppice (192.168.32.11)> STOR ice.bak
(000008)30/10/2020 14:27:26 - tppice (192.168.32.11)> 150 Opening data channel for file upload to server of "/ice.bak", restarting at offset 268488720392
(000008)30/10/2020 14:27:26 - tppice (192.168.32.11)> 550 Could not open file for writing.
(000008)30/10/2020 14:27:26 - tppice (192.168.32.11)> PASV
(000008)30/10/2020 14:27:26 - tppice (192.168.32.11)> 227 Entering Passive Mode (172,16,100,18,214,255)
(000008)30/10/2020 14:27:26 - tppice (192.168.32.11)> REST 0
(000008)30/10/2020 14:27:26 - tppice (192.168.32.11)> 350 Rest supported. Restarting at 0
(000008)30/10/2020 14:27:26 - tppice (192.168.32.11)> MLSD
(000008)30/10/2020 14:27:26 - tppice (192.168.32.11)> 150 Opening data channel for directory listing of "/"
(000008)30/10/2020 14:27:26 - tppice (192.168.32.11)> 226 Successfully transferred "/"
(000008)30/10/2020 14:28:30 - tppice (192.168.32.11)> PASV
(000008)30/10/2020 14:28:30 - tppice (192.168.32.11)> 227 Entering Passive Mode (172,16,100,18,247,178)
(000008)30/10/2020 14:28:30 - tppice (192.168.32.11)> STOR ice.bak
(000008)30/10/2020 14:28:30 - tppice (192.168.32.11)> 150 Opening data channel for file upload to server of "/ice.bak"
(000008)30/10/2020 14:28:30 - tppice (192.168.32.11)> 550 Could not open file for writing.
(000008)30/10/2020 14:28:30 - tppice (192.168.32.11)> PASV
(000008)30/10/2020 14:28:30 - tppice (192.168.32.11)> 227 Entering Passive Mode (172,16,100,18,233,60)
(000008)30/10/2020 14:28:30 - tppice (192.168.32.11)> MLSD
(000008)30/10/2020 14:28:30 - tppice (192.168.32.11)> 150 Opening data channel for directory listing of "/"
(000008)30/10/2020 14:28:30 - tppice (192.168.32.11)> 226 Successfully transferred "/"
(000008)30/10/2020 14:28:35 - tppice (192.168.32.11)> PASV
(000008)30/10/2020 14:28:35 - tppice (192.168.32.11)> 227 Entering Passive Mode (172,16,100,18,220,148)
(000008)30/10/2020 14:28:35 - tppice (192.168.32.11)> STOR ice.bak
(000008)30/10/2020 14:28:35 - tppice (192.168.32.11)> 150 Opening data channel for file upload to server of "/ice.bak"
(000008)30/10/2020 14:28:35 - tppice (192.168.32.11)> 550 Could not open file for writing.
(000008)30/10/2020 14:28:35 - tppice (192.168.32.11)> PASV
(000008)30/10/2020 14:28:35 - tppice (192.168.32.11)> 227 Entering Passive Mode (172,16,100,18,255,72)
(000008)30/10/2020 14:28:35 - tppice (192.168.32.11)> MLSD
(000008)30/10/2020 14:28:35 - tppice (192.168.32.11)> 150 Opening data channel for directory listing of "/"
(000008)30/10/2020 14:28:35 - tppice (192.168.32.11)> 226 Successfully transferred "/"
(000008)30/10/2020 14:29:35 - tppice (192.168.32.11)> disconnected.
(000006)30/10/2020 14:29:46 - tppice (192.168.32.11)> disconnected.
(000006)30/10/2020 14:29:46 - tppice (192.168.32.11)> 226 Successfully transferred "/ice.bak"
(000006)30/10/2020 14:29:46 - tppice (192.168.32.11)> could not send reply, disconnected.
(000009)30/10/2020 14:35:11 - (not logged in) (192.168.32.11)> Connected on port 21, sending welcome message...
(000009)30/10/2020 14:35:11 - (not logged in) (192.168.32.11)> 220-FileZilla Server 0.9.60 beta
(000009)30/10/2020 14:35:11 - (not logged in) (192.168.32.11)> 220-written by Tim Kosse (tim.kosse@filezilla-project.org)
(000009)30/10/2020 14:35:11 - (not logged in) (192.168.32.11)> 220 Please visit https://filezilla-project.org/
(000009)30/10/2020 14:35:11 - (not logged in) (192.168.32.11)> AUTH TLS
(000009)30/10/2020 14:35:11 - (not logged in) (192.168.32.11)> 502 Explicit TLS authentication not allowed
(000009)30/10/2020 14:35:11 - (not logged in) (192.168.32.11)> AUTH SSL
(000009)30/10/2020 14:35:11 - (not logged in) (192.168.32.11)> 502 Explicit TLS authentication not allowed
(000009)30/10/2020 14:35:11 - (not logged in) (192.168.32.11)> USER tppice
(000009)30/10/2020 14:35:11 - (not logged in) (192.168.32.11)> 331 Password required for tppice
(000009)30/10/2020 14:35:11 - (not logged in) (192.168.32.11)> PASS ************
(000009)30/10/2020 14:35:11 - tppice (192.168.32.11)> 230 Logged on
(000009)30/10/2020 14:35:11 - tppice (192.168.32.11)> CWD /
(000009)30/10/2020 14:35:11 - tppice (192.168.32.11)> 250 CWD successful. "/" is current directory.
(000009)30/10/2020 14:35:11 - tppice (192.168.32.11)> TYPE I
(000009)30/10/2020 14:35:11 - tppice (192.168.32.11)> 200 Type set to I
(000009)30/10/2020 14:35:11 - tppice (192.168.32.11)> PASV
(000009)30/10/2020 14:35:11 - tppice (192.168.32.11)> 227 Entering Passive Mode (172,16,100,18,208,75)
(000009)30/10/2020 14:35:11 - tppice (192.168.32.11)> MLSD
(000009)30/10/2020 14:35:11 - tppice (192.168.32.11)> 150 Opening data channel for directory listing of "/"
(000009)30/10/2020 14:35:11 - tppice (192.168.32.11)> 226 Successfully transferred "/"
(000009)30/10/2020 14:35:58 - tppice (192.168.32.11)> DELE ice.bak
(000009)30/10/2020 14:36:01 - tppice (192.168.32.11)> 250 File deleted successfully
(000010)30/10/2020 14:36:08 - (not logged in) (192.168.32.11)> Connected on port 21, sending welcome message...
(000010)30/10/2020 14:36:08 - (not logged in) (192.168.32.11)> 220-FileZilla Server 0.9.60 beta
(000010)30/10/2020 14:36:08 - (not logged in) (192.168.32.11)> 220-written by Tim Kosse (tim.kosse@filezilla-project.org)
(000010)30/10/2020 14:36:08 - (not logged in) (192.168.32.11)> 220 Please visit https://filezilla-project.org/
(000010)30/10/2020 14:36:08 - (not logged in) (192.168.32.11)> AUTH TLS
(000010)30/10/2020 14:36:08 - (not logged in) (192.168.32.11)> 502 Explicit TLS authentication not allowed
(000010)30/10/2020 14:36:08 - (not logged in) (192.168.32.11)> AUTH SSL
(000010)30/10/2020 14:36:08 - (not logged in) (192.168.32.11)> 502 Explicit TLS authentication not allowed
(000010)30/10/2020 14:36:08 - (not logged in) (192.168.32.11)> USER tppice
(000010)30/10/2020 14:36:08 - (not logged in) (192.168.32.11)> 331 Password required for tppice
(000010)30/10/2020 14:36:08 - (not logged in) (192.168.32.11)> PASS ************
(000010)30/10/2020 14:36:08 - tppice (192.168.32.11)> 230 Logged on
(000010)30/10/2020 14:36:08 - tppice (192.168.32.11)> CWD /
(000010)30/10/2020 14:36:08 - tppice (192.168.32.11)> 250 CWD successful. "/" is current directory.
(000010)30/10/2020 14:36:08 - tppice (192.168.32.11)> TYPE I
(000010)30/10/2020 14:36:08 - tppice (192.168.32.11)> 200 Type set to I
(000010)30/10/2020 14:36:08 - tppice (192.168.32.11)> PASV
(000010)30/10/2020 14:36:08 - tppice (192.168.32.11)> 227 Entering Passive Mode (172,16,100,18,213,241)
(000010)30/10/2020 14:36:08 - tppice (192.168.32.11)> STOR ice.bak
(000010)30/10/2020 14:36:08 - tppice (192.168.32.11)> 150 Opening data channel for file upload to server of "/ice.bak"
(000009)30/10/2020 14:36:31 - tppice (192.168.32.11)> PASV
(000009)30/10/2020 14:36:31 - tppice (192.168.32.11)> 227 Entering Passive Mode (172,16,100,18,222,2)
(000009)30/10/2020 14:36:31 - tppice (192.168.32.11)> MLSD
(000009)30/10/2020 14:36:31 - tppice (192.168.32.11)> 150 Opening data channel for directory listing of "/"
(000009)30/10/2020 14:36:31 - tppice (192.168.32.11)> 226 Successfully transferred "/"
(000009)30/10/2020 14:36:35 - tppice (192.168.32.11)> PASV
(000009)30/10/2020 14:36:35 - tppice (192.168.32.11)> 227 Entering Passive Mode (172,16,100,18,208,145)
(000009)30/10/2020 14:36:35 - tppice (192.168.32.11)> MLSD
(000009)30/10/2020 14:36:35 - tppice (192.168.32.11)> 150 Opening data channel for directory listing of "/"
(000009)30/10/2020 14:36:35 - tppice (192.168.32.11)> 226 Successfully transferred "/"
(000009)30/10/2020 14:36:44 - tppice (192.168.32.11)> PASV
(000009)30/10/2020 14:36:44 - tppice (192.168.32.11)> 227 Entering Passive Mode (172,16,100,18,205,128)
(000009)30/10/2020 14:36:44 - tppice (192.168.32.11)> MLSD
(000009)30/10/2020 14:36:44 - tppice (192.168.32.11)> 150 Opening data channel for directory listing of "/"
(000009)30/10/2020 14:36:44 - tppice (192.168.32.11)> 226 Successfully transferred "/"
(000009)30/10/2020 14:36:45 - tppice (192.168.32.11)> PASV
(000009)30/10/2020 14:36:45 - tppice (192.168.32.11)> 227 Entering Passive Mode (172,16,100,18,246,142)
(000009)30/10/2020 14:36:45 - tppice (192.168.32.11)> MLSD
(000009)30/10/2020 14:36:45 - tppice (192.168.32.11)> 150 Opening data channel for directory listing of "/"
(000009)30/10/2020 14:36:45 - tppice (192.168.32.11)> 226 Successfully transferred "/"
(000009)30/10/2020 14:36:46 - tppice (192.168.32.11)> PASV
(000009)30/10/2020 14:36:46 - tppice (192.168.32.11)> 227 Entering Passive Mode (172,16,100,18,203,110)
(000009)30/10/2020 14:36:46 - tppice (192.168.32.11)> MLSD
(000009)30/10/2020 14:36:46 - tppice (192.168.32.11)> 150 Opening data channel for directory listing of "/"
(000009)30/10/2020 14:36:46 - tppice (192.168.32.11)> 226 Successfully transferred "/"
(000009)30/10/2020 14:36:47 - tppice (192.168.32.11)> PASV
(000009)30/10/2020 14:36:47 - tppice (192.168.32.11)> 227 Entering Passive Mode (172,16,100,18,233,94)
(000009)30/10/2020 14:36:47 - tppice (192.168.32.11)> MLSD
(000009)30/10/2020 14:36:47 - tppice (192.168.32.11)> 150 Opening data channel for directory listing of "/"
(000009)30/10/2020 14:36:47 - tppice (192.168.32.11)> 226 Successfully transferred "/"
(000009)30/10/2020 14:36:50 - tppice (192.168.32.11)> PASV
(000009)30/10/2020 14:36:50 - tppice (192.168.32.11)> 227 Entering Passive Mode (172,16,100,18,211,59)
(000009)30/10/2020 14:36:50 - tppice (192.168.32.11)> MLSD
(000009)30/10/2020 14:36:50 - tppice (192.168.32.11)> 150 Opening data channel for directory listing of "/"
(000009)30/10/2020 14:36:50 - tppice (192.168.32.11)> 226 Successfully transferred "/"
(000009)30/10/2020 14:38:51 - tppice (192.168.32.11)> 421 Connection timed out.
(000009)30/10/2020 14:38:51 - tppice (192.168.32.11)> disconnected.

treb0r
500 Command not understood
Posts: 3
Joined: 2020-10-30 15:02
First name: Robert
Last name: Smith

Re: Large file copy - file already exists

#3 Post by treb0r » 2020-10-30 23:34

It looks to me as though the transfer completed successfully but each time now when the last byte is copied it says 'the file exists already do I want to overwrite/ resume/ rename/ skip?'
When the transfer starts it creates the file with a 0 byte size but the disk free space indicates that the file is being written to.
File size is identical on source and destination but in FZ Client window it reports destination filesize is still 0 bytes.

User avatar
botg
Site Admin
Posts: 35555
Joined: 2004-02-23 20:49
First name: Tim
Last name: Kosse

Re: Large file copy - file already exists

#4 Post by botg » 2020-11-02 08:23

Something odd in the log:
(000006)30/10/2020 12:03:25 - tppice (192.168.32.11)> STOR ice.bak
(000006)30/10/2020 12:03:25 - tppice (192.168.32.11)> 150 Opening data channel for file upload to server of "/ice.bak"
(000008)30/10/2020 14:27:26 - tppice (192.168.32.11)> STOR ice.bak
(000008)30/10/2020 14:27:26 - tppice (192.168.32.11)> 150 Opening data channel for file upload to server of "/ice.bak", restarting at offset 268488720392
(000006)30/10/2020 14:29:46 - tppice (192.168.32.11)> disconnected.
(000006)30/10/2020 14:29:46 - tppice (192.168.32.11)> 226 Successfully transferred "/ice.bak"
Looks like the client is attempting to resume a transfer that is still ongoing from the server's perspective.

What does it say in the client's message log?

Post Reply