Discuss (FTP) and (SFTP, FTPS and SCP), our Java file transfer clients.
no avatar
User

bhagyadesai

Posts

7

Joined

Mon Jun 25, 2012 6:20 pm

dirDetails() method goes in a loop

by bhagyadesai » Thu May 16, 2013 2:59 pm

Hi,

We are using edtftpj-pro.jar (edtftpj-pro-4.1.0).

We are trying to get list of directory using dirDetails() in a loop. At one of our clients, it is observed that after some time the dirDetials() gets into a loop and control does not come back to our code.

Here is the ftp trace -
I have given last two iterations of dirDetails, observe that once we get the Can't open data connection, there is no activitty.
We also tried with the latest version o edtftpj-pro-4.4.0. Still we observed the same problem.

DEBUG [FTPControlSocket] 13 ??? 2013 15:09:18.537 : ---> SYST
DEBUG [FTPControlSocket] 13 ??? 2013 15:09:18.552 : 215 Windows_NT
DEBUG [FTPControlSocket] 13 ??? 2013 15:09:18.552 : ---> SYST
DEBUG [FTPControlSocket] 13 ??? 2013 15:09:18.568 : 215 Windows_NT
DEBUG [MVSFileParser] 13 ??? 2013 15:09:18.568 : Ignoring the set locale.
DEBUG [FTPControlSocket] 13 ??? 2013 15:09:18.568 : ---> PWD
DEBUG [FTPControlSocket] 13 ??? 2013 15:09:18.599 : 257 "/" is current directory.
DEBUG [FTPClient] 13 ??? 2013 15:09:18.599 : setupDirDetails(/LocalUser/Public) returning: ///LocalUser/Public
DEBUG [FTPControlSocket] 13 ??? 2013 15:09:18.599 : ---> PASV
DEBUG [FTPControlSocket] 13 ??? 2013 15:09:18.615 : 227 Entering Passive Mode (91,199,99,72,215,3).
INFO [FTPControlSocket] 13 ??? 2013 15:09:18.615 : Substituting server supplied IP (91.199.99.72) with remote host IP (91.199.99.72)
DEBUG [StreamSocketFactory] 13 ??? 2013 15:09:18.615 : Connecting to 91.199.99.72:55043 via standard socket
DEBUG [SSLFTPControlSocket] 13 ??? 2013 15:09:18.630 : Creating FTPPassiveDataSocket
DEBUG [FTPControlSocket] 13 ??? 2013 15:09:18.630 : ---> LIST /LocalUser/Public
DEBUG [FTPControlSocket] 13 ??? 2013 15:09:18.646 : 125 Data connection already open; Transfer starting.
DEBUG [FTPControlSocket] 13 ??? 2013 15:09:18.880 : 226 Transfer complete.
DEBUG [FTPControlSocket] 13 ??? 2013 15:09:21.881 : ---> SYST
DEBUG [FTPControlSocket] 13 ??? 2013 15:09:22.209 : 215 Windows_NT
DEBUG [FTPControlSocket] 13 ??? 2013 15:09:22.225 : ---> SYST
DEBUG [FTPControlSocket] 13 ??? 2013 15:09:22.256 : 215 Windows_NT
DEBUG [MVSFileParser] 13 ??? 2013 15:09:22.256 : Ignoring the set locale.
DEBUG [FTPControlSocket] 13 ??? 2013 15:09:22.256 : ---> PWD
DEBUG [FTPControlSocket] 13 ??? 2013 15:09:22.287 : 257 "/" is current directory.
DEBUG [FTPClient] 13 ??? 2013 15:09:22.287 : setupDirDetails(/LocalUser/Public) returning: ///LocalUser/Public
DEBUG [FTPControlSocket] 13 ??? 2013 15:09:22.287 : ---> PASV
DEBUG [FTPControlSocket] 13 ??? 2013 15:09:22.303 : 227 Entering Passive Mode (91,199,99,72,215,4).
INFO [FTPControlSocket] 13 ??? 2013 15:09:22.303 : Substituting server supplied IP (91.199.99.72) with remote host IP (91.199.99.72)
DEBUG [StreamSocketFactory] 13 ??? 2013 15:09:22.303 : Connecting to 91.199.99.72:55044 via standard socket
DEBUG [SSLFTPControlSocket] 13 ??? 2013 15:09:22.334 : Creating FTPPassiveDataSocket
DEBUG [FTPControlSocket] 13 ??? 2013 15:09:22.334 : ---> LIST /LocalUser/Public
DEBUG [FTPControlSocket] 13 ??? 2013 15:09:22.365 : 125 Data connection already open; Transfer starting.
DEBUG [FTPControlSocket] 13 ??? 2013 15:09:22.584 : 226 Transfer complete.
DEBUG [FTPControlSocket] 13 ??? 2013 15:09:24.600 : ---> SYST
DEBUG [FTPControlSocket] 13 ??? 2013 15:09:24.616 : 215 Windows_NT
DEBUG [FTPControlSocket] 13 ??? 2013 15:09:24.616 : ---> SYST
DEBUG [FTPControlSocket] 13 ??? 2013 15:09:24.631 : 215 Windows_NT
DEBUG [MVSFileParser] 13 ??? 2013 15:09:24.631 : Ignoring the set locale.
DEBUG [FTPControlSocket] 13 ??? 2013 15:09:24.647 : ---> PWD
DEBUG [FTPControlSocket] 13 ??? 2013 15:09:24.663 : 257 "/" is current directory.
DEBUG [FTPClient] 13 ??? 2013 15:09:24.663 : setupDirDetails(/LocalUser/Public) returning: ///LocalUser/Public
DEBUG [FTPControlSocket] 13 ??? 2013 15:09:24.663 : ---> PASV
DEBUG [FTPControlSocket] 13 ??? 2013 15:09:24.678 : 227 Entering Passive Mode (91,199,99,72,215,5).
INFO [FTPControlSocket] 13 ??? 2013 15:09:24.678 : Substituting server supplied IP (91.199.99.72) with remote host IP (91.199.99.72)
DEBUG [StreamSocketFactory] 13 ??? 2013 15:09:24.678 : Connecting to 91.199.99.72:55045 via standard socket
DEBUG [SSLFTPControlSocket] 13 ??? 2013 15:09:24.694 : Creating FTPPassiveDataSocket
DEBUG [FTPControlSocket] 13 ??? 2013 15:09:24.694 : ---> LIST /LocalUser/Public
DEBUG [FTPControlSocket] 13 ??? 2013 15:09:36.806 : 425 Can't open data connection.

