Re: Exception in filter (was: Re: [Vote] MINA 2.2.0 release)

Thu, 21 Jul 2022 06:38:48 -0700 

Hi Emmanuel,
I took a look at this and it seems the two latches were a red herring. One is for the initiator (connector) and the other one for the acceptor that are used in the unit test. 


However, I think I found the root cause for the failing unit tests. We have an AbstractIoHandler 
which extends IoHandlerAdapter. In its exceptionCaught() method we do some magic and in the end 
disconnect the session. You can see that here: 
https://github.com/quickfix-j/quickfixj/pull/441/files#diff-ecbb4c6b07934a11f46ceae43478dc258e7dfcaedad8c67881c7441848f8909d
Now when I exchange the closeNow() with closeOnFlush() the unit tests succeed, meaning that the 
registered filter is notified of the Exception.
Is this expected? Did this behaviour change intentionally? Is it safe to always use closeOnFlush()? 
(probably I should wait for the returned CloseFuture to complete for a sensible amount of time)


Thanks in advance and best regards
Chris.


On 16.07.22 05:30, Emmanuel Lécharny wrote:

Hi Christoph,


after further analysis, it appears that we have 2 countdown latch instances (exceptionThrownLatch) 
at play:

* one that is decremented in the exceptionCaught event,


[Count<java.util.concurrent.CountDownLatch@b9ed2fa[Count = 1]>:1]------------------->PKIX path 
validation failed: java.security.cert.CertPathValidatorException: signature check failed

[Count<java.util.concurrent.CountDownLatch@b9ed2fa[Count = 
0]>:0<]-------------------

* and the other one that is checked for the exfeption being received:

