It seems it is happening exactly an hour after the upload begins. Any timeouts that could be kicking in. The connections are not idle.
-----Original Message----- From: Sachin Shetty [mailto:sshe...@egnyte.com] Sent: Monday, September 17, 2012 8:14 PM To: 'Sachin Shetty'; 'ftpserver-users@mina.apache.org' Subject: RE: GnuTLS internal error in Filezilla I enabled debug and found this to be the problem. INFO 2012-09-17 14:27:43,030 pool-6-thread-18 D- U- S- org.apache.ftpserver.listener.nio.FtpLoggingFilter - RECEIVED: STOR source_2364.txt DEBUG 2012-09-17 14:27:43,148 pool-6-thread-21 D- U- S- org.apache.ftpserver.command.impl.STOR - Exception getting the input data stream javax.net.ssl.SSLException: illegal change cipher spec msg, state = 1 at com.sun.net.ssl.internal.ssl.Alerts.getSSLException(Alerts.java:190) at com.sun.net.ssl.internal.ssl.SSLSocketImpl.fatal(SSLSocketImpl.java:1611) at com.sun.net.ssl.internal.ssl.SSLSocketImpl.fatal(SSLSocketImpl.java:1569) at com.sun.net.ssl.internal.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:940 ) at com.sun.net.ssl.internal.ssl.SSLSocketImpl.performInitialHandshake(SSLSocket Impl.java:1112) at com.sun.net.ssl.internal.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java :1139) at com.sun.net.ssl.internal.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java :1123) at org.apache.ftpserver.impl.IODataConnectionFactory.createDataSocket(IODataCon nectionFactory.java:391) at org.apache.ftpserver.impl.IODataConnectionFactory.openConnection(IODataConne ctionFactory.java:259) at org.apache.ftpserver.command.impl.STOR.execute(STOR.java:133) at org.apache.ftpserver.impl.DefaultFtpHandler.messageReceived(DefaultFtpHandle r.java:211) at org.apache.ftpserver.listener.nio.FtpHandlerAdapter.messageReceived(FtpHandl erAdapter.java:62) at org.apache.mina.core.filterchain.DefaultIoFilterChain$TailFilter.messageRece ived(DefaultIoFilterChain.java:716) at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceive d(DefaultIoFilterChain.java:434) at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoF ilterChain.java:46) at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageRec eived(DefaultIoFilterChain.java:796) at org.apache.ftpserver.listener.nio.FtpLoggingFilter.messageReceived(FtpLoggin gFilter.java:85) at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceive d(DefaultIoFilterChain.java:434) at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoF ilterChain.java:46) at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageRec eived(DefaultIoFilterChain.java:796) at org.apache.mina.core.filterchain.IoFilterEvent.fire(IoFilterEvent.java:75) at org.apache.mina.filter.logging.MdcInjectionFilter.filter(MdcInjectionFilter. java:136) at org.apache.mina.filter.util.CommonEventFilter.messageReceived(CommonEventFil ter.java:70) at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceive d(DefaultIoFilterChain.java:434) at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoF ilterChain.java:46) at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageRec eived(DefaultIoFilterChain.java:796) at org.apache.mina.filter.codec.ProtocolCodecFilter$ProtocolDecoderOutputImpl.f lush(ProtocolCodecFilter.java:427) at org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCod ecFilter.java:245) at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceive d(DefaultIoFilterChain.java:434) at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoF ilterChain.java:46) at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageRec eived(DefaultIoFilterChain.java:796) at org.apache.mina.core.filterchain.IoFilterEvent.fire(IoFilterEvent.java:75) at org.apache.mina.core.session.IoEvent.run(IoEvent.java:63) at org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.runTask(Ord eredThreadPoolExecutor.java:780) at org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.runTasks(Or deredThreadPoolExecutor.java:772) at org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.run(Ordered ThreadPoolExecutor.java:714) at java.lang.Thread.run(Thread.java:619) DEBUG 2012-09-17 14:27:43,148 pool-6-thread-21 D- U- S- org.apache.ftpserver.command.impl.STOR - Exception getting the input data stream javax.net.ssl.SSLException: illegal change cipher spec msg, state = 1 at com.sun.net.ssl.internal.ssl.Alerts.getSSLException(Alerts.java:190) at com.sun.net.ssl.internal.ssl.SSLSocketImpl.fatal(SSLSocketImpl.java:1611) at com.sun.net.ssl.internal.ssl.SSLSocketImpl.fatal(SSLSocketImpl.java:1569) at com.sun.net.ssl.internal.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:940 ) at com.sun.net.ssl.internal.ssl.SSLSocketImpl.performInitialHandshake(SSLSocket Impl.java:1112) at com.sun.net.ssl.internal.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java :1139) at com.sun.net.ssl.internal.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java :1123) at org.apache.ftpserver.impl.IODataConnectionFactory.createDataSocket(IODataCon nectionFactory.java:391) at org.apache.ftpserver.impl.IODataConnectionFactory.openConnection(IODataConne ctionFactory.java:259) at org.apache.ftpserver.command.impl.STOR.execute(STOR.java:133) at org.apache.ftpserver.impl.DefaultFtpHandler.messageReceived(DefaultFtpHandle r.java:211) at org.apache.ftpserver.listener.nio.FtpHandlerAdapter.messageReceived(FtpHandl erAdapter.java:62) at org.apache.mina.core.filterchain.DefaultIoFilterChain$TailFilter.messageRece ived(DefaultIoFilterChain.java:716) at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceive d(DefaultIoFilterChain.java:434) at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoF ilterChain.java:46) at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageRec eived(DefaultIoFilterChain.java:796) at org.apache.ftpserver.listener.nio.FtpLoggingFilter.messageReceived(FtpLoggin gFilter.java:85) at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceive d(DefaultIoFilterChain.java:434) at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoF ilterChain.java:46) at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageRec eived(DefaultIoFilterChain.java:796) at org.apache.mina.core.filterchain.IoFilterEvent.fire(IoFilterEvent.java:75) at org.apache.mina.filter.logging.MdcInjectionFilter.filter(MdcInjectionFilter. java:136) at org.apache.mina.filter.util.CommonEventFilter.messageReceived(CommonEventFil ter.java:70) at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceive d(DefaultIoFilterChain.java:434) at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoF ilterChain.java:46) at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageRec eived(DefaultIoFilterChain.java:796) at org.apache.mina.filter.codec.ProtocolCodecFilter$ProtocolDecoderOutputImpl.f lush(ProtocolCodecFilter.java:427) at org.apache.mina.filter.codec.ProtocolCodecFilter.messageReceived(ProtocolCod ecFilter.java:245) at org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceive d(DefaultIoFilterChain.java:434) at org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoF ilterChain.java:46) at org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageRec eived(DefaultIoFilterChain.java:796) at org.apache.mina.core.filterchain.IoFilterEvent.fire(IoFilterEvent.java:75) at org.apache.mina.core.session.IoEvent.run(IoEvent.java:63) at org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.runTask(Ord eredThreadPoolExecutor.java:780) at org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.runTasks(Or deredThreadPoolExecutor.java:772) at org.apache.mina.filter.executor.OrderedThreadPoolExecutor$Worker.run(Ordered ThreadPoolExecutor.java:714) at java.lang.Thread.run(Thread.java:619) -----Original Message----- From: Sachin Shetty [mailto:sshe...@egnyte.com] Sent: Monday, September 17, 2012 4:27 PM To: 'ftpserver-users@mina.apache.org' Subject: RE: GnuTLS internal error in Filezilla Here is the client log, it works fine for almost an hour before it hits the "Error: GnuTLS error -59: GnuTLS internal error." and then all of them fail Response: 227 Entering Passive Mode (173,245,120,49,78,44) Command: STOR source_2561.txt Response: 150 File status okay; about to open data connection. Response: 150 File status okay; about to open data connection. Response: 226 Transfer complete. Command: MFMT 20111108075428 source_2560.txt Response: 226 Transfer complete. Command: MFMT 20111108075402 source_256.txt Response: 150 File status okay; about to open data connection. Response: 213 ModifyTime=20111108075428; source_2560.txt Status: File transfer successful, transferred 16 bytes in 5 seconds Status: Starting upload of C:\sachin\temp\5k_folder\source_2562.txt Command: PASV Response: 213 ModifyTime=20111108075402; source_256.txt Status: File transfer successful, transferred 16 bytes in 5 seconds Status: Starting upload of C:\sachin\temp\5k_folder\source_2563.txt Command: PASV Response: 227 Entering Passive Mode (173,245,120,49,78,32) Command: STOR source_2562.txt Response: 227 Entering Passive Mode (173,245,120,49,78,42) Command: STOR source_2563.txt Response: 226 Transfer complete. Command: MFMT 20111108075428 source_2561.txt Response: 213 ModifyTime=20111108075428; source_2561.txt Status: File transfer successful, transferred 16 bytes in 4 seconds Status: Starting upload of C:\sachin\temp\5k_folder\source_2564.txt Command: PASV Response: 227 Entering Passive Mode (173,245,120,49,78,50) Command: STOR source_2564.txt Response: 150 File status okay; about to open data connection. Response: 150 File status okay; about to open data connection. Error: GnuTLS error -59: GnuTLS internal error. Error: GnuTLS error -59: GnuTLS internal error. Response: 425 Can't open data connection. Error: File transfer failed Status: Starting upload of C:\sachin\temp\5k_folder\source_2562.txt Status: Retrieving directory listing... Command: PASV Response: 425 Can't open data connection. Error: File transfer failed Status: Starting upload of C:\sachin\temp\5k_folder\source_2563.txt Status: Retrieving directory listing... Response: 227 Entering Passive Mode (173,245,120,49,78,32) Command: MLSD Response: 150 File status okay; about to open data connection. Response: 150 File status okay; about to open data connection. Error: GnuTLS error -59: GnuTLS internal error. Error: Transfer connection interrupted: ECONNABORTED - Connection aborted Error: GnuTLS error -59: GnuTLS internal error. Response: 425 Can't open data connection. Command: SIZE source_2562.txt Error: File transfer failed Status: Starting upload of C:\sachin\temp\5k_folder\source_2563.txt Status: Retrieving directory listing... -----Original Message----- From: John Hartnup [mailto:john.hart...@gmail.com] Sent: Monday, September 17, 2012 4:05 PM To: ftpserver-users@mina.apache.org Subject: Re: GnuTLS internal error in Filezilla Get either client or server logs that show the PORT/PASV addresses. See if there's any pattern in the working/broken port ranges. One fairly common issue is that the firewall has a range of ports open, that's smaller than the range the FTP client/server will try to use. So everything works fine, until eventually a port outside the range is requested. On 17 September 2012 11:27, Sachin Shetty <sshe...@egnyte.com> wrote: > Thanks for the response. > > It only stops working intermittently and interesting this is the immediate > error in the FtpLoggingFilter > > INFO 2012-09-16 11:32:56,015 pool-6-thread-19630 D- U- S- > org.apache.ftpserver.listener.nio.FtpLoggingFilter - SENT: 150 File status > okay; about to open data connection.^M > INFO 2012-09-16 11:32:56,015 pool-6-thread-19630 D- U- S- > org.apache.ftpserver.listener.nio.FtpLoggingFilter - SENT: 425 Can't open > data connection.^M > > Something happens in between the two log lines. > > > -----Original Message----- > From: John Hartnup [mailto:john.hart...@gmail.com] > Sent: Monday, September 17, 2012 3:42 PM > To: ftpserver-users@mina.apache.org > Subject: Re: GnuTLS internal error in Filezilla > > It looks to me like a firewall blocking the data connection. > > Some firewalls deal with FTP by snooping on the control connection, and > opening the appropriate ports when it sees a PORT or PASV command/response. > If the control connection is secured with SSL, the firewall can't see > PORT/PASV, so it doesn't open the ports. > > This IETF draft goes into some detail (or skip to the appendix to find out > how to fix it). > > On 17 September 2012 10:55, Sachin Shetty <sshe...@egnyte.com> wrote: > > > Hi, > > > > > > > > Any inputs on 425 Can't open data connection is really appreciated. It's > > causing lot of problems and we aren't sure what we else we can look for. > > > > > > > > Thanks > > > > Sachin > > > > > > > > From: Sachin Shetty [mailto:sshe...@egnyte.com] > > Sent: Friday, September 07, 2012 1:35 PM > > To: 'ftpserver-users@mina.apache.org' > > Subject: GnuTLS internal error in Filezilla > > > > > > > > Hi, > > > > We have Apache FTP Server running in production for a while now, it's > been > > mostly rock solid, but we see the following issue pretty often in > > production. > > > > Response: 150 File status okay; about to open data connection. > > Error: GnuTLS error -59: GnuTLS internal error. > > Response: 425 Can't open data connection. > > Error: File transfer failed > > > > On the apache ftp server logs, all we see is: > > > > INFO 2012-09-05 05:04:16,087 pool-3-thread-350 D- U- S- > > org.apache.ftpserver.listener.nio.FtpLoggingFilter - SENT: 425 Can't open > > data connection.^M > > > > Could it be one of the following: > > > > 1. All passive ports exhausted > > > > 2. We have a slightly different configuration, where we start 2 > listeners, > > one with implicit SSL and one without. Both have the same passive port > > range. > > > > Thanks > > Sachin > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > > -- > "There is no way to peace; peace is the way" > > -- "There is no way to peace; peace is the way"