Can anyone help us on this?

Thank you.
Regards
- Bhagyashree
no avatar
User

support2

Posts

3987

Joined

Tue May 18, 2004 8:30 am

Re: dirDetails() method goes in a loop

by support2 » Thu May 16, 2013 4:28 pm

Maybe post your code to show us what you are doing.
no avatar
User

bhagyadesai

Posts

7

Joined

Mon Jun 25, 2012 6:20 pm

by bhagyadesai » Thu May 16, 2013 6:36 pm

Its a big class so cannot paste everything here...
The flow is like this:
We have class which is extending SSLFTPClient. In this class we have written a method called dirSubdirAsXML(String folderPath).
We create object of our class and return the reference to the caller code.
Using the reference, we keep on calling dirSubdirAsXML(String folderPath) method after every 3 secs.
The dirSubdirAsXML(String folderPath) has below code in it..
FTPFile[] files=dirDetails(path);

So after few iterations, it is observed that the control doesn't come back to the caller.

Please let me know if u need more explaination.

Thank you.
Regards
- Bhagyashree
no avatar
User

support2

Posts

3987

Joined

Tue May 18, 2004 8:30 am

by support2 » Thu May 16, 2013 11:10 pm

Please email us the entire zipped log file and the code - to support at our domain name.
no avatar
User

bhagyadesai

Posts

7

Joined

Mon Jun 25, 2012 6:20 pm

by bhagyadesai » Fri May 17, 2013 12:50 am

the trace snippet i gave did'nt had the problematic log. Below is the log with LIST command invoked three times. It was successful twice and the third time it gave can't open data connection.

