I am using edtFTPj-free (ver 2.0.0) and JDK 1.4.2_08 to connect to an FTP server to upload files.
The FTP Server and system details are as below (as obtained from Windows FTP client):
ftp> open zosnq
Connected to zosnq.myplace.com.
220-IPFTPD1 IBM FTP CS V1R8 at ZOSNQ, 14:31:27 on 2008-01-24.
220 Connection will close if idle for more than 5 minutes.
User (zosnq.myplace.com:(none)): guest1
331 Send password please.
Password:
230 GUEST1 is logged on. Working directory is "GUEST1.".
ftp> QUOTE SYST
215 MVS is the operating system of this server. FTP Server is running on z/OS.
ftp> pwd
257 "'GUEST1.'" is working directory.
I continuosly upload files to this FTP server in a loop.
After some time (inconsistent), the file upload just dies out. There is no error messages received/logged from the EDT API.
I have pasted the relevant sections of the log file wherein you could see one successful transfer followed by the failure.
After the "STOR" command, nothing is recorded and the java program is no more alive.
DEBUG [TRANSFER_FTP_LOGGER] 20 Mar 2008 11:58:51.339 : --------------------------------------------------------------------
DEBUG [TRANSFER_FTP_LOGGER] 20 Mar 2008 11:58:51.339 : New FileTransferClient object instantiated.
DEBUG [TRANSFER_FTP_LOGGER] 20 Mar 2008 11:58:51.339 : Authentication params set. RemoteHost=ZOSNQ, User=GUEST1
DEBUG [TRANSFER_FTP_LOGGER] 20 Mar 2008 11:58:51.339 : Setting the connection mode to: Passive
DEBUG [TRANSFER_FTP_LOGGER] 20 Mar 2008 11:58:51.339 : Setting the timeout value to: 60000
DEBUG [FileTransferClient] 20 Mar 2008 11:58:51.417 : Configured client
DEBUG [FTPClient] 20 Mar 2008 11:58:51.417 : Connecting to ZOSNQ/xxx.xxx.xxx.xxx:21
DEBUG [SocketUtils] 20 Mar 2008 11:58:51.479 : Invoking connect with timeout=60000
DEBUG [SocketUtils] 20 Mar 2008 11:58:51.495 : Connected successfully
DEBUG [FTPControlSocket] 20 Mar 2008 11:58:51.511 : 220-IPFTPD1 IBM FTP CS V1R8 at ZOSNQ, 11:58:51 on 2008-03-20.
DEBUG [FTPControlSocket] 20 Mar 2008 11:58:51.511 : 220 Connection will close if idle for more than 5 minutes.
DEBUG [FileTransferClient] 20 Mar 2008 11:58:51.511 : Client connected
DEBUG [FileTransferClient] 20 Mar 2008 11:58:51.511 : Logging in
DEBUG [FTPControlSocket] 20 Mar 2008 11:58:51.511 : ---> USER GUEST1
DEBUG [FTPControlSocket] 20 Mar 2008 11:58:51.682 : 331 Send password please.
DEBUG [FTPControlSocket] 20 Mar 2008 11:58:51.682 : ---> PASS ********
DEBUG [FTPControlSocket] 20 Mar 2008 11:58:51.823 : 230 GUEST1 is logged on. Working directory is "GUEST1.".
DEBUG [FileTransferClient] 20 Mar 2008 11:58:51.823 : Logged in
DEBUG [FTPControlSocket] 20 Mar 2008 11:58:51.823 : ---> TYPE I
DEBUG [FTPControlSocket] 20 Mar 2008 11:58:51.823 : 200 Representation type is Image
DEBUG [TRANSFER_FTP_LOGGER] 20 Mar 2008 11:58:51.823 : Connected to ftp server: true
DEBUG [FTPControlSocket] 20 Mar 2008 11:58:51.823 : ---> TYPE I
DEBUG [FTPControlSocket] 20 Mar 2008 11:58:51.839 : 200 Representation type is Image
DEBUG [TRANSFER_FTP_LOGGER] 20 Mar 2008 11:58:51.839 : Transfer module invoked to transfer dataStreamCd:fcts,batchId:b00362
DEBUG [TRANSFER_FTP_LOGGER] 20 Mar 2008 11:58:51.948 : Execute command: SITE LRECL=300 BLKSIZE=3000 RECFM=FB
DEBUG [FTPControlSocket] 20 Mar 2008 11:58:51.948 : ---> SITE LRECL=300 BLKSIZE=3000 RECFM=FB
DEBUG [FTPControlSocket] 20 Mar 2008 11:58:51.964 : 200 SITE command was accepted
DEBUG [TRANSFER_FTP_LOGGER] 20 Mar 2008 11:58:51.964 : Execute command: SITE CYL PRI=1 SEC=1
DEBUG [FTPControlSocket] 20 Mar 2008 11:58:51.964 : ---> SITE CYL PRI=1 SEC=1
DEBUG [FTPControlSocket] 20 Mar 2008 11:58:51.964 : 200 SITE command was accepted
DEBUG [TRANSFER_FTP_LOGGER] 20 Mar 2008 11:58:51.964 : uploading file: e:/DATA/RETI/FCTS/rxt.ibt.fcts.b00362.d0984658.zip.out
DEBUG [FTPControlSocket] 20 Mar 2008 11:58:51.964 : ---> PASV
DEBUG [FTPControlSocket] 20 Mar 2008 11:58:51.979 : 227 Entering Passive Mode (xxx.xxx.xxx.xxx,12,87)
DEBUG [FTPControlSocket] 20 Mar 2008 11:58:51.979 : Substituting server supplied IP (xxx.xxx.xxx.xxx) with remote host IP (xxx.xxx.xxx.xxx)
DEBUG [FTPControlSocket] 20 Mar 2008 11:58:51.979 : ---> STOR 'rxt.ibt.fcts.b00362.d0984658.zip.out'
DEBUG [FTPControlSocket] 20 Mar 2008 11:58:52.89 : 125 Storing data set RXT.IBT.FCTS.B00362.D0984658.ZIP.OUT
DEBUG [FTPClient] 20 Mar 2008 11:58:52.104 : Transferred 976 bytes to remote host
DEBUG [FTPControlSocket] 20 Mar 2008 11:58:52.276 : 250 Transfer completed successfully.
...
...
...
DEBUG [TRANSFER_FTP_LOGGER] 20 Mar 2008 12:00:24.372 : Execute command: SITE CYL PRI=1 SEC=1
DEBUG [FTPControlSocket] 20 Mar 2008 12:00:24.372 : ---> SITE CYL PRI=1 SEC=1
DEBUG [FTPControlSocket] 20 Mar 2008 12:00:24.372 : 200 SITE command was accepted
DEBUG [TRANSFER_FTP_LOGGER] 20 Mar 2008 12:00:24.419 : uploading file: e:/DATA/RETI/FCTS/rxt.ibt.fcts.b00362.d0984905.zip.out
DEBUG [FTPControlSocket] 20 Mar 2008 12:00:24.450 : ---> PASV
DEBUG [FTPControlSocket] 20 Mar 2008 12:00:24.450 : 227 Entering Passive Mode (xxx.xxx.xxx.xxx,14,154)
DEBUG [FTPControlSocket] 20 Mar 2008 12:00:24.450 : Substituting server supplied IP (xxx.xxx.xxx.xxx) with remote host IP (xxx.xxx.xxx.xxx)
DEBUG [FTPControlSocket] 20 Mar 2008 12:00:24.465 : ---> STOR 'rxt.ibt.fcts.b00362.d0984905.zip.out'
DEBUG [FTPControlSocket] 20 Mar 2008 12:00:24.684 : 125 Storing data set RXT.IBT.FCTS.B00362.D0984905.ZIP.OUT
DEBUG [FTPClient] 20 Mar 2008 12:00:24.684 : Transferred 829 bytes to remote host
DEBUG [FTPControlSocket] 20 Mar 2008 12:00:24.919 : 250 Transfer completed successfully.
DEBUG [TRANSFER_FTP_LOGGER] 20 Mar 2008 12:00:24.919 : Execute command: SITE CYL PRI=1 SEC=1
DEBUG [FTPControlSocket] 20 Mar 2008 12:00:24.919 : ---> SITE CYL PRI=1 SEC=1
DEBUG [FTPControlSocket] 20 Mar 2008 12:00:24.934 : 200 SITE command was accepted
DEBUG [TRANSFER_FTP_LOGGER] 20 Mar 2008 12:00:24.934 : uploading file: e:/DATA/RETI/FCTS/rxt.ibt.fcts.b00362.d0984906.zip.out
DEBUG [FTPControlSocket] 20 Mar 2008 12:00:24.950 : ---> PASV
DEBUG [FTPControlSocket] 20 Mar 2008 12:00:24.981 : 227 Entering Passive Mode (xxx.xxx.xxx.xxx,14,160)
DEBUG [FTPControlSocket] 20 Mar 2008 12:00:24.981 : Substituting server supplied IP (xxx.xxx.xxx.xxx) with remote host IP (xxx.xxx.xxx.xxx)
DEBUG [FTPControlSocket] 20 Mar 2008 12:00:24.981 : ---> STOR 'rxt.ibt.fcts.b00362.d0984906.zip.out'
(NOTHING GETS RECORDED IN THE LOG AFTER THIS LINE)
Note: This is an intermittent issue and once we restart the transfer process, things work fine for sometime before this happens again.
Questions:
1. The last line of the logs state that STOR command is being issued. Could it be that ftpClient.readReply does not process the response after this?
2. Could you please recommend a way to debug this further?
3. Could this be related to the fix you have added to the replyCode=421 in the latest release of the library?
Thanks.
