Question:
Hello,
Here's what I am trying to achieve - - This is a nightly job to upload a 4.3 GB backup file (FileZilla Server version 0.9.43 beta). Since this is a large file and I need to perform a few tasks once the file is uploaded I am using the LargeFileUpload method.
I see that you recommend using 20 MB chunks - In my case I have to use bigger chunks (currently using 50 MB) in order to limit the number of data connections. At around 120 connections the firewall starts interfering and closes the connection.
This works beautifully on most nights and transfers the 4.3 GB file in less than an hour.
Problem - Once every one/two weeks the transfer/upload runs slow and throws the following error - SocketError: WSAECONNABORTED An established connection was aborted by the software in your host machine. For more information see this Chilkat Blog post: http://www.cknotes.com/?p=91
Here are the final few lines from the log -
appendFromMemory(10327ms):
uploadFromDataSource(10327ms):
pbsz_protp(78ms):
simpleCommand(47ms):
sendCommand:
sendingCommand: PBSZ 0
--sendCommand
readCommandResponse(47ms):
replyLineQP: 200 PBSZ=3D0
--readCommandResponse
--simpleCommand
simpleCommand(31ms):
sendCommand:
sendingCommand: PROT P
--sendCommand
readCommandResponse(31ms):
replyLineQP: 200 Protection level set to P
--readCommandResponse
--simpleCommand
--pbsz_protp
setupDataConnection(109ms):
setupPassiveDataSocket(109ms):
sendCommand:
sendingCommand: PASV
--sendCommand
readCommandResponse(47ms):
replyLineQP: 227 Entering Passive Mode (10,22,30,73,58,157)
--readCommandResponse
dataConnect(62ms):
hostname: XX.XXX.XXX.XX
port: 15005
socket2Connect(62ms):
connect2(62ms):
hostname: XX.XXX.XXX.XX
port: 15005
ssl: 0
connectSocket(62ms):
domainOrIpAddress: XX.XXX.XXX.XX
port: 15005
connectTimeoutMs: 30000
connect_ipv6_or_ipv4(62ms):
This is an IPV4 numeric address.
Domain to IP address resolution not needed.
connecting to IPV4 address...
ipAddress: XX.XXX.XXX.XX
createSocket:
Setting SO_SNDBUF size
sendBufSize: 262144
Setting SO_RCVBUF size
recvBufSize: 4194304
--createSocket
connect(62ms):
Waiting for the connect to complete...
myIP: XX.XX.XX.XX
myPort: 52894
socket connect successful.
--connect
--connect_ipv6_or_ipv4
--connectSocket
--connect2
--socket2Connect
socketOptions:
SO_SNDBUF: 262144
SO_RCVBUF: 4194304
TCP_NODELAY: 0
SO_KEEPALIVE: 0
--socketOptions
dataConnectSuccess: 1
--dataConnect
--setupPassiveDataSocket
--setupDataConnection
sendUploadCommand:
sendCommand:
sendingCommand: APPE Backup.bak
--sendCommand
--sendUploadCommand
Reading intermediate response for upload...
readCommandResponse(47ms):
replyLineQP: 150 Opening data channel for file upload to server, restarting at offset 1310720000
--readCommandResponse
intermediateResponseStatusCode: 150
intermediateReply: 150 Opening data channel for file upload to server, restarting at offset 1310720000
sendUploadFileData(9719ms):
UploadData: Elapsed time: 9719 millisec
--sendUploadFileData
closingDataConnection(31ms):
shutdownChannel(31ms):
sending close notify...
sendCloseNotify:
Turning on TCP_NODELAY.
--sendCloseNotify
reading SSL/TLS close notify...
(bForceClose) socket shutdown..
terminateConnection:
Cleanly terminated TCP connection.
--terminateConnection
Clearing TLS client certificates.
--shutdownChannel
--closingDataConnection
Reading final response...
readCommandResponse(15ms):
replyLineQP: 226 Successfully transferred ""
--readCommandResponse
FinalReply: Elapsed time: 15 millisec
--uploadFromDataSource
--appendFromMemory
appendFromMemory(216295ms):
uploadFromDataSource(216295ms):
pbsz_protp(93ms):
simpleCommand(46ms):
sendCommand:
sendingCommand: PBSZ 0
--sendCommand
readCommandResponse(46ms):
replyLineQP: 200 PBSZ=3D0
--readCommandResponse
--simpleCommand
simpleCommand(47ms):
sendCommand:
sendingCommand: PROT P
--sendCommand
readCommandResponse(47ms):
replyLineQP: 200 Protection level set to P
--readCommandResponse
--simpleCommand
--pbsz_protp
setupDataConnection(78ms):
setupPassiveDataSocket(78ms):
sendCommand:
sendingCommand: PASV
--sendCommand
readCommandResponse(47ms):
replyLineQP: 227 Entering Passive Mode (10,22,30,73,58,158)
--readCommandResponse
dataConnect(31ms):
hostname: XX.XXX.XXX.XX
port: 15006
socket2Connect(31ms):
connect2(31ms):
hostname: XX.XXX.XXX.XX
port: 15006
ssl: 0
connectSocket(31ms):
domainOrIpAddress: XX.XXX.XXX.XX
port: 15006
connectTimeoutMs: 30000
connect_ipv6_or_ipv4(31ms):
This is an IPV4 numeric address.
Domain to IP address resolution not needed.
connecting to IPV4 address...
ipAddress: XX.XXX.XXX.XX
createSocket:
Setting SO_SNDBUF size
sendBufSize: 262144
Setting SO_RCVBUF size
recvBufSize: 4194304
--createSocket
connect(31ms):
Waiting for the connect to complete...
myIP: XX.XX.XX.XX
myPort: 52895
socket connect successful.
--connect
--connect_ipv6_or_ipv4
--connectSocket
--connect2
--socket2Connect
socketOptions:
SO_SNDBUF: 262144
SO_RCVBUF: 4194304
TCP_NODELAY: 0
SO_KEEPALIVE: 0
--socketOptions
dataConnectSuccess: 1
--dataConnect
--setupPassiveDataSocket
--setupDataConnection
sendUploadCommand:
sendCommand:
sendingCommand: APPE Backup.bak
--sendCommand
--sendUploadCommand
Reading intermediate response for upload...
readCommandResponse(47ms):
replyLineQP: 150 Opening data channel for file upload to server, restarting at offset 1363148800
--readCommandResponse
intermediateResponseStatusCode: 150
intermediateReply: 150 Opening data channel for file upload to server, restarting at offset 1363148800
sendUploadFileData(155689ms):
sendOnSocketFromSource(155689ms):
Error sending on socket (1)
SocketError: WSAECONNABORTED An established connection was aborted by the software in your host machine.
For more information see this Chilkat Blog post: http://www.cknotes.com/?p=91
send_size: 4096
Failed to send TLS message.
Failed to send on socket from source.
--sendOnSocketFromSource
Failed to upload data.
UploadData: Elapsed time: 155689 millisec
--sendUploadFileData
Reading final response...
readCommandResponse(60029ms):
sockRecv: Socket operation timeout.
Failed to read beginning of SSL/TLS record.
b: 0
dbSize: 0
nReadNBytes: 0
Failed to receive more TLS applicaton data.
nReceived: 0
Failed to read FTP control channel reply.
readFtpReply: Socket operation timeout.
--readCommandResponse
Closing the control connection...
shutdownChannel(47ms):
sending close notify...
sendCloseNotify:
Turning on TCP_NODELAY.
--sendCloseNotify
reading SSL/TLS close notify...
(bForceClose) socket shutdown..
terminateConnection:
Cleanly terminated TCP connection.
--terminateConnection
Clearing TLS client certificates.
--shutdownChannel
FinalReply: Elapsed time: 60076 millisec
--uploadFromDataSource
--appendFromMemory
totalNumBytesSent: 1365573632
totalTime: Elapsed time: 1684671 millisec
Failed.
--LargeFileUpload
Question - Will reducing the chunk size fix this issue? I need to understand this better so that I can work on resolving the firewall issue (not sure if this is on the client side or server side) with limiting the number of data connections to 120.
Thanks!
To clarify: The LargFileUpload method is not creating simultaneous data connections (which isn't possible in a given FTP session). The data connections are one after the other.
I don't know if reducing the chunk size would fix it. You would have to experiment. However, if the LargeFileUpload method fails prior to completion, then it's possible to resume the LargeFileUpload by setting the ftp.RestartNext property and then call LargeFileUpload again with the same arguments. When RestartNext is true, Chilkat will examine the size of the file on the server, and the resume uploading from the position in the local file that corresponds to that size. (If somehow the firewall is in some state where some time has to pass before resuming would succeed, then you'll have to find out. Frankly I don't know why a firewall would behave as you describe. My feeling is that a problem such as this should be fixed at the source.)
Thanks a lot for your response. Implemented RestartNext... hoping for the best!
Hello,
Somewhat related to the original issue. I implemented RestartNext and I am making 3 attempts to complete the file transfer with a wait of 10 min between attempts (to give the server some time to free up resources if needed).
The nightly FTP transfers have been running fine since January of this year, however this Monday we started receiving the "An established connection was aborted by the software in your host machine." on all three attempts.
I checked with the client if anything had changed on the FTP server (an update or a parallel process running around the same time) and they have confirmed that nothing has changed.
I am kinda stumped and wanted to know if you have any suggestions on how I should go about troubleshooting this issue. Thanks in advance.
closingDataConnection(62ms):
shutdownChannel(62ms):
sending close notify...
sendCloseNotify:
Turning on TCP_NODELAY.
--sendCloseNotify
reading SSL/TLS close notify...
Did not receive SSL/TLS close notify (this is common and not an error).
(bForceClose) socket shutdown..
Clearing TLS client certificates.
--shutdownChannel
--closingDataConnection