DEBUG [FTPControlSocket] 12 ??? 2013 15:17:36.034 : ---> SYST
DEBUG [FTPControlSocket] 12 ??? 2013 15:17:36.034 : 215 Windows_NT
DEBUG [FTPControlSocket] 12 ??? 2013 15:17:36.034 : ---> SYST
DEBUG [FTPControlSocket] 12 ??? 2013 15:17:36.050 : 215 Windows_NT
DEBUG [MVSFileParser] 12 ??? 2013 15:17:36.050 : Ignoring the set locale.
DEBUG [FTPControlSocket] 12 ??? 2013 15:17:36.050 : ---> PWD
DEBUG [FTPControlSocket] 12 ??? 2013 15:17:36.065 : 257 "/" is current directory.
DEBUG [FTPClient] 12 ??? 2013 15:17:36.065 : setupDirDetails(/LocalUser/Public) returning: ///LocalUser/Public
DEBUG [FTPControlSocket] 12 ??? 2013 15:17:36.065 : ---> PASV
DEBUG [FTPControlSocket] 12 ??? 2013 15:17:36.065 : 227 Entering Passive Mode (91,199,99,72,215,0).
INFO [FTPControlSocket] 12 ??? 2013 15:17:36.065 : Substituting server supplied IP (91.199.99.72) with remote host IP (91.199.99.72)
DEBUG [StreamSocketFactory] 12 ??? 2013 15:17:36.065 : Connecting to 91.199.99.72:55040 via standard socket
DEBUG [SSLFTPControlSocket] 12 ??? 2013 15:17:36.081 : Creating FTPPassiveDataSocket
DEBUG [FTPControlSocket] 12 ??? 2013 15:17:36.081 : ---> LIST /LocalUser/Public
DEBUG [FTPControlSocket] 12 ??? 2013 15:17:36.097 : 125 Data connection already open; Transfer starting.
DEBUG [FTPControlSocket] 12 ??? 2013 15:17:36.331 : 226 Transfer complete.
DEBUG [FTPControlSocket] 12 ??? 2013 15:17:39.331 : ---> SYST
DEBUG [FTPControlSocket] 12 ??? 2013 15:17:39.331 : 215 Windows_NT
DEBUG [FTPControlSocket] 12 ??? 2013 15:17:39.331 : ---> SYST
DEBUG [FTPControlSocket] 12 ??? 2013 15:17:39.347 : 215 Windows_NT
DEBUG [MVSFileParser] 12 ??? 2013 15:17:39.347 : Ignoring the set locale.
DEBUG [FTPControlSocket] 12 ??? 2013 15:17:39.347 : ---> PWD
DEBUG [FTPControlSocket] 12 ??? 2013 15:17:39.347 : 257 "/" is current directory.
DEBUG [FTPClient] 12 ??? 2013 15:17:39.347 : setupDirDetails(/LocalUser/Public) returning: ///LocalUser/Public
DEBUG [FTPControlSocket] 12 ??? 2013 15:17:39.347 : ---> PASV
DEBUG [FTPControlSocket] 12 ??? 2013 15:17:39.362 : 227 Entering Passive Mode (91,199,99,72,215,1).
INFO [FTPControlSocket] 12 ??? 2013 15:17:39.362 : Substituting server supplied IP (91.199.99.72) with remote host IP (91.199.99.72)
DEBUG [StreamSocketFactory] 12 ??? 2013 15:17:39.362 : Connecting to 91.199.99.72:55041 via standard socket
DEBUG [SSLFTPControlSocket] 12 ??? 2013 15:17:39.378 : Creating FTPPassiveDataSocket
DEBUG [FTPControlSocket] 12 ??? 2013 15:17:39.378 : ---> LIST /LocalUser/Public
DEBUG [FTPControlSocket] 12 ??? 2013 15:17:39.378 : 125 Data connection already open; Transfer starting.
DEBUG [FTPControlSocket] 12 ??? 2013 15:17:39.597 : 226 Transfer complete.
DEBUG [FTPControlSocket] 12 ??? 2013 15:17:42.612 : ---> SYST
DEBUG [FTPControlSocket] 12 ??? 2013 15:17:42.628 : 215 Windows_NT
DEBUG [FTPControlSocket] 12 ??? 2013 15:17:42.628 : ---> SYST
DEBUG [FTPControlSocket] 12 ??? 2013 15:17:42.644 : 215 Windows_NT
DEBUG [MVSFileParser] 12 ??? 2013 15:17:42.644 : Ignoring the set locale.
DEBUG [FTPControlSocket] 12 ??? 2013 15:17:42.644 : ---> PWD
DEBUG [FTPControlSocket] 12 ??? 2013 15:17:42.659 : 257 "/" is current directory.
DEBUG [FTPClient] 12 ??? 2013 15:17:42.659 : setupDirDetails(/LocalUser/Public) returning: ///LocalUser/Public
DEBUG [FTPControlSocket] 12 ??? 2013 15:17:42.659 : ---> PASV
DEBUG [FTPControlSocket] 12 ??? 2013 15:17:42.690 : 227 Entering Passive Mode (91,199,99,72,215,2).
INFO [FTPControlSocket] 12 ??? 2013 15:17:42.690 : Substituting server supplied IP (91.199.99.72) with remote host IP (91.199.99.72)
DEBUG [StreamSocketFactory] 12 ??? 2013 15:17:42.690 : Connecting to 91.199.99.72:55042 via standard socket
DEBUG [SSLFTPControlSocket] 12 ??? 2013 15:17:42.706 : Creating FTPPassiveDataSocket
DEBUG [FTPControlSocket] 12 ??? 2013 15:17:42.706 : ---> LIST /LocalUser/Public
DEBUG [FTPControlSocket] 12 ??? 2013 15:17:55.128 : 425 Can't open data connection.
no avatar
User