[Count<java.util.concurrent.CountDownLatch@8458f04[Count = 1]>:1 in assert

As you can see, the instances ID are different: b9ed2fa and 8458f04.


Seems like the handler you have added in teh chain is not owning the same latch that the one being 
checked in the assert, now to see why...



On 13/07/2022 17:43, Emmanuel Lécharny wrote:

Hi Christoph,

actually, there is a kind of race condition in your test.

I have added some logs:

                 @Override

                 public void exceptionCaught(NextFilter nextFilter, IoSession session, Throwable 
cause)

                         throws Exception {


System.out.println("[Count:"+exceptionThrownLatch.getCount()+"]------------------->" + 
cause.getMessage());

                     //LOGGER.info("exceptionCaught", cause);
                     exceptionThrownLatch.countDown();

System.out.println("[Count:"+exceptionThrownLatch.getCount()+"<]-------------------");
                     nextFilter.exceptionCaught(session, cause);
                 }


which generates:


[Count:1]------------------->PKIX path validation failed: 
java.security.cert.CertPathValidatorException: signature check failed

[Count:0<]-------------------


after the initiator.start() call. So the latch is properly decremented and the 
initiator.assertSslExceptionThrown() should be valid:


         public void assertSslExceptionThrown() throws Exception {

System.out.println("[Count:"+exceptionThrownLatch.getCount()+" in assert");
             boolean reachedZero = exceptionThrownLatch.await(TIMEOUT_SECONDS, 
TimeUnit.SECONDS);

             if (!reachedZero) {
                 throw new AssertionError("No SSL exception thrown");
             }

and weird enough, the latch counter is .... 1 ! (ie, the counter is *not* 
decremented)


Here are the complete logs (check the 'Count' string):


juil. 13, 2022 5:33:12 PM quickfix.mina.ssl.SSLCertificateTest$TestAcceptor 
createConnector
INFOS: Creating acceptor: [DEFAULT]
SocketUseSSL=Y
EndTime=00:00:00
ReconnectInterval=2
SocketAcceptPort=50957
SocketTrustStore=single-session/server.truststore
NeedClientAuth=Y
EnabledProtocols=TLSv1.2
SocketAcceptHost=localhost
CipherSuites=TLS_RSA_WITH_AES_128_CBC_SHA
ConnectionType=acceptor
StartTime=00:00:00
SocketKeyStorePassword=password
SocketConnectProtocol=SOCKET
KeyStoreType=JKS
SocketKeyStore=single-session/server.keystore
SocketTrustStorePassword=password
TrustStoreType=JKS
HeartBtInt=30
[SESSION]
BeginString=FIX.4.4
SenderCompID=ALFA
TargetCompID=ZULU
DataDictionary=FIX44.xml

juil. 13, 2022 5:33:14 PM quickfix.DefaultSessionSchedule <init>
INFOS: [FIX.4.4:ALFA->ZULU] daily, 00:00:00-UTC - 00:00:00-UTC

<20220713-15:33:14, FIX.4.4:ALFA->ZULU, event> (Session FIX.4.4:ALFA->ZULU schedule is daily, 
00:00:00-UTC - 00:00:00-UTC)

<20220713-15:33:14, FIX.4.4:ALFA->ZULU, event> (Created session: 
FIX.4.4:ALFA->ZULU)
juil. 13, 2022 5:33:14 PM quickfix.mina.SessionConnector startSessionTimer
INFOS: SessionTimer started
juil. 13, 2022 5:33:14 PM quickfix.mina.NetworkingOptions logOption
INFOS: Socket option: SocketTcpNoDelay=true
juil. 13, 2022 5:33:14 PM quickfix.mina.NetworkingOptions logOption
INFOS: Socket option: SocketSynchronousWrites=false
juil. 13, 2022 5:33:14 PM quickfix.mina.NetworkingOptions logOption
INFOS: Socket option: SocketSynchronousWriteTimeout=30000
juil. 13, 2022 5:33:14 PM quickfix.mina.acceptor.AbstractSocketAcceptor 
installSSL
INFOS: Installing SSL filter for 0.0.0.0/0.0.0.0:50957
juil. 13, 2022 5:33:14 PM quickfix.mina.acceptor.AbstractSocketAcceptor 
startAcceptingConnections
INFOS: Listening for connections at 0.0.0.0/0.0.0.0:50957 for session(s) 
[FIX.4.4:ALFA->ZULU]
juil. 13, 2022 5:33:14 PM quickfix.mina.ssl.SSLCertificateTest$TestInitiator 
createConnector
INFOS: Creating initiator: [DEFAULT]
SocketConnectPort=50957
SocketUseSSL=Y
EndTime=00:00:00
ReconnectInterval=2
SocketTrustStore=single-session/client.truststore
EnabledProtocols=TLSv1.2
CipherSuites=TLS_RSA_WITH_AES_128_CBC_SHA
ConnectionType=initiator
StartTime=00:00:00
SocketConnectHost=localhost
SocketKeyStorePassword=password
SocketConnectProtocol=SOCKET
KeyStoreType=JKS
SocketKeyStore=single-session/server.keystore
SocketTrustStorePassword=password
TrustStoreType=JKS
HeartBtInt=30
[SESSION]
BeginString=FIX.4.4
SenderCompID=ZULU
TargetCompID=ALFA
DataDictionary=FIX44.xml

juil. 13, 2022 5:33:14 PM quickfix.DefaultSessionSchedule <init>
INFOS: [FIX.4.4:ZULU->ALFA] daily, 00:00:00-UTC - 00:00:00-UTC

<20220713-15:33:14, FIX.4.4:ZULU->ALFA, event> (Session FIX.4.4:ZULU->ALFA schedule is daily, 
00:00:00-UTC - 00:00:00-UTC)

<20220713-15:33:14, FIX.4.4:ZULU->ALFA, event> (Created session: 
FIX.4.4:ZULU->ALFA)
juil. 13, 2022 5:33:14 PM quickfix.mina.NetworkingOptions logOption
INFOS: Socket option: SocketTcpNoDelay=true
juil. 13, 2022 5:33:14 PM quickfix.mina.NetworkingOptions logOption
INFOS: Socket option: SocketSynchronousWrites=false
juil. 13, 2022 5:33:14 PM quickfix.mina.NetworkingOptions logOption
INFOS: Socket option: SocketSynchronousWriteTimeout=30000

<20220713-15:33:14, FIX.4.4:ZULU->ALFA, event> (Configured socket addresses for session: 
[localhost/127.0.0.1:50957])

juil. 13, 2022 5:33:14 PM quickfix.mina.SessionConnector startSessionTimer
INFOS: SessionTimer started
[Count:1 in assert
juil. 13, 2022 5:33:14 PM quickfix.mina.acceptor.AcceptorIoHandler 
sessionCreated

INFOS: MINA session created: local=/127.0.0.1:50957, class 
org.apache.mina.transport.socket.nio.NioSocketSession, remote=/127.0.0.1:50958
<20220713-15:33:14, FIX.4.4:ZULU->ALFA, event> (MINA session created: local=/127.0.0.1:50958, 
class org.apache.mina.transport.socket.nio.NioSocketSession, remote=localhost/127.0.0.1:50957)

juil. 13, 2022 5:33:15 PM org.apache.mina.filter.ssl.SSLHandlerG0 execute_task
GRAVE: SSLHandlerG0@52097369[mode=server, connected=false] task() - storing 
error {}

javax.net.ssl.SSLHandshakeException: PKIX path validation failed: 
java.security.cert.CertPathValidatorException: signature check failed

     at ....


[Count:1]------------------->PKIX path validation failed: 
java.security.cert.CertPathValidatorException: signature check failed

[Count:0<]-------------------
juil. 13, 2022 5:33:15 PM quickfix.mina.AbstractIoHandler exceptionCaught

GRAVE: Socket (/127.0.0.1:50958): javax.net.ssl.SSLHandshakeException: PKIX path validation 
failed: java.security.cert.CertPathValidatorException: signature check failed
javax.net.ssl.SSLHandshakeException: PKIX path validation failed: 
java.security.cert.CertPathValidatorException: signature check failed

     at ...

<20220713-15:33:15, FIX.4.4:ZULU->ALFA, event> (Disconnecting: Encountered 
END_OF_STREAM)
juil. 13, 2022 5:33:15 PM quickfix.mina.AbstractIoHandler exceptionCaught
GRAVE: Socket (null): org.apache.mina.core.write.WriteToClosedSessionException
org.apache.mina.core.write.WriteToClosedSessionException

     at 
org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.clearWriteRequestQueue(AbstractPollingIoProcessor.java:1192) 

     at 
org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.removeNow(AbstractPollingIoProcessor.java:1153) 

     at 
org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.removeSessions(AbstractPollingIoProcessor.java:864) 

     at 
org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractPollingIoProcessor.java:694) 


     at 
org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64)
     at 
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
     at 
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
     at java.base/java.lang.Thread.run(Thread.java:829)

juil. 13, 2022 5:33:16 PM quickfix.mina.acceptor.AcceptorIoHandler 
sessionCreated

INFOS: MINA session created: local=/127.0.0.1:50957, class 
org.apache.mina.transport.socket.nio.NioSocketSession, remote=/127.0.0.1:50959
<20220713-15:33:16, FIX.4.4:ZULU->ALFA, event> (MINA session created: local=/127.0.0.1:50959, 
class org.apache.mina.transport.socket.nio.NioSocketSession, remote=localhost/127.0.0.1:50957)

juil. 13, 2022 5:33:17 PM org.apache.mina.filter.ssl.SSLHandlerG0 execute_task
GRAVE: SSLHandlerG0@4dd2b12c[mode=server, connected=false] task() - storing 
error {}

javax.net.ssl.SSLHandshakeException: PKIX path validation failed: 
java.security.cert.CertPathValidatorException: signature check failed

     at ...



[Count:0]------------------->PKIX path validation failed: 
java.security.cert.CertPathValidatorException: signature check failed

[Count:0<]-------------------
juil. 13, 2022 5:33:17 PM quickfix.mina.AbstractIoHandler exceptionCaught

GRAVE: Socket (/127.0.0.1:50959): javax.net.ssl.SSLHandshakeException: PKIX path validation 
failed: java.security.cert.CertPathValidatorException: signature check failed
javax.net.ssl.SSLHandshakeException: PKIX path validation failed: 
java.security.cert.CertPathValidatorException: signature check failed

     at ...

Basically, it goes:
- assert (counter is 1)
- receive exception (counter is decremented and is now 0)
- close the connection : "Disconnecting: Encountered END_OF_STREAM"

and you are doomed, the assert has already failed.



At this point, I believe the pb is in your test, as the root cause is properly propagated to the 
client :



[Count:1]------------------->PKIX path validation failed: 
java.security.cert.CertPathValidatorException: signature check failed

[Count:0<]-------------------



On 13/07/2022 13:58, Emmanuel Lécharny wrote:



On 13/07/2022 09:37, Christoph John wrote:

Hi Emmanuel,


thanks for your analysis. The filter that should catch the exception is added as last part in 
the chain. Could it be that the chain is not fully iterated somehow? Just guessing, I don't 
have enough MINA experience to make an educated guess. :)


