Hi all,
We used to FtpServer v1.0.6 to develop our own FTP solution.
One of our users has 3 types of errors : he uses a batch to download
files with Filezilla, WinSCP or lftp
20140723000030:12:30:21.794000 == Info: response reading failed
20140723000037:12:30:35.663000 == Info: error:14094410:SSL
routines:SSL3_READ_BYTES:sslv3 alert handshake failure
20140723000049:12:31:02.808000 == Info: response reading failed
20140723000050:12:31:03.417000 == Info: response reading failed
20140723000051:12:31:02.760000 == Info: error:14094410:SSL
routines:SSL3_READ_BYTES:sslv3 alert handshake failure
20140723000052:12:31:05.413000 == Info: response reading faile
20140723000122:12:32:02.165000 == Info: response reading failed
20140723000124:12:32:04.552000 == Info: error:14094410:SSL
routines:SSL3_READ_BYTES:sslv3 alert handshake failure
20140723000133:12:32:23.771000 == Info: response reading failed
20140724000000:12:32:27.626000 == Info: SSL read: error:1408F119:SSL
routines:SSL3_GET_RECORD:decryption failed or bad record mac, errno 0
20140724000005:12:32:36.485000 == Info: SSL read: error:1408F119:SSL
routines:SSL3_GET_RECORD:decryption failed or bad record mac, errno 0
On the side of FTP server (our software), errors occurs at different
moment of the download :
(these errors are not systematic)
- on RETR command
[2014-09-12 14:15:55,672] INFO
org.apache.ftpserver.listener.nio.FtpLoggingFilter - RECEIVED: RETR
20140723000050
[2014-09-12 14:15:56,387] INFO
fr.valerian.webank.ft.mina.ftp.ftplet.WeBankFtplet - DOWNLOAD du fichier
20140723000050 execute en 0 s
[2014-09-12 14:15:56,387] INFO
org.apache.ftpserver.listener.nio.FtpLoggingFilter - SENT: 150 Getting
data connection.^M
[2014-09-12 14:15:56,387] INFO
org.apache.ftpserver.listener.nio.FtpLoggingFilter - SENT: 226 Data
transfer okay.^M
[2014-09-12 14:15:56,458] WARN
org.apache.ftpserver.listener.nio.FtpLoggingFilter - EXCEPTION :
javax.net.ssl.SSLException: Invalid Padding length: 189
at sun.security.ssl.Alerts.getSSLException(Alerts.java:208)
at sun.security.ssl.SSLEngineImpl.fatal(SSLEngineImpl.java:1683)
at
sun.security.ssl.SSLEngineImpl.readRecord(SSLEngineImpl.java:959)
at
sun.security.ssl.SSLEngineImpl.readNetRecord(SSLEngineImpl.java:884)
at sun.security.ssl.SSLEngineImpl.unwrap(SSLEngineImpl.java:758)
at javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:624)
at
org.apache.mina.filter.ssl.SslHandler.unwrap(SslHandler.java:725)
at
org.apache.mina.filter.ssl.SslHandler.messageReceived(SslHandler.java:358)
at
org.apache.mina.filter.ssl.SslFilter.messageReceived(SslFilter.java:476)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:46)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:796)
at
org.apache.mina.core.filterchain.IoFilterAdapter.messageReceived(IoFilterAdapter.java:119)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.fireMessageReceived(DefaultIoFilterChain.java:426)
at
org.apache.mina.core.polling.AbstractPollingIoProcessor.read(AbstractPollingIoProcessor.java:715)
at
org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:668)
at
org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:657)
at
org.apache.mina.core.polling.AbstractPollingIoProcessor.access$600(AbstractPollingIoProcessor.java:68)
at
org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractPollingIoProcessor.java:1141)
at
org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
Caused by: javax.crypto.BadPaddingException: Invalid Padding length: 189
at sun.security.ssl.CipherBox.removePadding(CipherBox.java:729)
at sun.security.ssl.CipherBox.decrypt(CipherBox.java:494)
at
sun.security.ssl.EngineInputRecord.decrypt(EngineInputRecord.java:210)
at
sun.security.ssl.SSLEngineImpl.readRecord(SSLEngineImpl.java:953)
... 21 more
[2014-09-12 14:15:56,459] ERROR
org.apache.ftpserver.impl.DefaultFtpHandler - Exception caught, closing
session
- on PASV command
[2014-09-12 14:16:24,032] INFO
org.apache.ftpserver.listener.nio.FtpLoggingFilter - RECEIVED: PASV
[2014-09-12 14:16:24,033] INFO
org.apache.ftpserver.listener.nio.FtpLoggingFilter - SENT: 227 Entering
Passive Mode (192,168,241,88,23,114)^M
[2014-09-12 14:16:24,106] WARN
org.apache.ftpserver.listener.nio.FtpLoggingFilter - EXCEPTION :
javax.net.ssl.SSLException: Invalid Padding length: 200
at sun.security.ssl.Alerts.getSSLException(Alerts.java:208)
at sun.security.ssl.SSLEngineImpl.fatal(SSLEngineImpl.java:1683)
at
sun.security.ssl.SSLEngineImpl.readRecord(SSLEngineImpl.java:959)
at
sun.security.ssl.SSLEngineImpl.readNetRecord(SSLEngineImpl.java:884)
at sun.security.ssl.SSLEngineImpl.unwrap(SSLEngineImpl.java:758)
at javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:624)
at
org.apache.mina.filter.ssl.SslHandler.unwrap(SslHandler.java:725)
at
org.apache.mina.filter.ssl.SslHandler.messageReceived(SslHandler.java:358)
at
org.apache.mina.filter.ssl.SslFilter.messageReceived(SslFilter.java:476)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:46)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:796)
at
org.apache.mina.core.filterchain.IoFilterAdapter.messageReceived(IoFilterAdapter.java:119)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.fireMessageReceived(DefaultIoFilterChain.java:426)
at
org.apache.mina.core.polling.AbstractPollingIoProcessor.read(AbstractPollingIoProcessor.java:715)
at
org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:668)
at
org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:657)
at
org.apache.mina.core.polling.AbstractPollingIoProcessor.access$600(AbstractPollingIoProcessor.java:68)
at
org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractPollingIoProcessor.java:1141)
at
org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
Caused by: javax.crypto.BadPaddingException: Invalid Padding length: 200
at sun.security.ssl.CipherBox.removePadding(CipherBox.java:729)
at sun.security.ssl.CipherBox.decrypt(CipherBox.java:494)
at
sun.security.ssl.EngineInputRecord.decrypt(EngineInputRecord.java:210)
at
sun.security.ssl.SSLEngineImpl.readRecord(SSLEngineImpl.java:953)
... 21 more
[2014-09-12 14:16:24,106] ERROR
org.apache.ftpserver.impl.DefaultFtpHandler - Exception caught, closing
session
- on USER command
[2014-09-12 14:17:36,425] INFO
org.apache.ftpserver.listener.nio.FtpLoggingFilter - RECEIVED: USER EFQCPW17
[2014-09-12 14:17:36,446] INFO
org.apache.ftpserver.listener.nio.FtpLoggingFilter - SENT: 331 User name
okay, need password for EFQCPW17.^M
[2014-09-12 14:17:36,491] WARN
org.apache.ftpserver.listener.nio.FtpLoggingFilter - EXCEPTION :
javax.net.ssl.SSLException: Invalid TLS padding data
at sun.security.ssl.Alerts.getSSLException(Alerts.java:208)
at sun.security.ssl.SSLEngineImpl.fatal(SSLEngineImpl.java:1683)
at
sun.security.ssl.SSLEngineImpl.readRecord(SSLEngineImpl.java:959)
at
sun.security.ssl.SSLEngineImpl.readNetRecord(SSLEngineImpl.java:884)
at sun.security.ssl.SSLEngineImpl.unwrap(SSLEngineImpl.java:758)
at javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:624)
at
org.apache.mina.filter.ssl.SslHandler.unwrap(SslHandler.java:725)
at
org.apache.mina.filter.ssl.SslHandler.messageReceived(SslHandler.java:358)
at
org.apache.mina.filter.ssl.SslFilter.messageReceived(SslFilter.java:476)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:46)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:796)
at
org.apache.mina.core.filterchain.IoFilterAdapter.messageReceived(IoFilterAdapter.java:119)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:434)
at
org.apache.mina.core.filterchain.DefaultIoFilterChain.fireMessageReceived(DefaultIoFilterChain.java:426)
at
org.apache.mina.core.polling.AbstractPollingIoProcessor.read(AbstractPollingIoProcessor.java:715)
at
org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:668)
at
org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:657)
at
org.apache.mina.core.polling.AbstractPollingIoProcessor.access$600(AbstractPollingIoProcessor.java:68)
at
org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractPollingIoProcessor.java:1141)
at
org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
Caused by: javax.crypto.BadPaddingException: Invalid TLS padding data
at sun.security.ssl.CipherBox.removePadding(CipherBox.java:738)
at sun.security.ssl.CipherBox.decrypt(CipherBox.java:494)
at
sun.security.ssl.EngineInputRecord.decrypt(EngineInputRecord.java:210)
at
sun.security.ssl.SSLEngineImpl.readRecord(SSLEngineImpl.java:953)
... 21 more
[2014-09-12 14:17:36,491] ERROR
org.apache.ftpserver.impl.DefaultFtpHandler - Exception caught, closing
session
Any ideas anyone ?
Thanks a lot.
Didier
--
<http://informatique.elcimai.com/solutions-bancaires>
*Didier IBIS*
Service Développement
Tél : 01 48 15 88 92
Email : di...@webank.fr