support2

Posts

3987

Joined

Tue May 18, 2004 8:30 am

by support2 » Fri May 17, 2013 11:13 am

It fails the third time because you are running out of TCP sockets - there is a limited number available and lots of frequent listings exhaust them. If listing fails, you should catch the exception, wait 30 sec, and then retry.
no avatar
User

bhagyadesai

Posts

7

Joined

Mon Jun 25, 2012 6:20 pm

by bhagyadesai » Mon May 20, 2013 10:26 pm

Hi,
The problem is not solved even after increasing the delay between each LIST command to 1 minute. Below is the scenario how we call the LIST method.
In out code, we log-in and connect to the ftp server from two different threads.
1st thread opens the connection, issues CWD and closes the connection after every 5 minute.
2nd thread after every 1 minute, opens the connection, issues issues dirdetails() method and closes the connection using quit() method.

After around 23 hours, It is observed that 1st thread is working properly but in case of 2nd thread the control does not come back to our code.

Also now we don't get any error can't open data connection which was coming earlier (when we used to issue LIST method after every 3 secs. without closing and connecting after it for each iteration).

Below is the trace log.

DEBUG [SSLFTPClient] 20 ??? 2013 10:28:41.944 : Setting custom validator to com.enterprisedt.net.ftp.ssl.SSLFTPStandardValidator
DEBUG [SSLFTPClient] 20 ??? 2013 10:28:41.944 : Turned server validation off
DEBUG [SSLFTPClient] 20 ??? 2013 10:28:41.944 : Created explicit FTPS client.
DEBUG [SSLFTPClient] 20 ??? 2013 10:28:41.944 : Connecting to 91.199.99.72:1924
DEBUG [StreamSocketFactory] 20 ??? 2013 10:28:41.944 : Connecting to 91.199.99.72:1924 via standard socket
DEBUG [SSLSocket] 20 ??? 2013 10:28:41.959 : Timeout=0
DEBUG [FTPControlSocket] 20 ??? 2013 10:28:41.990 : 220-Microsoft FTP Service
DEBUG [FTPControlSocket] 20 ??? 2013 10:28:42.209 : 220 Syneron Files
DEBUG [SSLFTPControlSocket] 20 ??? 2013 10:28:42.209 : DISABLE_CONTROL_SSL_CLOSURE=false
DEBUG [SSLFTPControlSocket] 20 ??? 2013 10:28:42.209 : DISABLE_CONTROL_WAIT_ON_CLOSE=false
DEBUG [SSLFTPControlSocket] 20 ??? 2013 10:28:42.209 : ALLOW_BASIC_CONSTRAINTS_IN_NON_CA=false
DEBUG [FTPControlSocket] 20 ??? 2013 10:28:42.209 : ---> USER SynFTP
DEBUG [FTPControlSocket] 20 ??? 2013 10:28:42.240 : 331 Password required for SynFTP.
DEBUG [FTPControlSocket] 20 ??? 2013 10:28:42.240 : ---> PASS ********
DEBUG [FTPControlSocket] 20 ??? 2013 10:28:42.256 : 230-Syneron Welcome
DEBUG [FTPControlSocket] 20 ??? 2013 10:28:42.475 : 230 User SynFTP logged in.
DEBUG [FTPControlSocket] 20 ??? 2013 10:28:42.475 : ---> TYPE I
DEBUG [FTPControlSocket] 20 ??? 2013 10:28:42.803 : 200 Type set to I.
DEBUG [FTPControlSocket] 20 ??? 2013 10:28:42.803 : ---> SYST
DEBUG [FTPControlSocket] 20 ??? 2013 10:28:42.834 : 215 Windows_NT
DEBUG [FTPFileFactory] 20 ??? 2013 10:28:42.834 : Selected Windows parser
DEBUG [FTPClient] 20 ??? 2013 10:28:42.834 : Set new FTPFileFactory: com.enterprisedt.net.ftp.WindowsFileParser
DEBUG [FTPControlSocket] 20 ??? 2013 10:28:42.834 : ---> SYST
DEBUG [FTPControlSocket] 20 ??? 2013 10:28:42.850 : 215 Windows_NT
DEBUG [FTPControlSocket] 20 ??? 2013 10:28:42.850 : ---> SYST
DEBUG [FTPControlSocket] 20 ??? 2013 10:28:42.865 : 215 Windows_NT
DEBUG [MVSFileParser] 20 ??? 2013 10:28:42.865 : Ignoring the set locale.
DEBUG [FTPControlSocket] 20 ??? 2013 10:28:42.865 : ---> PWD
DEBUG [FTPControlSocket] 20 ??? 2013 10:28:42.897 : 257 "/" is current directory.
DEBUG [FTPClient] 20 ??? 2013 10:28:42.897 : setupDirDetails(/LocalUser/Public) returning: ///LocalUser/Public
DEBUG [FTPControlSocket] 20 ??? 2013 10:28:42.897 : ---> PASV
DEBUG [FTPControlSocket] 20 ??? 2013 10:28:42.912 : 227 Entering Passive Mode (91,199,99,72,215,9).
INFO [FTPControlSocket] 20 ??? 2013 10:28:42.912 : Substituting server supplied IP (91.199.99.72) with remote host IP (91.199.99.72)
DEBUG [StreamSocketFactory] 20 ??? 2013 10:28:42.912 : Connecting to 91.199.99.72:55049 via standard socket
DEBUG [SSLFTPControlSocket] 20 ??? 2013 10:28:42.944 : Creating FTPPassiveDataSocket
DEBUG [FTPControlSocket] 20 ??? 2013 10:28:42.944 : ---> LIST /LocalUser/Public
DEBUG [FTPControlSocket] 20 ??? 2013 10:28:42.959 : 125 Data connection already open; Transfer starting.
DEBUG [FTPControlSocket] 20 ??? 2013 10:28:43.178 : 226 Transfer complete.
DEBUG [FTPControlSocket] 20 ??? 2013 10:28:43.194 : ---> QUIT
DEBUG [FTPControlSocket] 20 ??? 2013 10:28:43.209 : 221 Syneron Bye Bye