This is what I'm going to check :-)

Stay tuned !


Cheers
Chris

Jul 13, 2022 06:38:00 Emmanuel Lécharny <elecha...@gmail.com>:


Here are some of my current findings.

For the (failing) test shouldFailWhenUsingBadClientCertificate, here are the 
traces we get:

juil. 13, 2022 6:28:42 AM org.apache.mina.filter.ssl.SSLHandlerG0 execute_task
GRAVE: SSLHandlerG0@ae273e3[mode=server, connected=false] task() - storing 
error {}

javax.net.ssl.SSLHandshakeException: PKIX path validation failed: 
java.security.cert.CertPathValidatorException: signature check failed

     at java.base/sun.security.ssl.Alert.createSSLException(Alert.java:131)
     at 
java.base/sun.security.ssl.TransportContext.fatal(TransportContext.java:349)
     at 
java.base/sun.security.ssl.TransportContext.fatal(TransportContext.java:292)
     at 
java.base/sun.security.ssl.TransportContext.fatal(TransportContext.java:287)

     at 
java.base/sun.security.ssl.CertificateMessage$T12CertificateConsumer.checkClientCerts(CertificateMessage.java:700) 

     at 
java.base/sun.security.ssl.CertificateMessage$T12CertificateConsumer.onCertificate(CertificateMessage.java:411) 

     at 
