put() hangs

Question

I am using the following code:

if( ! asciiType ) 
            m_client.setType( FTPTransferType.BINARY );
        else
            m_client.setType( FTPTransferType.ASCII );
        
        
        if(usePassive)
            m_client.setConnectMode( FTPConnectMode.PASV );
        else
            m_client.setConnectMode( FTPConnectMode.ACTIVE);
        
        m_client.put( file.getCanonicalPath(), remoteName );

Everything seems to work fine until I tried connecting to an FTP server over the internet. I can retrieve and put files on the server for a while, then suddenly it just hangs. It is not the local file as it happens on different files. I cannot seem to find any consistancy.

The server throws a 553 data transfer failed error, yet the client still sits there.

I have a timeout of 15000 on the socket, and it doesnt timeout either. I left it running for 5 minutes without a timeout exception.

This is happening on Windows XP running JDK 1.4.2-b28, edtftpj-1.4.5.

Thanks!

Answer 1

If you are getting 553, something went wrong on the server side - you tried to use a filename that wasn't permitted, or something else the server did not allow.

What do you mean, "the client still sits there"? Did the client throw an FTPException?

The server throws a 553 data transfer failed error, yet the client still sits there.

Answer 2

The client just hangs. There is no exception thrown at all.

I receive some error during other transfers (read time outs) just fine. But after a while, this happens. Again the server can be stopped, clearing up all connections (checked with a netstat -a on the server showing no connections to the client). This I believe should have atleast cause a IOException.

Answer 3

Can you post the log file? You'll need to make sure logging is switched on.

The client just hangs. There is no exception thrown at all.

I receive some error during other transfers (read time outs) just fine. But after a while, this happens. Again the server can be stopped, clearing up all connections (checked with a netstat -a on the server showing no connections to the client). This I believe should have atleast cause a IOException.

Answer 4

I have the same problem. PUT get IOException only after about 10 minutes. no matter what timeout value I tried to set. (tried to catch InterruptedIOException but not caught)

Any clue?

;-::

Answer 5

The file (typically) is being put successfully but the client is crashing trying to run the verify portion after the put.