DEBUG [SSLFTPClient] 20 ??? 2013 10:29:41.209 : Setting custom validator to com.enterprisedt.net.ftp.ssl.SSLFTPStandardValidator
DEBUG [SSLFTPClient] 20 ??? 2013 10:29:41.209 : Turned server validation off
DEBUG [SSLFTPClient] 20 ??? 2013 10:29:41.209 : Created explicit FTPS client.
DEBUG [SSLFTPClient] 20 ??? 2013 10:29:41.209 : Connecting to 91.199.99.72:1924
DEBUG [StreamSocketFactory] 20 ??? 2013 10:29:41.209 : Connecting to 91.199.99.72:1924 via standard socket
DEBUG [SSLSocket] 20 ??? 2013 10:29:41.225 : Timeout=0

Above I have given last two iterations of open,LIST and QUIT (2nd thread operations). Observe that in the 2nd set, after Timeout=0, we don't have any other log in the log file where as prior to 10:29:41, we had the complete set of USER,SYST,LIST,QUIT commands being executed.

We are using quit() method to close the connection. Do you suggest us to use quitImmediately() or any other method control the sockets? Please assist us on the same.

Awaiting your answer.
Thank you.
- Bhagyashree
no avatar
User

support2

Posts

3987

Joined

Tue May 18, 2004 8:30 am

by support2 » Wed May 22, 2013 5:21 pm

Connecting to 91.199.99.72:1924 via standard socket
DEBUG [SSLSocket] 20 ??? 2013 10:29:41.225 : Timeout=0

Looks to me like it isn't connecting successfully. Because you have an infinite timeout, it hangs.
no avatar
User

bhagyadesai

Posts

7

Joined

Mon Jun 25, 2012 6:20 pm

Problem Soved!

by bhagyadesai » Fri Jun 07, 2013 5:16 pm

no avatar
User

bhagyadesai

Posts

7

Joined

Mon Jun 25, 2012 6:20 pm

by bhagyadesai » Tue Aug 06, 2013 3:44 pm

no avatar
User

support2

Posts

3987

Joined

Tue May 18, 2004 8:30 am

by support2 » Wed Aug 07, 2013 4:25 pm

no avatar
User

bhagyadesai

Posts

7

Joined

Mon Jun 25, 2012 6:20 pm

by bhagyadesai » Wed Aug 07, 2013 5:02 pm

no avatar
User

support2

Posts

3987

Joined

Tue May 18, 2004 8:30 am

by support2 » Thu Aug 08, 2013 10:43 pm


Who is online

Users browsing this forum: No registered users and 19 guests

Powered by phpBB ® | phpBB3 Style by KomiDesign
cron