java.base/sun.security.ssl.CertificateMessage$T12CertificateConsumer.consume(CertificateMessage.java:375) 


     at java.base/sun.security.ssl.SSLHandshake.consume(SSLHandshake.java:392)
     at 
java.base/sun.security.ssl.HandshakeContext.dispatch(HandshakeContext.java:443)

     at 
java.base/sun.security.ssl.SSLEngineImpl$DelegatedTask$DelegatedAction.run(SSLEngineImpl.java:1074) 

     at 
java.base/sun.security.ssl.SSLEngineImpl$DelegatedTask$DelegatedAction.run(SSLEngineImpl.java:1061) 


     at java.base/java.security.AccessController.doPrivileged(Native Method)
     at 
java.base/sun.security.ssl.SSLEngineImpl$DelegatedTask.run(SSLEngineImpl.java:1008)
     at 
org.apache.mina.filter.ssl.SSLHandlerG0.execute_task(SSLHandlerG0.java:743)
     at 
org.apache.mina.filter.ssl.SSLHandlerG0.receive_loop(SSLHandlerG0.java:255)
     at org.apache.mina.filter.ssl.SSLHandlerG0.receive(SSLHandlerG0.java:162)
     at org.apache.mina.filter.ssl.SslFilter.messageReceived(SslFilter.java:342)

     at 
org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650) 

     at 
org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
     at 
org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128) 

     at 
org.apache.mina.core.filterchain.IoFilterAdapter.messageReceived(IoFilterAdapter.java:122)
     at 
org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650) 

     at 
org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
     at 
org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128) 

     at 
org.apache.mina.core.filterchain.IoFilterAdapter.messageReceived(IoFilterAdapter.java:122)
     at 
org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650) 

     at 
org.apache.mina.core.filterchain.DefaultIoFilterChain.fireMessageReceived(DefaultIoFilterChain.java:643) 

     at 
org.apache.mina.core.polling.AbstractPollingIoProcessor.read(AbstractPollingIoProcessor.java:539)
     at 
org.apache.mina.core.polling.AbstractPollingIoProcessor.access$1200(AbstractPollingIoProcessor.java:68) 

     at 
org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.process(AbstractPollingIoProcessor.java:1224) 

     at 
org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.process(AbstractPollingIoProcessor.java:1213) 

     at 
org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractPollingIoProcessor.java:683) 


     at 
org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64)
     at 
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
     at 
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
     at java.base/java.lang.Thread.run(Thread.java:829)

Caused by: sun.security.validator.ValidatorException: PKIX path validation failed: 
java.security.cert.CertPathValidatorException: signature check failed

     at 
java.base/sun.security.validator.PKIXValidator.doValidate(PKIXValidator.java:369)
     at 
java.base/sun.security.validator.PKIXValidator.engineValidate(PKIXValidator.java:275)
     at java.base/sun.security.validator.Validator.validate(Validator.java:264)
     at 
java.base/sun.security.ssl.X509TrustManagerImpl.validate(X509TrustManagerImpl.java:313)

     at 
java.base/sun.security.ssl.X509TrustManagerImpl.checkTrusted(X509TrustManagerImpl.java:233)
     at 
java.base/sun.security.ssl.X509TrustManagerImpl.checkClientTrusted(X509TrustManagerImpl.java:104)
     at 
quickfix.mina.ssl.X509TrustManagerWrapper.checkClientTrusted(X509TrustManagerWrapper.java:60)
     at 
