[ 
https://issues.apache.org/jira/browse/DIRMINA-1044?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15495711#comment-15495711
 ] 

Emmanuel Lecharny commented on DIRMINA-1044:
--------------------------------------------

Many thanks for the in depth analysis. Indeed, there is a huge problem that 
needs to be fixed urgently.

Would you provide a unit test that can reproduce the problem ? That would help 
a lot debugging the SslFilter...

Thanks !

> Non-Secure (no TLS/SSL) based client could successfully send message to 
> secure Mina endpoint after second attempt
> -----------------------------------------------------------------------------------------------------------------
>
>                 Key: DIRMINA-1044
>                 URL: https://issues.apache.org/jira/browse/DIRMINA-1044
>             Project: MINA
>          Issue Type: Bug
>          Components: Filter
>    Affects Versions: 2.0.13, 2.0.14
>            Reporter: Thomas Papke
>
> Following scenario:
> - We have a server application using Mina2. This endpoint is configured with 
> Mina SSLFilter (clientAuth=MUST, no startTLS support)
> If a client application (not able to do any kind of SSL) try to connect, we 
> have identified the following.
> 1. TCP connection --> could be successfully established (might be Ok)
> {code}
> 2016-09-16T03:23:47,423 DEBUG [NioProcessor-21] 
> org.apache.mina.filter.ssl.SslFilter(432) - Adding the SSL Filter ssl to the 
> chain
> 2016-09-16T03:23:47,455 DEBUG [NioProcessor-21] 
> org.apache.mina.filter.ssl.SslHandler(147) - Session Server[2](no sslEngine) 
> Initializing the SSL Handler
> Using SSLEngineImpl.
> Allow unsafe renegotiation: false
> Allow legacy hello messages: true
> Is initial handshake: true
> Is secure renegotiation: false
> Ignoring unsupported cipher suite: TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA384 
> for TLSv1
> Ignoring unsupported cipher suite: TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA384 for 
> TLSv1
> Ignoring unsupported cipher suite: TLS_RSA_WITH_AES_256_CBC_SHA256 for TLSv1
> Ignoring unsupported cipher suite: TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA384 for 
> TLSv1
> Ignoring unsupported cipher suite: TLS_ECDH_RSA_WITH_AES_256_CBC_SHA384 for 
> TLSv1
> Ignoring unsupported cipher suite: TLS_DHE_RSA_WITH_AES_256_CBC_SHA256 for 
> TLSv1
> Ignoring unsupported cipher suite: TLS_DHE_DSS_WITH_AES_256_CBC_SHA256 for 
> TLSv1
> Ignoring unsupported cipher suite: TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA384 
> for TLSv1.1
> Ignoring unsupported cipher suite: TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA384 for 
> TLSv1.1
> Ignoring unsupported cipher suite: TLS_RSA_WITH_AES_256_CBC_SHA256 for TLSv1.1
> Ignoring unsupported cipher suite: TLS_ECDH_ECDSA_WITH_AES_256_CBC_SHA384 for 
> TLSv1.1
> Ignoring unsupported cipher suite: TLS_ECDH_RSA_WITH_AES_256_CBC_SHA384 for 
> TLSv1.1
> Ignoring unsupported cipher suite: TLS_DHE_RSA_WITH_AES_256_CBC_SHA256 for 
> TLSv1.1
> Ignoring unsupported cipher suite: TLS_DHE_DSS_WITH_AES_256_CBC_SHA256 for 
> TLSv1.1
> 2016-09-16T03:23:47,455 DEBUG [NioProcessor-21] 
> org.apache.mina.filter.ssl.SslHandler(198) - Session Server[2](no sslEngine) 
> SSL Handler Initialization done.
> 2016-09-16T03:23:47,455 DEBUG [NioProcessor-21] 
> org.apache.mina.filter.ssl.SslFilter(718) - Session Server[2](ssl...) : 
> Starting the first handshake
> 2016-09-16T03:23:47,455 DEBUG [NioProcessor-21] 
> org.apache.mina.filter.ssl.SslHandler(572) - Session Server[2](ssl...) 
> processing the NEED_UNWRAP state
> 2016-09-16T03:23:47,471 DEBUG [NioProcessor-21] 
> org.apache.mina.filter.executor.OrderedThreadPoolExecutor(432) - Adding event 
> SESSION_OPENED to session 2
> Queue : [SESSION_OPENED, ]
> 2016-09-16T03:23:47,471 DEBUG [pool-32-thread-1] 
> org.apache.mina.core.filterchain.IoFilterEvent(68) - Firing a SESSION_OPENED 
> event for session 2
> 2016-09-16T03:23:47,486 DEBUG [pool-32-thread-1] 
> org.apache.mina.core.filterchain.IoFilterEvent(117) - Event SESSION_OPENED 
> has been fired for session 2
> {code}
> 2. Client transmit some non-ssl encrypted payload --> client run into a 
> timeout, TCP connection remain open
> {code}
> 2016-09-16T03:24:04,693 DEBUG [NioProcessor-21] 
> org.apache.mina.filter.ssl.SslFilter(484) - Session Server[2](ssl...): 
> Message received : HeapBuffer[pos=0 lim=873 cap=2048: 0B 4D 53 48 7C 5E 7E 5C 
> 26 7C 4E 45 53 7C 4E 49...]
> 2016-09-16T03:24:04,693 DEBUG [NioProcessor-21] 
> org.apache.mina.filter.ssl.SslHandler(346) - Session Server[2](ssl...) 
> Processing the received message
> 2016-09-16T03:24:04,693 DEBUG [NioProcessor-21] 
> org.apache.mina.filter.ssl.SslHandler(572) - Session Server[2](ssl...) 
> processing the NEED_UNWRAP state
> NioProcessor-21, fatal error: 80: problem unwrapping net record
> javax.net.ssl.SSLException: Unrecognized SSL message, plaintext connection?
> NioProcessor-21, SEND TLSv1.2 ALERT:  fatal, description = internal_error
> NioProcessor-21, WRITE: TLSv1.2 Alert, length = 2
> 2016-09-16T03:24:04,694 DEBUG [NioProcessor-21] 
> org.apache.mina.filter.executor.OrderedThreadPoolExecutor(432) - Adding event 
> EXCEPTION_CAUGHT to session 2
> Queue : [EXCEPTION_CAUGHT, ]
> 2016-09-16T03:24:04,694 DEBUG [pool-32-thread-1] 
> org.apache.mina.core.filterchain.IoFilterEvent(68) - Firing a 
> EXCEPTION_CAUGHT event for session 2
> 2016-09-16T03:24:04,694 DEBUG [pool-32-thread-1] 
> org.apache.mina.core.filterchain.IoFilterEvent(117) - Event EXCEPTION_CAUGHT 
> has been fired for session 2
> {code}
> 3. Client tries a second attempt to send non-ssl encrypted payload --> *the 
> message successfully pass through to the application!*
> {code}
> 2016-09-16T03:25:52,521 DEBUG [NioProcessor-21] 
> org.apache.mina.filter.ssl.SslFilter(484) - Session Server[2](ssl...): 
> Message received : HeapBuffer[pos=0 lim=873 cap=2048: 0B 4D 53 48 7C 5E 7E 5C 
> 26 7C 4E 45 53 7C 4E 49...]
> 2016-09-16T03:25:52,521 DEBUG [NioProcessor-21] 
> org.apache.mina.filter.ssl.SslHandler(346) - Session Server[2](ssl...) 
> Processing the received message
> 2016-09-16T03:25:52,521 DEBUG [NioProcessor-21] 
> org.apache.mina.filter.ssl.SslHandler(572) - Session Server[2](ssl...) 
> processing the NEED_UNWRAP state
> 2016-09-16T03:25:52,521 DEBUG [NioProcessor-21] 
> org.apache.mina.filter.ssl.SslFilter(769) - Session Server[2](ssl...): 
> Processing the SSL Data 
> NioProcessor-21, called closeOutbound()
> NioProcessor-21, closeOutboundInternal()
> [Raw write]: length = 7
> 0000: 15 03 03 00 02 02 50                               ......P
> 2016-09-16T03:25:52,585 DEBUG [NioProcessor-21] 
> org.apache.mina.filter.ssl.SslFilter(608) - Session Server[2]: Writing 
> Message : WriteRequest: HeapBuffer[pos=0 lim=7 cap=8: 15 03 03 00 02 02 50]
> NioProcessor-21, called closeInbound()
> NioProcessor-21, fatal: engine already closed.  Rethrowing 
> javax.net.ssl.SSLException: Inbound closed before receiving peer's 
> close_notify: possible truncation attack?
> 2016-09-16T03:25:52,585 DEBUG [NioProcessor-21] 
> org.apache.mina.filter.ssl.SslHandler(215) - Unexpected exception from 
> SSLEngine.closeInbound().
> javax.net.ssl.SSLException: Inbound closed before receiving peer's 
> close_notify: possible truncation attack?
>       at sun.security.ssl.Alerts.getSSLException(Alerts.java:208) 
> ~[?:1.8.0_91]
>       at sun.security.ssl.SSLEngineImpl.fatal(SSLEngineImpl.java:1666) 
> ~[?:1.8.0_91]
>       at sun.security.ssl.SSLEngineImpl.fatal(SSLEngineImpl.java:1634) 
> ~[?:1.8.0_91]
>       at sun.security.ssl.SSLEngineImpl.closeInbound(SSLEngineImpl.java:1561) 
> ~[?:1.8.0_91]
>       at org.apache.mina.filter.ssl.SslHandler.destroy(SslHandler.java:213) 
> [mina-core-2.0.14.jar:?]
>       at 
> org.apache.mina.filter.ssl.SslFilter.initiateClosure(SslFilter.java:752) 
> [mina-core-2.0.14.jar:?]
>       at 
> org.apache.mina.filter.ssl.SslFilter.messageReceived(SslFilter.java:509) 
> [mina-core-2.0.14.jar:?]
>       at 
> org.openehealth.ipf.platform.camel.ihe.mllp.core.HandshakeCallbackSSLFilter.messageReceived(HandshakeCallbackSSLFilter.java:66)
>  [ipf-platform-camel-ihe-mllp-3.1.0.jar:?]
>       at 
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:542)
>  [mina-core-2.0.14.jar:?]
>       at 
> org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:48)
>  [mina-core-2.0.14.jar:?]
>       at 
> org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:947)
>  [mina-core-2.0.14.jar:?]
>       at 
> org.apache.mina.core.filterchain.IoFilterAdapter.messageReceived(IoFilterAdapter.java:109)
>  [mina-core-2.0.14.jar:?]
>       at 
> org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:542)
>  [mina-core-2.0.14.jar:?]
>       at 
> org.apache.mina.core.filterchain.DefaultIoFilterChain.fireMessageReceived(DefaultIoFilterChain.java:535)
>  [mina-core-2.0.14.jar:?]
>       at 
> org.apache.mina.core.polling.AbstractPollingIoProcessor.read(AbstractPollingIoProcessor.java:703)
>  [mina-core-2.0.14.jar:?]
>       at 
> org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:659)
>  [mina-core-2.0.14.jar:?]
>       at 
> org.apache.mina.core.polling.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:648)
>  [mina-core-2.0.14.jar:?]
>       at 
> org.apache.mina.core.polling.AbstractPollingIoProcessor.access$600(AbstractPollingIoProcessor.java:68)
>  [mina-core-2.0.14.jar:?]
>       at 
> org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractPollingIoProcessor.java:1120)
>  [mina-core-2.0.14.jar:?]
>       at 
> org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64)
>  [mina-core-2.0.14.jar:?]
>       at 
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
>  [?:1.8.0_91]
>       at 
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
>  [?:1.8.0_91]
>       at java.lang.Thread.run(Thread.java:745) [?:1.8.0_91]
> NioProcessor-21, called closeOutbound()
> NioProcessor-21, closeOutboundInternal()
> 2016-09-16T03:25:52,600 DEBUG [NioProcessor-21] 
> org.apache.mina.filter.codec.ProtocolCodecFilter(211) - Processing a 
> MESSAGE_RECEIVED for session 2
> 2016-09-16T03:25:52,632 DEBUG [NioProcessor-21] 
> org.apache.mina.filter.executor.OrderedThreadPoolExecutor(432) - Adding event 
> MESSAGE_RECEIVED to session 2
> Queue : [MESSAGE_RECEIVED, ]
> 2016-09-16T03:25:52,632 DEBUG [pool-32-thread-2] 
> org.apache.mina.core.filterchain.IoFilterEvent(68) - Firing a 
> MESSAGE_RECEIVED event for session 2
> {code}
> *Especially step 3 should never happen.* Instead I would expect that 
> somewhere in step 2 the connection to the client will be closed, because no 
> handshake could be done.
> We have already debugged a bit in the Mina SSL Filter and identified the 
> following:
> - During step 2, we see a SSLHandshakeException that will be thrown in the 
> {{org.apache.mina.filter.ssl.SslFilter.messageReceived(NextFilter, IoSession, 
> Object)}} method. But the SSL Filter seems to not handle such kind of 
> Exception ({{org.apache.mina.filter.ssl.SslFilter.exceptionCaught(NextFilter, 
> IoSession, Throwable)}} only handle WriteToClosedSessionException)?
> - From the javadoc 
> [https://mina.apache.org/mina-project/apidocs/org/apache/mina/core/service/IoHandler.html#exceptionCaught(org.apache.mina.core.session.IoSession,%20java.lang.Throwable)]
>  it seems to be that Mina itself handle IoExceptions and close the 
> connection. SSLHandshakeException  is a IoException, but as described above, 
> the connection is *NOT* closed. Additional Remark: The javadoc is for the 
> IoHandler, not for IoFilter - so I am not sure if this rule also applies to 
> the IoFilter?
> We have not yet an proposal how to fix Mina and/or the Mina SSLFilter. We 
> will try to workaround with a custom filter which close the session if 
> SSLHandshakeException failed.
> We have testet the problem with Mina 2.0.13 and 2.0.14.



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Reply via email to