14:04:40.683 COL D 5192 (java_extensions.cxx:1442): Uploading file: \\electra\pms\download\adv-c\advft-g\remit-us11-adv-advft-062408-1008.rcv
14:04:40.683 COL D 5192 (java_extensions.cxx:1442): DEBUG [SocketUtils] 27 Jun 2008 14:04:40.683 : Could not use Socket.isConnected (java.lang.NoSuchMethodException)
14:04:40.699 COL D 5192 (java_extensions.cxx:1442): DEBUG [FTPControlSocket] 27 Jun 2008 14:04:40.699 : ---> PORT 204,165,247,14,16,128
14:04:40.746 COL D 5192 (java_extensions.cxx:1442): DEBUG [FTPControlSocket] 27 Jun 2008 14:04:40.746 : 200 PORT command successful.
14:04:40.746 COL D 5192 (java_extensions.cxx:1442): DEBUG [FTPControlSocket] 27 Jun 2008 14:04:40.746 : ---> STOR remit-us11-adv-advft-062408-1008.rcv
14:04:40.871 COL D 5192 (java_extensions.cxx:1442): DEBUG [FTPControlSocket] 27 Jun 2008 14:04:40.871 : 150 Opening data connection for $1$DGA10:[ECOMREMIT]remit-us11-adv-advft-062408-1008.rcv; (XXX.16X.24X.1X,4224)
14:04:40.871 COL D 5192 (java_extensions.cxx:1442): DEBUG [FTPActiveDataSocket] 27 Jun 2008 14:04:40.871 : Calling accept()
14:04:40.871 COL D 5192 (java_extensions.cxx:1442): DEBUG [FTPActiveDataSocket] 27 Jun 2008 14:04:40.871 : accept() succeeded
14:04:41.652 COL D 5192 (java_extensions.cxx:1442): DEBUG [FTPActiveDataSocket] 27 Jun 2008 14:04:41.652 : closeChild() succeeded
14:04:41.652 COL D 5192 (java_extensions.cxx:1442): DEBUG [FTPActiveDataSocket] 27 Jun 2008 14:04:41.652 : close() succeeded
14:04:41.652 COL D 5192 (java_extensions.cxx:1442): DEBUG [FTPClient] 27 Jun 2008 14:04:41.652 : Transferred 219926 bytes to remote host
14:04:41.668 COL D 5192 (java_extensions.cxx:1442): DEBUG [SocketUtils] 27 Jun 2008 14:04:41.668 : Could not use Socket.isConnected (java.lang.NoSuchMethodException)
14:14:41.668 COL D 5192 (java_extensions.cxx:1442): DEBUG [FTPClient] 27 Jun 2008 14:14:41.668 : Validate transfer on error after exception : Read timed out
14:14:41.683 COL D 5192 (java_extensions.cxx:1442): java.io.InterruptedIOException: Read timed out [THROWING]: java.io.InterruptedIOException: Read timed out
at java.net.SocketInputStream.socketRead(Native Method)
at java.net.SocketInputStream.read(Unknown Source)
at java.net.SocketInputStream.read(Unknown Source)
at java.io.InputStreamReader.fill(Unknown Source)
at java.io.InputStreamReader.read(Unknown Source)
at java.io.BufferedReader.fill(Unknown Source)
at java.io.BufferedReader.readLine(Unknown Source)
at java.io.BufferedReader.readLine(Unknown Source)
at com.enterprisedt.net.ftp.FTPControlSocket.D(Unknown Source)
at com.enterprisedt.net.ftp.FTPClient.validateTransfer(Unknown Source)
at com.enterprisedt.net.ftp.FTPClient.put(Unknown Source)
at com.enterprisedt.net.ftp.FTPClient.put(Unknown Source)
at com.enterprisedt.net.ftp.FTPClient.put(Unknown Source)
at com.idx.ec.caft.filetransfer.EDTFTPBase.uploadFile(EDTFTPBase.java:94)
at com.idx.ec.caft.ConnectionManager.uploadFile(ConnectionManager.java:273)
at com.idx.ec.caft.logic.ByAllOut.processState(ByAllOut.java:47)
at com.idx.ec.caft.logic.ByAllBase.processStates(ByAllBase.java:105)
at com.idx.ec.caft.CAFTBase.runCAFT(CAFTBase.java:131)
at crRTECAFT.processMessage(crRTECAFT.java:92)
at com.idx.ec.egate.file.ECBaseCollaboration2.executeBusinessRules(ECBaseCollaboration2.java:255)
at com.stc.jcsre.JCollaboration.translate(JCollaboration.java:148)
at com.stc.common.collabService.JCCollabControllerImpl.translate(JCCollabControllerImpl.java:568)

14:14:41.683 COL D 5192 (java_extensions.cxx:1442): DEBUG [SocketUtils] 27 Jun 2008 14:14:41.683 : Could not use Socket.isConnected (java.lang.NoSuchMethodException)
14:14:41.683 COL D 5192 (java_extensions.cxx:1442): DEBUG [SocketUtils] 27 Jun 2008 14:14:41.683 : Could not use Socket.isConnected (java.lang.NoSuchMethodException)
14:14:42.183 COL D 5192 (java_extensions.cxx:1442): WARN [FTPClient] 27 Jun 2008 14:14:42.183 : Validate transfer on error failed : Read timed out
14:14:42.183 COL D 5192 (java_extensions.cxx:1442): java.io.InterruptedIOException: Read timed out [THROWING]: java.io.InterruptedIOException: Read timed out
at java.net.SocketInputStream.socketRead(Native Method)
at java.net.SocketInputStream.read(Unknown Source)
at java.net.SocketInputStream.read(Unknown Source)
at java.io.InputStreamReader.fill(Unknown Source)
at java.io.InputStreamReader.read(Unknown Source)
at java.io.BufferedReader.fill(Unknown Source)
at java.io.BufferedReader.readLine(Unknown Source)
at java.io.BufferedReader.readLine(Unknown Source)
at com.enterprisedt.net.ftp.FTPControlSocket.D(Unknown Source)
at com.enterprisedt.net.ftp.FTPClient.validateTransfer(Unknown Source)
at com.enterprisedt.net.ftp.FTPClient.validateTransferOnError(Unknown Source)
at com.enterprisedt.net.ftp.FTPClient.put(Unknown Source)
at com.enterprisedt.net.ftp.FTPClient.put(Unknown Source)
at com.enterprisedt.net.ftp.FTPClient.put(Unknown Source)
at com.idx.ec.caft.filetransfer.EDTFTPBase.uploadFile(EDTFTPBase.java:94)
at com.idx.ec.caft.ConnectionManager.uploadFile(ConnectionManager.java:273)
at com.idx.ec.caft.logic.ByAllOut.processState(ByAllOut.java:47)
at com.idx.ec.caft.logic.ByAllBase.processStates(ByAllBase.java:105)
at com.idx.ec.caft.CAFTBase.runCAFT(CAFTBase.java:131)
at crRTECAFT.processMessage(crRTECAFT.java:92)
at com.idx.ec.egate.file.ECBaseCollaboration2.executeBusinessRules(ECBaseCollaboration2.java:255)
at com.stc.jcsre.JCollaboration.translate(JCollaboration.java:148)
at com.stc.common.collabService.JCCollabControllerImpl.translate(JCCollabControllerImpl.java:568)

We've wrapped this call with our own file management and catch all exceptions and retry, but certain files just will not finish the put() no matter how many times they retry. We send down thousands of files per day, and have only 2 customers with this issue, and with these customers the issue is intermittent. Some files are successfull going to this directory.

Ideas?

Thanks.

Answer 6

This sounds bizarre. So some files cannot be transferred (even trying repeatedly) while others can??

The files don't look large. The timeout looks like 600 sec which should be fine.

Basically, the server isn't sending a reply to the client saying that the file transferred correctly.

Here's a few questions to try answering:

1) Is it only files of a certain name? Does renaming the files help?
2) Are there are clues in the server logs?
3) Are there any quota or disk space issues on the server?
4) Have you tried using passive mode transfers?
5) Do other FTP clients have any trouble transferring the same files?

Also, does your retry mechanism use resume, i.e. only transfers the portion of the file that remains to be transferred?

Answer 7

Here's a few questions to try answering:

1) Is it only files of a certain name? Does renaming the files help? Does not help
2) Are there are clues in the server logs? I will need to follow up with our customer to see what their FTP Server is saying
3) Are there any quota or disk space issues on the server? No
4) Have you tried using passive mode transfers? Does not help
5) Do other FTP clients have any trouble transferring the same files? Have used win2k client with success

Also, does your retry mechanism use resume, i.e. only transfers the portion of the file that remains to be transferred? retries the entire file

Answer 8

The timeout looks like 600 sec which should be fine.

Why 600 sec? No matter what time out value I set, it will always timeout about 10 minutes. I have tried to set to 5 seconds, 30....

FTPClient ftp = new FTPClient();
ftp.setTimeout(MaxFTPTimeout);

and I do not get java.io.InterruptedIOException. Only get IOException after about 10 minutes

any clue?

Answer 9

here is my code and log. Thanks !!!

FileTransferClient ftp = new FileTransferClient();
ftp.setTimeout(MaxFTPTimeout); //this timeout is  2 minutes, but why get java.net.SocketException after about 10 minutes
ftp.setUserName( destination.getUserName() );
ftp.setPassword( destination.getPassword() );
ftp.setContentType(FTPTransferType.BINARY);
ftp.setEventListener(monitor);

ftp.setRemoteHost((String)destination.getHost());
if (destination.getPort() != null)
  ftp.setRemotePort(((Integer)destination.getPort()).intValue());

try {                   
  ftp.uploadFile((String)source.getFileName(), (String)destination.getFileName() + ".tmp");
  Thread.sleep(FTPsleep);                    
} 
catch (java.io.InterruptedIOException e) {
  sendNotification(NotificationType.FTP_PROGRESS, slotNumber + 
    "java.io.InterruptedIOException Problem transferring (dest): " + destination.getHost() + " " + e.toString(), token);
  return returnError("java.io.InterruptedIOException Problem transferring (dest): " + destination.getHost() + " " + e.toString());
}                   
catch (Exception e) {
  sendNotification(NotificationType.FTP_PROGRESS, slotNumber + 
  "ftp.put Exception Problem transferring (dest): " + destination.getHost() + " " + e.toString(), token);
  return returnError("ftp.put Exception Problem transferring (dest): " + destination.getHost() + " " + e.toString());
}

30 Jun 2008 21:01:04,940 [Chassis Pool] DEBUG - forward notification module.transfer.progress
30 Jun 2008 21:01:04,940 [Chassis Pool] DEBUG - updateSummaryStatus 9/pon2/7: Connecting via ftp... false false
30 Jun 2008 21:01:04,940 [Chassis Pool] DEBUG - Connecting to /10.255.92.7:21
30 Jun 2008 21:01:04,960 [Chassis Pool] DEBUG - forward notification module.transfer.progress
30 Jun 2008 21:01:04,980 [Chassis Pool] DEBUG - updateSummaryStatus 9/pon2/7: Logging in... false false
30 Jun 2008 21:01:04,980 [Chassis Pool] DEBUG - forward notification module.transfer.progress
30 Jun 2008 21:01:04,980 [Chassis Pool] DEBUG - updateSummaryStatus 9/pon2/7: Starting transfer... false false
30 Jun 2008 21:01:06,140 [Chassis Pool] DEBUG - updateSummaryStatus 9/pon2/7: onte_test.imz.w7 2% false false
30 Jun 2008 21:01:10,820 [Chassis Pool] DEBUG - updateSummaryStatus 9/pon2/7: onte_test.imz.w7 7% false false........
..
30 Jun 2008 21:01:21,720 [Chassis Pool] DEBUG - updateSummaryStatus 9/pon2/7: onte_test.imz.w7 21% false false
30 Jun 2008 21:01:28,440 [Chassis Pool] DEBUG - forward notification module.transfer.progress
30 Jun 2008 21:01:28,440 [Chassis Pool] DEBUG - updateSummaryStatus 9/pon2/7: onte_test.imz.w7 29% false false

fiber unplugged (disconnected)

....
30 Jun 2008 21:10:30,720 [Chassis Pool] DEBUG - Validate transfer on error after exception
java.net.SocketException: Broken pipe: socket write error
at java.net.SocketOutputStream.write([BII)V [line 186]
at java.io.DataOutputStream.write([BII)V [line 43]
at java.io.BufferedOutputStream.flush()V [line 63]
at java.io.BufferedOutputStream.write([BII)V [line 47]
at com.enterprisedt.com.ftp.FTPClient.putData(FTPClient.java:2396)
at com.enterprisedt.com.ftp.FTPClient.put(FTPClient.java:2080)
at com.enterprisedt.com.ftp.FTPClient.put(FTPClient.java:2062)
at com.enterprisedt.com.ftp.FileTransferClient.uploadFile(FileTransferClient.java:663)
at com.enterprisedt.com.ftp.FileTransferClient.uploadFile(FileTransferClient.java:637)

......
30 Jun 2008 21:10:31,220 [Chassis Pool] WARN - Validate transfer on error failed
java.net.SocketTimeoutException: Read timed out
at java.net.PERCSocketImpl.receive([BII)I [native]
at java.net.SocketInputStream.read([BII)I [line 116]
at COM.newmonics.io.Encoder.refillBuffer()V [line 795]
at COM.newmonics.io.ASCIIEncoder.getNextChar(Z)I [line 274]
at COM.newmonics.io.ASCIIEncoder.getChars([CII)I [line 226]
at java.io.InputStreamReader.read([CII)I [line 90]
at java.io.BufferedReader.refill()Z [line 393]
at java.io.BufferedReader.nextChar()I [line 408]
at java.io.BufferedReader.readLine()Ljava/lang/String; [line 200]
at com.enterprisedt.com.ftp.FTPControlSocket.readReply(FTPControlSocket.java:910)
at com.enterprisedt.com.ftp.FTPClient.validateTransfer(FTPClient.java:2114)
at com.enterprisedt.com.ftp.FTPClient.validateTransferOnError(FTPClient.java:2146)
at com.enterprisedt.com.ftp.FTPClient.put(FTPClient.java:2091)
at com.enterprisedt.com.ftp.FTPClient.put(FTPClient.java:2062)
at com.enterprisedt.com.ftp.FileTransferClient.uploadFile(FileTransferClient.java:663)
at com.enterprisedt.com.ftp.FileTransferClient.uploadFile(FileTransferClient.java:637)
......

30 Jun 2008 21:10:31,220 [Chassis Pool] DEBUG - forward notification module.transfer.progress
30 Jun 2008 21:10:31,220 [Chassis Pool] DEBUG - updateSummaryStatus 9/pon2/7ftp.put Exception Problem transferring (dest): 10.255.92.7 java.net.SocketException: Broken pipe: socket write error false false

Answer 10

Just FYI MaxFTPTimeout must be in milliseconds, e.g. 60000 should be the minimum timeout used (60 s).