java.base/sun.security.ssl.AbstractTrustManagerWrapper.checkClientTrusted(SSLContextImpl.java:1517) 

     at 
java.base/sun.security.ssl.CertificateMessage$T12CertificateConsumer.checkClientCerts(CertificateMessage.java:682) 


     ... 31 more
Caused by: java.security.cert.CertPathValidatorException: signature check failed

     at 
java.base/sun.security.provider.certpath.PKIXMasterCertPathValidator.validate(PKIXMasterCertPathValidator.java:135) 

     at 
java.base/sun.security.provider.certpath.PKIXCertPathValidator.validate(PKIXCertPathValidator.java:224) 

     at 
java.base/sun.security.provider.certpath.PKIXCertPathValidator.validate(PKIXCertPathValidator.java:144) 

     at 
java.base/sun.security.provider.certpath.PKIXCertPathValidator.engineValidate(PKIXCertPathValidator.java:83) 


     at 
java.base/java.security.cert.CertPathValidator.validate(CertPathValidator.java:309)
     at 
java.base/sun.security.validator.PKIXValidator.doValidate(PKIXValidator.java:364)
     ... 39 more
Caused by: java.security.SignatureException: Signature does not match.
     at java.base/sun.security.x509.X509CertImpl.verify(X509CertImpl.java:422)

     at 
java.base/sun.security.provider.certpath.BasicChecker.verifySignature(BasicChecker.java:166)

     at 
java.base/sun.security.provider.certpath.BasicChecker.check(BasicChecker.java:147)

     at 
java.base/sun.security.provider.certpath.PKIXMasterCertPathValidator.validate(PKIXMasterCertPathValidator.java:125) 


     ... 44 more

juil. 13, 2022 6:28:42 AM quickfix.mina.ssl.SSLCertificateTest$TestConnector$1 
exceptionCaught
INFOS: exceptionCaught

javax.net.ssl.SSLHandshakeException: PKIX path validation failed: 
java.security.cert.CertPathValidatorException: signature check failed

     at java.base/sun.security.ssl.Alert.createSSLException(Alert.java:131)
     at 
java.base/sun.security.ssl.TransportContext.fatal(TransportContext.java:349)
     at 
java.base/sun.security.ssl.TransportContext.fatal(TransportContext.java:292)
     at 
java.base/sun.security.ssl.TransportContext.fatal(TransportContext.java:287)

     at 
java.base/sun.security.ssl.CertificateMessage$T12CertificateConsumer.checkClientCerts(CertificateMessage.java:700) 

     at 
java.base/sun.security.ssl.CertificateMessage$T12CertificateConsumer.onCertificate(CertificateMessage.java:411) 

     at 
java.base/sun.security.ssl.CertificateMessage$T12CertificateConsumer.consume(CertificateMessage.java:375) 


     at java.base/sun.security.ssl.SSLHandshake.consume(SSLHandshake.java:392)
     at 
java.base/sun.security.ssl.HandshakeContext.dispatch(HandshakeContext.java:443)

     at 
java.base/sun.security.ssl.SSLEngineImpl$DelegatedTask$DelegatedAction.run(SSLEngineImpl.java:1074) 

     at 
java.base/sun.security.ssl.SSLEngineImpl$DelegatedTask$DelegatedAction.run(SSLEngineImpl.java:1061) 


     at java.base/java.security.AccessController.doPrivileged(Native Method)
     at 
java.base/sun.security.ssl.SSLEngineImpl$DelegatedTask.run(SSLEngineImpl.java:1008)
     at 
org.apache.mina.filter.ssl.SSLHandlerG0.execute_task(SSLHandlerG0.java:743)
     at 
org.apache.mina.filter.ssl.SSLHandlerG0.receive_loop(SSLHandlerG0.java:255)
     at org.apache.mina.filter.ssl.SSLHandlerG0.receive(SSLHandlerG0.java:162)
     at org.apache.mina.filter.ssl.SslFilter.messageReceived(SslFilter.java:342)

     at 
org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650) 

     at 
org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
     at 
org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128) 

     at 
org.apache.mina.core.filterchain.IoFilterAdapter.messageReceived(IoFilterAdapter.java:122)
     at 
org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650) 

     at 
org.apache.mina.core.filterchain.DefaultIoFilterChain.access$1300(DefaultIoFilterChain.java:49)
     at 
org.apache.mina.core.filterchain.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:1128) 

     at 
