Uploaded image for project: 'Infinispan'
  1. Infinispan
  2. ISPN-13016

HotRodSniFunctionalTest.testServerWithNotMatchingDefaultAndClientWithSNI random hangs

    XMLWordPrintable

Details

    Description

      Very likely related to WFSSL-73, ISPN-12558, and ISPN-12996. The client's verification of the server certificate fails, and OpenSSSLEngine shuts down, then the channel promise from ch.writeAndFlush(op) never completes.

      04:45:05,454 DEBUG (HotRodSniFunctionalTest-Client-329-1:[]) [OpenSSLContextSPI] Certificate verification failed
      sun.security.validator.ValidatorException: Certificate signature validation failed
      	at sun.security.validator.SimpleValidator.engineValidate(SimpleValidator.java:216) ~[?:?]
      	at sun.security.validator.Validator.validate(Validator.java:264) ~[?:?]
      	at sun.security.ssl.X509TrustManagerImpl.validate(X509TrustManagerImpl.java:313) ~[?:?]
      	at sun.security.ssl.X509TrustManagerImpl.checkTrusted(X509TrustManagerImpl.java:233) ~[?:?]
      	at sun.security.ssl.X509TrustManagerImpl.checkServerTrusted(X509TrustManagerImpl.java:110) ~[?:?]
      	at org.wildfly.openssl.OpenSSLContextSPI.lambda$init$0(OpenSSLContextSPI.java:241) ~[wildfly-openssl-2.1.3.Final.jar:2.1.3.Final]
      	at org.wildfly.openssl.SSLImpl.readFromSSL0(Native Method) ~[wildfly-openssl-2.1.3.Final.jar:2.1.3.Final]
      	at org.wildfly.openssl.SSLImpl.readFromSSL(SSLImpl.java:153) [wildfly-openssl-2.1.3.Final.jar:?]
      	at org.wildfly.openssl.OpenSSLEngine.unwrap(OpenSSLEngine.java:612) [wildfly-openssl-2.1.3.Final.jar:2.1.3.Final]
      	at javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:637) [?:?]
      	at io.netty.handler.ssl.SslHandler$SslEngineType$3.unwrap(SslHandler.java:284) [netty-handler-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.handler.ssl.SslHandler.unwrap(SslHandler.java:1358) [netty-handler-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.handler.ssl.SslHandler.decodeJdkCompatible(SslHandler.java:1253) [netty-handler-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.handler.ssl.SslHandler.decode(SslHandler.java:1300) [netty-handler-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:508) [netty-codec-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:447) [netty-codec-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:276) [netty-codec-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) [netty-transport-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) [netty-transport-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) [netty-transport-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410) [netty-transport-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) [netty-transport-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) [netty-transport-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919) [netty-transport-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166) [netty-transport-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:719) [netty-transport-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:655) [netty-transport-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:581) [netty-transport-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493) [netty-transport-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) [netty-common-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [netty-common-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [netty-common-4.1.63.Final.jar:4.1.63.Final]
      	at java.lang.Thread.run(Thread.java:834) [?:?]
      Caused by: java.security.SignatureException: Signature does not match.
      	at sun.security.x509.X509CertImpl.verify(X509CertImpl.java:456) ~[?:?]
      	at sun.security.x509.X509CertImpl.verify(X509CertImpl.java:390) ~[?:?]
      	at org.wildfly.openssl.OpenSslX509Certificate.verify(OpenSslX509Certificate.java:139) ~[wildfly-openssl-2.1.3.Final.jar:2.1.3.Final]
      	at sun.security.validator.SimpleValidator.engineValidate(SimpleValidator.java:214) ~[?:?]
      	... 32 more
      04:45:05,456 DEBUG (HotRodSniFunctionalTest-Client-329-1:[]) [OpenSSLEngine] WFOPENSSL0008 Read from SSL failed error: (337047686) read result:(-1) error string: error:1416F086:SSL routines:tls_process_server_certificate:certificate verify failed
      04:45:05,456 ERROR (HotRodSniFunctionalTest-Client-329-1:[]) [Decoder] ISPN005003: Exception reported
      io.netty.handler.codec.DecoderException: java.lang.IllegalStateException: ssl is null
      	at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:478) ~[netty-codec-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:276) ~[netty-codec-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) [netty-transport-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) [netty-transport-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357) [netty-transport-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410) [netty-transport-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379) [netty-transport-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365) [netty-transport-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919) [netty-transport-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166) [netty-transport-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:719) [netty-transport-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:655) [netty-transport-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:581) [netty-transport-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493) [netty-transport-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) [netty-common-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [netty-common-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [netty-common-4.1.63.Final.jar:4.1.63.Final]
      	at java.lang.Thread.run(Thread.java:834) [?:?]
      Caused by: java.lang.IllegalStateException: ssl is null
      	at org.wildfly.openssl.SSLImpl.getTime0(Native Method) ~[wildfly-openssl-2.1.3.Final.jar:2.1.3.Final]
      	at org.wildfly.openssl.SSLImpl.getTime(SSLImpl.java:355) ~[wildfly-openssl-2.1.3.Final.jar:2.1.3.Final]
      	at org.wildfly.openssl.OpenSSlSession.initCreationTime(OpenSSlSession.java:332) ~[wildfly-openssl-2.1.3.Final.jar:2.1.3.Final]
      	at org.wildfly.openssl.OpenSSlSession.initialised(OpenSSlSession.java:307) ~[wildfly-openssl-2.1.3.Final.jar:2.1.3.Final]
      	at org.wildfly.openssl.OpenSSLEngine.getSession(OpenSSLEngine.java:1031) ~[wildfly-openssl-2.1.3.Final.jar:2.1.3.Final]
      	at io.netty.handler.ssl.SslHandler$SslEngineType$3.allocateWrapBuffer(SslHandler.java:314) ~[netty-handler-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.handler.ssl.SslHandler.allocateOutNetBuf(SslHandler.java:2205) ~[netty-handler-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.handler.ssl.SslHandler.wrap(SslHandler.java:839) ~[netty-handler-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.handler.ssl.SslHandler.wrapAndFlush(SslHandler.java:813) ~[netty-handler-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.handler.ssl.SslHandler.handleUnwrapThrowable(SslHandler.java:1283) ~[netty-handler-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.handler.ssl.SslHandler.decodeJdkCompatible(SslHandler.java:1259) ~[netty-handler-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.handler.ssl.SslHandler.decode(SslHandler.java:1300) ~[netty-handler-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:508) ~[netty-codec-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:447) ~[netty-codec-4.1.63.Final.jar:4.1.63.Final]
      	... 17 more
      04:45:05,457 DEBUG (HotRod-HotRodSniFunctionalTest-ServerIO-328-1:[]) [SslHandler] [id: 0x209a3b24, L:/127.0.0.1:12631 ! R:/127.0.0.1:53574] SSLEngine.closeInbound() raised an exception.
      javax.net.ssl.SSLException: WFOPENSSL0009 Inbound is closed
      	at org.wildfly.openssl.OpenSSLEngine.closeInbound(OpenSSLEngine.java:716) ~[wildfly-openssl-2.1.3.Final.jar:2.1.3.Final]
      	at io.netty.handler.ssl.SslHandler.setHandshakeFailure(SslHandler.java:1815) [netty-handler-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.handler.ssl.SslHandler.channelInactive(SslHandler.java:1086) [netty-handler-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:262) [netty-transport-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:248) [netty-transport-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:241) [netty-transport-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelInactive(DefaultChannelPipeline.java:1405) [netty-transport-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:262) [netty-transport-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:248) [netty-transport-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.channel.DefaultChannelPipeline.fireChannelInactive(DefaultChannelPipeline.java:901) [netty-transport-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.channel.AbstractChannel$AbstractUnsafe$8.run(AbstractChannel.java:831) [netty-transport-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164) [netty-common-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472) [netty-common-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:384) [netty-transport-native-epoll-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) [netty-common-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [netty-common-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [netty-common-4.1.63.Final.jar:4.1.63.Final]
      	at java.lang.Thread.run(Thread.java:834) [?:?]
      

      Eventually the long test killer interrupts the test thread

      04:50:05,066 ERROR (RunningTestsRegistry-Worker:[]) [TestSuiteProgress] Test failed: org.infinispan.server.hotrod.HotRodSniFunctionalTest.testServerWithNotMatchingDefaultAndClientWithSNI
      java.lang.RuntimeException: Test timed out after 300 seconds
      	at java.lang.Object.$$BlockHound$$_wait(Native Method) ~[?:?]
      	at java.lang.Object.wait(Object.java) ~[?:?]
      	at java.lang.Object.wait(Object.java:328) ~[?:?]
      	at io.netty.util.concurrent.DefaultPromise.awaitUninterruptibly(DefaultPromise.java:275) ~[netty-common-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.channel.DefaultChannelPromise.awaitUninterruptibly(DefaultChannelPromise.java:137) ~[netty-transport-4.1.63.Final.jar:4.1.63.Final]
      	at io.netty.channel.DefaultChannelPromise.awaitUninterruptibly(DefaultChannelPromise.java:30) ~[netty-transport-4.1.63.Final.jar:4.1.63.Final]
      	at org.infinispan.server.hotrod.test.HotRodClient.writeOp(HotRodClient.java:310) ~[test-classes/:?]
      	at org.infinispan.server.hotrod.HotRodSniFunctionalTest.testServerWithNotMatchingDefaultAndClientWithSNI(HotRodSniFunctionalTest.java:111) ~[test-classes/:?]
      

      Attachments

        Issue Links

          Activity

            People

              Unassigned Unassigned
              dberinde@redhat.com Dan Berindei (Inactive)
              Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

                Created:
                Updated: