DownloadStream doesn't free connection on close

Question

This works fine:

AsyncFileTransferClient session = new AsyncFileTransferClient (1, 4);
session.setRemoteHost ("localhost");
session.setUserName ("anonymous");
session.setPassword ("test");
session.connect ();
String remoteDirectory = "ftptests";
session.changeDirectory (remoteDirectory);
String filename = "101-put-ok.xml";

// Strategy 1: download to byte array (works fine)
byte[] localFile = session.downloadByteArray (filename);
long byteCount = localFile.length;

session.disconnect ();
assertEquals ("1 localFile length", 240, byteCount);

but this doesn't free the connection and doesn't terminate:

AsyncFileTransferClient session = new AsyncFileTransferClient (1, 4);
session.setRemoteHost ("localhost");
session.setUserName ("anonymous");
session.setPassword ("test");
session.connect ();
String remoteDirectory = "ftptests";
session.changeDirectory (remoteDirectory);
String filename = "101-put-ok.xml";

// Strategy 2: download to stream
FileTransferInputStream localFile = session.downloadStream (filename);
byte[] buffer = new byte[2000];
long byteCount = localFile.read (buffer, 0, 2000);
long end = localFile.read (buffer);
localFile.close ();

session.disconnect ();
assertEquals ("1 localFile length", 240, byteCount);

Fragment of log for strategy 1:

10:41:10,451 DEBUG [main]  edt.AsyncResult - waitTillComplete() called: com.enterprisedt.net.ftp.async.DownloadByteArrayResult@7ffc6e42
10:41:10,451 DEBUG [main]  edt.AsyncResult - Waiting until operation complete - com.enterprisedt.net.ftp.async.DownloadByteArrayResult
10:41:10,451 INFO  [FTPThread_edt_4]  edt.FTPTaskProcessor - Processing task 3:Download[101-put-ok.xml=> byteArray]
10:41:10,451 DEBUG [FTPThread_edt_4]  edt.FTPConnectionPool - Waiting for a free connection ...
10:41:10,467 DEBUG [FTPThread_edt_4]  edt.FTPConnectionPool - Connection now free!
10:41:10,467 DEBUG [FTPThread_edt_4]  edt.FTPConnectionPool - Got a free connection: FTPConnection #1(0 left)
10:41:10,467 DEBUG [FTPThread_edt_4]  edt.AsyncResult - notifyComplete() called: com.enterprisedt.net.ftp.async.DownloadByteArrayResult@7ffc6e42
10:41:10,467 DEBUG [FTPThread_edt_4]  edt.AsyncResult - waitTillComplete() called: com.enterprisedt.net.ftp.async.DownloadByteArrayResult@7ffc6e42
10:41:10,467 DEBUG [main]  edt.AsyncResult - waitTillComplete() exit: com.enterprisedt.net.ftp.async.DownloadByteArrayResult@7ffc6e42
10:41:10,467 DEBUG [FTPThread_edt_4]  edt.AsyncResult - waitTillComplete() exit: com.enterprisedt.net.ftp.async.DownloadByteArrayResult@7ffc6e42
10:41:10,467 INFO  [FTPThread_edt_4]  edt.FTPTaskProcessor - Processed task 3:Download[101-put-ok.xml=> byteArray]
10:41:10,467 INFO  [FTPThread_edt_4]  edt.FTPTaskProcessor - Freed connection for task 3
10:41:10,467 INFO  [FTPThread_edt_4]  edt.FTPTaskProcessor - Task 3 complete (FTPThread[FTPThread_edt_4])

Fragment of log for strategy 2:

10:43:40,916 INFO  [FTPThread_edt_4]  edt.FTPTaskProcessor - Processing task 3:Download[101-put-ok.xml=>stream]
10:43:40,916 DEBUG [FTPThread_edt_4]  edt.FTPConnectionPool - Waiting for a free connection ...
10:43:40,932 DEBUG [FTPThread_edt_4]  edt.FTPConnectionPool - Connection now free!
10:43:40,932 DEBUG [FTPThread_edt_4]  edt.FTPConnectionPool - Got a free connection: FTPConnection #1(0 left)

Environment:
edtftpj-pro version 4.5.0
jdk 1.6.0-43
Windows 7
FileZilla server

I'll supply exhaustive diagnostic information if necessary, but perhaps I'm missing something obvious.
Suggestions welcome
Simon

Answer 1

Thanks, we will try to replicate and get back to you.

Answer 2

I haven't been able to replicate the problem, so it may be an environment-specific problem. I've therefore set up an account for you on our server. I've PM'd you the hostname and credentials. Here's the code:

package com.enterprisedt.client.sparker;

import junit.framework.Assert;
import com.enterprisedt.net.ftp.AsyncFileTransferClient;
import com.enterprisedt.net.ftp.FileTransferInputStream;
import com.enterprisedt.util.debug.Level;
import com.enterprisedt.util.debug.Logger;

public class DownloadStreamTest {

   public static void main(String[] args) {
      Logger.addStandardOutputAppender();
      Logger.setLevel(Level.DEBUG);
      AsyncFileTransferClient session = new AsyncFileTransferClient (1, 4);
      try {
         session.setRemoteHost ("HOSTNAME");
         session.setUserName ("USERNAME"); 
         session.setPassword ("PASSWORD"); 
         session.connect ();
         String remoteDirectory = "ftptests"; 
         session.changeDirectory (remoteDirectory); 
         String filename = "101-put-ok.xml"; 
   
         // Strategy 2: download to stream 
         FileTransferInputStream localFile = session.downloadStream (filename); 
         byte[] buffer = new byte[2000];
         long byteCount = localFile.read (buffer, 0, 2000); 
         long end = localFile.read (buffer); 
         localFile.close (); 
   
         Assert.assertEquals ("1 localFile length", 240, byteCount); 
      } catch (Throwable e) {
         e.printStackTrace();
      } finally {
         try {
            session.disconnect ();
         } catch (Throwable e) {
            e.printStackTrace();
         } 
      }
   }

}

Please let me know how that goes for you. If you can replicate it against our server then please post the log. If you can't replicate it then try comparing the log created when connected to our server with the log created when connecting to your own server.

- Hans (EnterpriseDT)

Answer 3

Hans,

Thanks for your response, suggestions and standalone class.
I ran it here, and it hangs just like my test class does in Eclipse.

To eliminate potential classpath problems I set up a clean project directory and simple command file.
To reach your server I had to go through a http proxy.
I captured output to a log file; when it hung I used ctrl/Break to generate a thread dump for you.
I edited the log and the source files only to replace sensitive text with [suppressed].
I zipped the whole directory structure, and uploaded the result (1.3Mb) to the directory you kindly created for me at completeftp:
/Home/sparker/edtftp.zip

I hope this will help you diagnose the problem. If you need more, just ask.
Simon

Answer 4

Did you use an HTTP proxy in the test you described in your first message, or was that only used for the test against our server?

- Hans

Answer 5

My original test case ran against a FileZilla server on localhost, and I didn't specify a proxy of any kind.
I only introduced the HTTP proxy in order to reach your site.

Note that retrieving to a byte array has always worked as expected, and the wire protocol is clean.

For what it's worth, here's something I noted while debugging in Eclipse:
FTPInputStream extends AbstractFTPInputStream, but it delegates to another instance of AbstractFTPInputStream.
Definitions of fields 'closed' and 'started' in the first object shadow similar definitions in the second.
State changes are visible only in the delegate.

Hope this helps,
Simon

Answer 6

Hi Simon

My colleague and I spent a considerable amount of time trying to work out how this could happen. In the face of the undeniable evidence of your log file, we'd basically concluded that it was impossible. Then when we realized that it had already been fixed! It was fixed in September last year, which was after the most recent release. So in fact I can't happen in the latest build. We've uploaded a new jar file for you to use. You can find it in the home directory of the account I created for you.

- Hans (EnterpriseDT)

Answer 7

That worked a treat, Hans!

Thanks for your trouble. I've shipped that jar to our customer after some testing here, and we'll incorporate it in future releases.
Any idea when 4.6 will be released officially?

Simon

Answer 8

By end April we expect