org.apache.mina.core.filterchain.IoFilterAdapter.messageReceived(IoFilterAdapter.java:122)
     at 
org.apache.mina.core.filterchain.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:650) 

     at 
org.apache.mina.core.filterchain.DefaultIoFilterChain.fireMessageReceived(DefaultIoFilterChain.java:643) 

     at 
org.apache.mina.core.polling.AbstractPollingIoProcessor.read(AbstractPollingIoProcessor.java:539)
     at 
org.apache.mina.core.polling.AbstractPollingIoProcessor.access$1200(AbstractPollingIoProcessor.java:68) 

     at 
org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.process(AbstractPollingIoProcessor.java:1224) 

     at 
org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.process(AbstractPollingIoProcessor.java:1213) 

     at 
org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractPollingIoProcessor.java:683) 


     at 
org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64)
     at 
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
     at 
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
     at java.base/java.lang.Thread.run(Thread.java:829)

Caused by: sun.security.validator.ValidatorException: PKIX path validation failed: 
java.security.cert.CertPathValidatorException: signature check failed

     at 
java.base/sun.security.validator.PKIXValidator.doValidate(PKIXValidator.java:369)
     at 
java.base/sun.security.validator.PKIXValidator.engineValidate(PKIXValidator.java:275)
     at java.base/sun.security.validator.Validator.validate(Validator.java:264)
     at 
java.base/sun.security.ssl.X509TrustManagerImpl.validate(X509TrustManagerImpl.java:313)

     at 
java.base/sun.security.ssl.X509TrustManagerImpl.checkTrusted(X509TrustManagerImpl.java:233)
     at 
java.base/sun.security.ssl.X509TrustManagerImpl.checkClientTrusted(X509TrustManagerImpl.java:104)
     at 
quickfix.mina.ssl.X509TrustManagerWrapper.checkClientTrusted(X509TrustManagerWrapper.java:60)
     at 
java.base/sun.security.ssl.AbstractTrustManagerWrapper.checkClientTrusted(SSLContextImpl.java:1517) 

     at 
java.base/sun.security.ssl.CertificateMessage$T12CertificateConsumer.checkClientCerts(CertificateMessage.java:682) 


     ... 31 more
Caused by: java.security.cert.CertPathValidatorException: signature check failed

     at 
java.base/sun.security.provider.certpath.PKIXMasterCertPathValidator.validate(PKIXMasterCertPathValidator.java:135) 

     at 
java.base/sun.security.provider.certpath.PKIXCertPathValidator.validate(PKIXCertPathValidator.java:224) 

     at 
java.base/sun.security.provider.certpath.PKIXCertPathValidator.validate(PKIXCertPathValidator.java:144) 

     at 
java.base/sun.security.provider.certpath.PKIXCertPathValidator.engineValidate(PKIXCertPathValidator.java:83) 


     at 
java.base/java.security.cert.CertPathValidator.validate(CertPathValidator.java:309)
     at 
java.base/sun.security.validator.PKIXValidator.doValidate(PKIXValidator.java:364)
     ... 39 more
Caused by: java.security.SignatureException: Signature does not match.
     at java.base/sun.security.x509.X509CertImpl.verify(X509CertImpl.java:422)

     at 
java.base/sun.security.provider.certpath.BasicChecker.verifySignature(BasicChecker.java:166)

     at 
java.base/sun.security.provider.certpath.BasicChecker.check(BasicChecker.java:147)

     at 
java.base/sun.security.provider.certpath.PKIXMasterCertPathValidator.validate(PKIXMasterCertPathValidator.java:125) 


     ... 44 more



As we can see, there is a log:
juil. 13, 2022 6:28:42 AM quickfix.mina.ssl.SSLCertificateTest$TestConnector$1 
exceptionCaught
INFOS: exceptionCaught

javax.net.ssl.SSLHandshakeException: PKIX path validation failed: 
java.security.cert.CertPathValidatorException: signature check failed



saying that the client has actually received a rooted exception (here, the PKIX path 
validation failed).



OTOH, it seems that the connector does not properly handle this exception, ie the alert 
message is not propagated to the exceptionCaught handler on the client side.



That is the part to be investigated, IMO.








--
Christoph John
Software Engineering
T +49 241 557080-28
christoph.j...@macd.com

MACD GmbH
Oppenhoffallee 103
52066 Aachen, Germany
www.macd.com

Amtsgericht Aachen: HRB 8151
Ust.-Id: DE 813021663
Geschäftsführer: George Macdonald
























					Reply via email to