[Red Hat JIRA] (ISPN-12558) StackOverflowError during REST connection shutdown
by Dan Berindei (Jira)
[ https://issues.redhat.com/browse/ISPN-12558?page=com.atlassian.jira.plugi... ]
Dan Berindei edited comment on ISPN-12558 at 12/8/20 3:58 AM:
--------------------------------------------------------------
Workaround: Ignore the IllegalStateException from OpenSSLEngine in RestRequestHandler to avoid the StackOverflowError.
was (Author: dan.berindei):
Ignore the IllegalStateException from OpenSSLEngine in RestRequestHandler to avoid the StackOverflowError.
> StackOverflowError during REST connection shutdown
> --------------------------------------------------
>
> Key: ISPN-12558
> URL: https://issues.redhat.com/browse/ISPN-12558
> Project: Infinispan
> Issue Type: Bug
> Reporter: Dan Berindei
> Assignee: Dan Berindei
> Priority: Major
> Labels: testsuite_stability
>
> When the REST server accepts a HTTP2 SSL connection, it initializes a {{OpenSSLEngine}} provided by {{wildfly-openssl-java}}:
> {noformat}
> at org.wildfly.openssl.OpenSSLEngine.initSsl(OpenSSLEngine.java:188)
> at org.wildfly.openssl.OpenSSLEngine.unwrap(OpenSSLEngine.java:532)
> at javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:637)
> at io.netty.handler.ssl.JdkSslEngine.unwrap(JdkSslEngine.java:92)
> at io.netty.handler.ssl.JdkAlpnSslEngine.unwrap(JdkAlpnSslEngine.java:143)
> at io.netty.handler.ssl.SslHandler$SslEngineType$3.unwrap(SslHandler.java:282)
> at io.netty.handler.ssl.SslHandler.unwrap(SslHandler.java:1380)
> at io.netty.handler.ssl.SslHandler.decodeJdkCompatible(SslHandler.java:1275)
> at io.netty.handler.ssl.SslHandler.decode(SslHandler.java:1322)
> at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:501)
> at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:440)
> at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:276)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
> at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
> at io.netty.handler.codec.ByteToMessageDecoder.handlerRemoved(ByteToMessageDecoder.java:253)
> at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:508)
> at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:440)
> at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:276)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
> at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
> at io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:93)
> at org.infinispan.server.core.transport.StatsChannelHandler.channelRead(StatsChannelHandler.java:26)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
> at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
> at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
> at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
> at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:792)
> at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:475)
> {noformat}
> When the client closes the connection, is sends a {{close_notify}} message, and {{org.wildfly.openssl.OpenSSLEngine.unwrap()}} automatically shuts down the engine:
> {noformat}
> at org.wildfly.openssl.OpenSSLEngine.shutdown(OpenSSLEngine.java:205)
> at org.wildfly.openssl.OpenSSLEngine.closeInbound(OpenSSLEngine.java:692)
> at org.wildfly.openssl.OpenSSLEngine.unwrap(OpenSSLEngine.java:657)
> at javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:637)
> at io.netty.handler.ssl.JdkSslEngine.unwrap(JdkSslEngine.java:92)
> at io.netty.handler.ssl.JdkAlpnSslEngine.unwrap(JdkAlpnSslEngine.java:143)
> at io.netty.handler.ssl.SslHandler$SslEngineType$3.unwrap(SslHandler.java:282)
> at io.netty.handler.ssl.SslHandler.unwrap(SslHandler.java:1380)
> at io.netty.handler.ssl.SslHandler.decodeJdkCompatible(SslHandler.java:1275)
> at io.netty.handler.ssl.SslHandler.decode(SslHandler.java:1322)
> at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:501)
> at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:440)
> at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:276)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
> at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
> at io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:93)
> at org.infinispan.server.core.transport.StatsChannelHandler.channelRead(StatsChannelHandler.java:26)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
> at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
> at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
> at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
> at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:792)
> at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:475)
> {noformat}
> But then {{Http2MultiplexCodec}} also wants to flush its output buffer (which happens to be an {{EmptyByteBuf}}).
> It cannot flush because the {{OpenSSLEngine}} instance is no longer valid:
> {noformat}
> java.lang.IllegalStateException: ssl is null
> at org.wildfly.openssl.SSLImpl.getSessionId0(Native Method)
> at org.wildfly.openssl.SSLImpl.getSessionId(SSLImpl.java:494)
> at org.wildfly.openssl.OpenSSLEngine.getSession(OpenSSLEngine.java:977)
> at io.netty.handler.ssl.JdkSslEngine.getSession(JdkSslEngine.java:48)
> at io.netty.handler.ssl.SslHandler$SslEngineType$3.allocateWrapBuffer(SslHandler.java:312)
> at io.netty.handler.ssl.SslHandler.allocateOutNetBuf(SslHandler.java:2207)
> at io.netty.handler.ssl.SslHandler.wrap(SslHandler.java:840)
> at io.netty.handler.ssl.SslHandler.wrapAndFlush(SslHandler.java:811)
> at io.netty.handler.ssl.SslHandler.flush(SslHandler.java:792)
> at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:750)
> at io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:742)
> at io.netty.channel.AbstractChannelHandlerContext.flush(AbstractChannelHandlerContext.java:728)
> at io.netty.handler.codec.http2.Http2ConnectionHandler.flush(Http2ConnectionHandler.java:189)
> at io.netty.handler.codec.http2.Http2MultiplexCodec.flush0(Http2MultiplexCodec.java:282)
> at io.netty.handler.codec.http2.Http2MultiplexCodec.processPendingReadCompleteQueue(Http2MultiplexCodec.java:261)
> at io.netty.handler.codec.http2.Http2MultiplexCodec.channelReadComplete(Http2MultiplexCodec.java:240)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:410)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:397)
> at io.netty.channel.AbstractChannelHandlerContext.fireChannelReadComplete(AbstractChannelHandlerContext.java:390)
> at io.netty.handler.ssl.SslHandler.channelReadComplete0(SslHandler.java:1341)
> at io.netty.handler.ssl.SslHandler.channelReadComplete(SslHandler.java:1330)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:410)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:397)
> at io.netty.channel.AbstractChannelHandlerContext.fireChannelReadComplete(AbstractChannelHandlerContext.java:390)
> at io.netty.channel.DefaultChannelPipeline$HeadContext.channelReadComplete(DefaultChannelPipeline.java:1415)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:410)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:397)
> at io.netty.channel.DefaultChannelPipeline.fireChannelReadComplete(DefaultChannelPipeline.java:925)
> at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:812)
> {noformat}
> Our {{RestRequestHandler}} catches the exception, logs it, then wants to close the connection, which requires a flush.
> The flush throws an {{IllegalStateException}}, which {{RestRequestHandler}} catches again, and the whole thing is repeated until eventually it leads to a {{StackOverflowError}}.
> After the first {{StackOverflowError}}, some new classes are loaded. The test suite has a BlockHound instrumentation agent (using ByteBuddy internally), and when they also throw {{StackOverflowError}}, the JVM logs an assertion failure message:
> {noformat}
> [ERROR] *** java.lang.instrument ASSERTION FAILED ***: "!errorOutstanding" with message transform method call failed at ./src/java.instrument/share/native/libinstrument/JPLISAgent.c line: 873
> {noformat}
> The problem can always be reproduced by running {{org.infinispan.rest.resources.CacheV2ResourceTest.testSearchStatistics[security=true, protocol=HTTP_20, ssl=true]}}. In CI, it sometimes hangs the build (not even the long test 5 minute timeout works).
--
This message was sent by Atlassian Jira
(v7.13.8#713008)
5 years, 4 months
[Red Hat JIRA] (ISPN-12558) StackOverflowError during REST connection shutdown
by Dan Berindei (Jira)
[ https://issues.redhat.com/browse/ISPN-12558?page=com.atlassian.jira.plugi... ]
Dan Berindei commented on ISPN-12558:
-------------------------------------
I created an issue in the wildfly-openssl project as well: https://github.com/wildfly-security/wildfly-openssl/issues/93
> StackOverflowError during REST connection shutdown
> --------------------------------------------------
>
> Key: ISPN-12558
> URL: https://issues.redhat.com/browse/ISPN-12558
> Project: Infinispan
> Issue Type: Bug
> Reporter: Dan Berindei
> Assignee: Dan Berindei
> Priority: Major
> Labels: testsuite_stability
>
> When the REST server accepts a HTTP2 SSL connection, it initializes a {{OpenSSLEngine}} provided by {{wildfly-openssl-java}}:
> {noformat}
> at org.wildfly.openssl.OpenSSLEngine.initSsl(OpenSSLEngine.java:188)
> at org.wildfly.openssl.OpenSSLEngine.unwrap(OpenSSLEngine.java:532)
> at javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:637)
> at io.netty.handler.ssl.JdkSslEngine.unwrap(JdkSslEngine.java:92)
> at io.netty.handler.ssl.JdkAlpnSslEngine.unwrap(JdkAlpnSslEngine.java:143)
> at io.netty.handler.ssl.SslHandler$SslEngineType$3.unwrap(SslHandler.java:282)
> at io.netty.handler.ssl.SslHandler.unwrap(SslHandler.java:1380)
> at io.netty.handler.ssl.SslHandler.decodeJdkCompatible(SslHandler.java:1275)
> at io.netty.handler.ssl.SslHandler.decode(SslHandler.java:1322)
> at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:501)
> at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:440)
> at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:276)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
> at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
> at io.netty.handler.codec.ByteToMessageDecoder.handlerRemoved(ByteToMessageDecoder.java:253)
> at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:508)
> at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:440)
> at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:276)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
> at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
> at io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:93)
> at org.infinispan.server.core.transport.StatsChannelHandler.channelRead(StatsChannelHandler.java:26)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
> at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
> at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
> at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
> at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:792)
> at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:475)
> {noformat}
> When the client closes the connection, is sends a {{close_notify}} message, and {{org.wildfly.openssl.OpenSSLEngine.unwrap()}} automatically shuts down the engine:
> {noformat}
> at org.wildfly.openssl.OpenSSLEngine.shutdown(OpenSSLEngine.java:205)
> at org.wildfly.openssl.OpenSSLEngine.closeInbound(OpenSSLEngine.java:692)
> at org.wildfly.openssl.OpenSSLEngine.unwrap(OpenSSLEngine.java:657)
> at javax.net.ssl.SSLEngine.unwrap(SSLEngine.java:637)
> at io.netty.handler.ssl.JdkSslEngine.unwrap(JdkSslEngine.java:92)
> at io.netty.handler.ssl.JdkAlpnSslEngine.unwrap(JdkAlpnSslEngine.java:143)
> at io.netty.handler.ssl.SslHandler$SslEngineType$3.unwrap(SslHandler.java:282)
> at io.netty.handler.ssl.SslHandler.unwrap(SslHandler.java:1380)
> at io.netty.handler.ssl.SslHandler.decodeJdkCompatible(SslHandler.java:1275)
> at io.netty.handler.ssl.SslHandler.decode(SslHandler.java:1322)
> at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:501)
> at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:440)
> at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:276)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
> at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
> at io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:93)
> at org.infinispan.server.core.transport.StatsChannelHandler.channelRead(StatsChannelHandler.java:26)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
> at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
> at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
> at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
> at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:792)
> at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:475)
> {noformat}
> But then {{Http2MultiplexCodec}} also wants to flush its output buffer (which happens to be an {{EmptyByteBuf}}).
> It cannot flush because the {{OpenSSLEngine}} instance is no longer valid:
> {noformat}
> java.lang.IllegalStateException: ssl is null
> at org.wildfly.openssl.SSLImpl.getSessionId0(Native Method)
> at org.wildfly.openssl.SSLImpl.getSessionId(SSLImpl.java:494)
> at org.wildfly.openssl.OpenSSLEngine.getSession(OpenSSLEngine.java:977)
> at io.netty.handler.ssl.JdkSslEngine.getSession(JdkSslEngine.java:48)
> at io.netty.handler.ssl.SslHandler$SslEngineType$3.allocateWrapBuffer(SslHandler.java:312)
> at io.netty.handler.ssl.SslHandler.allocateOutNetBuf(SslHandler.java:2207)
> at io.netty.handler.ssl.SslHandler.wrap(SslHandler.java:840)
> at io.netty.handler.ssl.SslHandler.wrapAndFlush(SslHandler.java:811)
> at io.netty.handler.ssl.SslHandler.flush(SslHandler.java:792)
> at io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:750)
> at io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:742)
> at io.netty.channel.AbstractChannelHandlerContext.flush(AbstractChannelHandlerContext.java:728)
> at io.netty.handler.codec.http2.Http2ConnectionHandler.flush(Http2ConnectionHandler.java:189)
> at io.netty.handler.codec.http2.Http2MultiplexCodec.flush0(Http2MultiplexCodec.java:282)
> at io.netty.handler.codec.http2.Http2MultiplexCodec.processPendingReadCompleteQueue(Http2MultiplexCodec.java:261)
> at io.netty.handler.codec.http2.Http2MultiplexCodec.channelReadComplete(Http2MultiplexCodec.java:240)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:410)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:397)
> at io.netty.channel.AbstractChannelHandlerContext.fireChannelReadComplete(AbstractChannelHandlerContext.java:390)
> at io.netty.handler.ssl.SslHandler.channelReadComplete0(SslHandler.java:1341)
> at io.netty.handler.ssl.SslHandler.channelReadComplete(SslHandler.java:1330)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:410)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:397)
> at io.netty.channel.AbstractChannelHandlerContext.fireChannelReadComplete(AbstractChannelHandlerContext.java:390)
> at io.netty.channel.DefaultChannelPipeline$HeadContext.channelReadComplete(DefaultChannelPipeline.java:1415)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:410)
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:397)
> at io.netty.channel.DefaultChannelPipeline.fireChannelReadComplete(DefaultChannelPipeline.java:925)
> at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:812)
> {noformat}
> Our {{RestRequestHandler}} catches the exception, logs it, then wants to close the connection, which requires a flush.
> The flush throws an {{IllegalStateException}}, which {{RestRequestHandler}} catches again, and the whole thing is repeated until eventually it leads to a {{StackOverflowError}}.
> After the first {{StackOverflowError}}, some new classes are loaded. The test suite has a BlockHound instrumentation agent (using ByteBuddy internally), and when they also throw {{StackOverflowError}}, the JVM logs an assertion failure message:
> {noformat}
> [ERROR] *** java.lang.instrument ASSERTION FAILED ***: "!errorOutstanding" with message transform method call failed at ./src/java.instrument/share/native/libinstrument/JPLISAgent.c line: 873
> {noformat}
> The problem can always be reproduced by running {{org.infinispan.rest.resources.CacheV2ResourceTest.testSearchStatistics[security=true, protocol=HTTP_20, ssl=true]}}. In CI, it sometimes hangs the build (not even the long test 5 minute timeout works).
--
This message was sent by Atlassian Jira
(v7.13.8#713008)
5 years, 4 months
[Red Hat JIRA] (ISPN-12559) SearchAdminResource.searchStats blocking call
by Dan Berindei (Jira)
[ https://issues.redhat.com/browse/ISPN-12559?page=com.atlassian.jira.plugi... ]
Dan Berindei updated ISPN-12559:
--------------------------------
Status: Pull Request Sent (was: Open)
Git Pull Request: https://github.com/infinispan/infinispan/pull/8923
Ignore file reads in {{NamedSPILoader}}, which is a re-implementation of {{java.util.ServiceLoader}}.
> SearchAdminResource.searchStats blocking call
> ---------------------------------------------
>
> Key: ISPN-12559
> URL: https://issues.redhat.com/browse/ISPN-12559
> Project: Infinispan
> Issue Type: Bug
> Components: REST, Server
> Affects Versions: 12.0.0.Dev07
> Reporter: Dan Berindei
> Assignee: Dan Berindei
> Priority: Major
> Labels: testsuite_stability
> Fix For: 12.0.0.CR1
>
>
> {{SearchAdminResource.searchStats()}} invokes {{SearchFetchable.fetchTotalHitCount()}}, which sometimes reads from the index.
> It can be reproduced by running test method {{CacheV2ResourceTest#testSearchStatistics}} by itself, e.g. in the IDE.
> {noformat}
> 09:29:43,766 ERROR (REST-Test-ServerIO-3-1:[]) [TestSuiteProgress] Test failed: org.infinispan.rest.resources.CacheV2ResourceTest[security=true, protocol=HTTP_20, ssl=true].BlockingChecker
> java.lang.AssertionError: Blocking call! java.io.RandomAccessFile#readBytes on thread Thread[REST-Test-ServerIO-3-1,5,main]
> at org.infinispan.util.CoreTestBlockHoundIntegration.lambda$applyTo$0(CoreTestBlockHoundIntegration.java:49) ~[test-classes/:?]
> at reactor.blockhound.BlockHound$Builder.lambda$install$8(BlockHound.java:383) ~[blockhound-1.0.3.RELEASE.jar:?]
> at reactor.blockhound.BlockHoundRuntime.checkBlocking(BlockHoundRuntime.java:89) ~[?:?]
> at java.io.RandomAccessFile.readBytes(RandomAccessFile.java) ~[?:?]
> at java.io.RandomAccessFile.read(RandomAccessFile.java:408) ~[?:?]
> at java.io.RandomAccessFile.readFully(RandomAccessFile.java:472) ~[?:?]
> at java.util.zip.ZipFile$Source.readFullyAt(ZipFile.java:1281) ~[?:?]
> at java.util.zip.ZipFile$ZipFileInputStream.initDataOffset(ZipFile.java:907) ~[?:?]
> at java.util.zip.ZipFile$ZipFileInputStream.read(ZipFile.java:923) ~[?:?]
> at java.util.zip.ZipFile$ZipFileInflaterInputStream.fill(ZipFile.java:445) ~[?:?]
> at java.util.zip.InflaterInputStream.read(InflaterInputStream.java:158) ~[?:?]
> at java.io.FilterInputStream.read(FilterInputStream.java:132) ~[?:?]
> at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:297) ~[?:?]
> at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:339) ~[?:?]
> at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:188) ~[?:?]
> at java.io.InputStreamReader.read(InputStreamReader.java:181) ~[?:?]
> at java.io.BufferedReader.fill(BufferedReader.java:161) ~[?:?]
> at java.io.BufferedReader.readLine(BufferedReader.java:326) ~[?:?]
> at java.io.BufferedReader.readLine(BufferedReader.java:392) ~[?:?]
> at org.apache.lucene.util.SPIClassIterator.loadNextProfile(SPIClassIterator.java:112) ~[lucene-core-8.6.2.jar:8.6.2 016993b65e393b58246d54e8ddda9f56a453eb0e - ivera - 2020-08-26 10:53:36]
> at org.apache.lucene.util.SPIClassIterator.hasNext(SPIClassIterator.java:143) ~[lucene-core-8.6.2.jar:8.6.2 016993b65e393b58246d54e8ddda9f56a453eb0e - ivera - 2020-08-26 10:53:36]
> at org.apache.lucene.util.NamedSPILoader.reload(NamedSPILoader.java:69) ~[lucene-core-8.6.2.jar:8.6.2 016993b65e393b58246d54e8ddda9f56a453eb0e - ivera - 2020-08-26 10:53:36]
> at org.apache.lucene.util.NamedSPILoader.<init>(NamedSPILoader.java:51) ~[lucene-core-8.6.2.jar:8.6.2 016993b65e393b58246d54e8ddda9f56a453eb0e - ivera - 2020-08-26 10:53:36]
> at org.apache.lucene.util.NamedSPILoader.<init>(NamedSPILoader.java:38) ~[lucene-core-8.6.2.jar:8.6.2 016993b65e393b58246d54e8ddda9f56a453eb0e - ivera - 2020-08-26 10:53:36]
> at org.apache.lucene.codecs.PostingsFormat$Holder.<clinit>(PostingsFormat.java:49) ~[lucene-core-8.6.2.jar:8.6.2 016993b65e393b58246d54e8ddda9f56a453eb0e - ivera - 2020-08-26 10:53:36]
> at org.apache.lucene.codecs.PostingsFormat.forName(PostingsFormat.java:112) ~[lucene-core-8.6.2.jar:8.6.2 016993b65e393b58246d54e8ddda9f56a453eb0e - ivera - 2020-08-26 10:53:36]
> at org.apache.lucene.codecs.perfield.PerFieldPostingsFormat$FieldsReader.<init>(PerFieldPostingsFormat.java:312) ~[lucene-core-8.6.2.jar:8.6.2 016993b65e393b58246d54e8ddda9f56a453eb0e - ivera - 2020-08-26 10:53:36]
> at org.apache.lucene.codecs.perfield.PerFieldPostingsFormat.fieldsProducer(PerFieldPostingsFormat.java:395) ~[lucene-core-8.6.2.jar:8.6.2 016993b65e393b58246d54e8ddda9f56a453eb0e - ivera - 2020-08-26 10:53:36]
> at org.apache.lucene.index.SegmentCoreReaders.<init>(SegmentCoreReaders.java:114) ~[lucene-core-8.6.2.jar:8.6.2 016993b65e393b58246d54e8ddda9f56a453eb0e - ivera - 2020-08-26 10:53:36]
> at org.apache.lucene.index.SegmentReader.<init>(SegmentReader.java:83) ~[lucene-core-8.6.2.jar:8.6.2 016993b65e393b58246d54e8ddda9f56a453eb0e - ivera - 2020-08-26 10:53:36]
> at org.apache.lucene.index.ReadersAndUpdates.getReader(ReadersAndUpdates.java:171) ~[lucene-core-8.6.2.jar:8.6.2 016993b65e393b58246d54e8ddda9f56a453eb0e - ivera - 2020-08-26 10:53:36]
> at org.apache.lucene.index.ReadersAndUpdates.getReadOnlyClone(ReadersAndUpdates.java:213) ~[lucene-core-8.6.2.jar:8.6.2 016993b65e393b58246d54e8ddda9f56a453eb0e - ivera - 2020-08-26 10:53:36]
> at org.apache.lucene.index.StandardDirectoryReader.open(StandardDirectoryReader.java:106) ~[lucene-core-8.6.2.jar:8.6.2 016993b65e393b58246d54e8ddda9f56a453eb0e - ivera - 2020-08-26 10:53:36]
> at org.apache.lucene.index.IndexWriter.getReader(IndexWriter.java:590) ~[lucene-core-8.6.2.jar:8.6.2 016993b65e393b58246d54e8ddda9f56a453eb0e - ivera - 2020-08-26 10:53:36]
> at org.apache.lucene.index.StandardDirectoryReader.doOpenFromWriter(StandardDirectoryReader.java:294) ~[lucene-core-8.6.2.jar:8.6.2 016993b65e393b58246d54e8ddda9f56a453eb0e - ivera - 2020-08-26 10:53:36]
> at org.apache.lucene.index.StandardDirectoryReader.doOpenIfChanged(StandardDirectoryReader.java:279) ~[lucene-core-8.6.2.jar:8.6.2 016993b65e393b58246d54e8ddda9f56a453eb0e - ivera - 2020-08-26 10:53:36]
> at org.apache.lucene.index.DirectoryReader.openIfChanged(DirectoryReader.java:235) ~[lucene-core-8.6.2.jar:8.6.2 016993b65e393b58246d54e8ddda9f56a453eb0e - ivera - 2020-08-26 10:53:36]
> at org.apache.lucene.index.DirectoryReader.openIfChanged(DirectoryReader.java:212) ~[lucene-core-8.6.2.jar:8.6.2 016993b65e393b58246d54e8ddda9f56a453eb0e - ivera - 2020-08-26 10:53:36]
> at org.hibernate.search.backend.lucene.lowlevel.writer.impl.IndexWriterDelegatorImpl.openReaderIfChanged(IndexWriterDelegatorImpl.java:133) ~[hibernate-search-backend-lucene-6.0.0.CR1.jar:6.0.0.CR1]
> at org.hibernate.search.backend.lucene.lowlevel.reader.impl.NearRealTimeIndexReaderProvider.getFreshIndexReader(NearRealTimeIndexReaderProvider.java:89) ~[hibernate-search-backend-lucene-6.0.0.CR1.jar:6.0.0.CR1]
> at org.hibernate.search.backend.lucene.lowlevel.reader.impl.NearRealTimeIndexReaderProvider.getOrCreate(NearRealTimeIndexReaderProvider.java:78) ~[hibernate-search-backend-lucene-6.0.0.CR1.jar:6.0.0.CR1]
> at org.hibernate.search.backend.lucene.lowlevel.index.impl.IndexAccessorImpl.getIndexReader(IndexAccessorImpl.java:168) ~[hibernate-search-backend-lucene-6.0.0.CR1.jar:6.0.0.CR1]
> at org.hibernate.search.backend.lucene.index.impl.Shard.openReader(Shard.java:78) ~[hibernate-search-backend-lucene-6.0.0.CR1.jar:6.0.0.CR1]
> at org.hibernate.search.backend.lucene.index.impl.ShardHolder.openIndexReaders(ShardHolder.java:103) ~[hibernate-search-backend-lucene-6.0.0.CR1.jar:6.0.0.CR1]
> at org.hibernate.search.backend.lucene.index.impl.LuceneIndexManagerImpl.openIndexReaders(LuceneIndexManagerImpl.java:152) ~[hibernate-search-backend-lucene-6.0.0.CR1.jar:6.0.0.CR1]
> at org.hibernate.search.backend.lucene.lowlevel.reader.impl.HibernateSearchMultiReader.open(HibernateSearchMultiReader.java:51) ~[hibernate-search-backend-lucene-6.0.0.CR1.jar:6.0.0.CR1]
> at org.hibernate.search.backend.lucene.orchestration.impl.LuceneSyncWorkOrchestratorImpl$WorkExecution.<init>(LuceneSyncWorkOrchestratorImpl.java:114) ~[hibernate-search-backend-lucene-6.0.0.CR1.jar:6.0.0.CR1]
> at org.hibernate.search.backend.lucene.orchestration.impl.LuceneSyncWorkOrchestratorImpl.submit(LuceneSyncWorkOrchestratorImpl.java:49) ~[hibernate-search-backend-lucene-6.0.0.CR1.jar:6.0.0.CR1]
> at org.hibernate.search.backend.lucene.orchestration.impl.LuceneSyncWorkOrchestrator.submit(LuceneSyncWorkOrchestrator.java:28) ~[hibernate-search-backend-lucene-6.0.0.CR1.jar:6.0.0.CR1]
> at org.hibernate.search.backend.lucene.search.query.impl.LuceneSearchQueryImpl.doSubmit(LuceneSearchQueryImpl.java:204) ~[hibernate-search-backend-lucene-6.0.0.CR1.jar:6.0.0.CR1]
> at org.hibernate.search.backend.lucene.search.query.impl.LuceneSearchQueryImpl.fetchTotalHitCount(LuceneSearchQueryImpl.java:113) ~[hibernate-search-backend-lucene-6.0.0.CR1.jar:6.0.0.CR1]
> at org.hibernate.search.engine.search.query.dsl.spi.AbstractSearchQueryOptionsStep.fetchTotalHitCount(AbstractSearchQueryOptionsStep.java:207) ~[hibernate-search-engine-6.0.0.CR1.jar:6.0.0.CR1]
> at org.infinispan.query.stats.impl.LocalIndexStatistics.lambda$indexInfos$0(LocalIndexStatistics.java:38) ~[classes/:?]
> at java.util.stream.Collectors.lambda$uniqKeysMapAccumulator$1(Collectors.java:178) ~[?:?]
> at java.util.stream.ReduceOps$3ReducingSink.accept(ReduceOps.java:169) ~[?:?]
> at java.util.HashMap$EntrySpliterator.forEachRemaining(HashMap.java:1837) ~[?:?]
> at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:484) ~[?:?]
> at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:474) ~[?:?]
> at java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:913) ~[?:?]
> at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[?:?]
> at java.util.stream.ReferencePipeline.collect(ReferencePipeline.java:578) ~[?:?]
> at org.infinispan.query.stats.impl.LocalIndexStatistics.indexInfos(LocalIndexStatistics.java:34) ~[classes/:?]
> at org.infinispan.query.core.stats.IndexStatistics.toJson(IndexStatistics.java:38) ~[classes/:?]
> at org.infinispan.commons.dataconversion.internal.Json$DefaultFactory.make(Json.java:1190) ~[classes/:?]
> at org.infinispan.commons.dataconversion.internal.Json.make(Json.java:1443) ~[classes/:?]
> at org.infinispan.rest.resources.SearchAdminResource.makeJson(SearchAdminResource.java:120) ~[classes/:?]
> at org.infinispan.rest.resources.SearchAdminResource.searchStats(SearchAdminResource.java:87) ~[classes/:?]
> at org.infinispan.rest.framework.impl.RestDispatcherImpl.dispatch(RestDispatcherImpl.java:75) ~[classes/:?]
> {noformat}
--
This message was sent by Atlassian Jira
(v7.13.8#713008)
5 years, 4 months
[Red Hat JIRA] (ISPN-12561) CacheV2ResourceTest does not close RestClient responses
by Dan Berindei (Jira)
[ https://issues.redhat.com/browse/ISPN-12561?page=com.atlassian.jira.plugi... ]
Dan Berindei updated ISPN-12561:
--------------------------------
Status: Pull Request Sent (was: Open)
Git Pull Request: https://github.com/infinispan/infinispan/pull/8922
> CacheV2ResourceTest does not close RestClient responses
> -------------------------------------------------------
>
> Key: ISPN-12561
> URL: https://issues.redhat.com/browse/ISPN-12561
> Project: Infinispan
> Issue Type: Bug
> Components: REST, Test Suite
> Affects Versions: 12.0.0.Dev07
> Reporter: Dan Berindei
> Assignee: Dan Berindei
> Priority: Minor
> Fix For: 12.0.0.CR1
>
>
> {{RestClient}} needs responses with bodies to be closed, either explicitly, or implicitly by reading the entire body. {{CacheV2ResourceTest}} checks only the HTTP status for most responses, without reading the body.
> OkHttpClient logs a WARN message when a response is not closed. If debug logging is enabled for {{okhttp3.OkHttpClient}}, the message includes a stack trace:
> {noformat}
> 10:22:36,569 WARN (OkHttp ConnectionPool) [OkHttpClient] A connection to https://localhost:43483/ was leaked. Did you forget to close a response body?
> java.lang.Throwable: response.body().close()
> at okhttp3.internal.platform.Platform.getStackTraceForCloseable(Platform.java:149)
> at okhttp3.internal.connection.Transmitter.callStart(Transmitter.java:116)
> at okhttp3.RealCall.enqueue(RealCall.java:92)
> at org.infinispan.client.rest.impl.okhttp.RestClientOkHttp.execute(RestClientOkHttp.java:248)
> at org.infinispan.client.rest.impl.okhttp.RestCacheClientOkHttp.post(RestCacheClientOkHttp.java:94)
> at org.infinispan.rest.resources.CacheV2ResourceTest.testCacheV2KeyOps(CacheV2ResourceTest.java:142)
> {noformat}
--
This message was sent by Atlassian Jira
(v7.13.8#713008)
5 years, 4 months
[Red Hat JIRA] (ISPN-12561) CacheV2ResourceTest does not close RestClient responses
by Dan Berindei (Jira)
Dan Berindei created ISPN-12561:
-----------------------------------
Summary: CacheV2ResourceTest does not close RestClient responses
Key: ISPN-12561
URL: https://issues.redhat.com/browse/ISPN-12561
Project: Infinispan
Issue Type: Bug
Components: REST, Test Suite
Affects Versions: 12.0.0.Dev07
Reporter: Dan Berindei
Assignee: Dan Berindei
Fix For: 12.0.0.CR1
{{RestClient}} needs responses with bodies to be closed, either explicitly, or implicitly by reading the entire body. {{CacheV2ResourceTest}} checks only the HTTP status for most responses, without reading the body.
OkHttpClient logs a WARN message when a response is not closed. If debug logging is enabled for {{okhttp3.OkHttpClient}}, the message includes a stack trace:
{noformat}
10:22:36,569 WARN (OkHttp ConnectionPool) [OkHttpClient] A connection to https://localhost:43483/ was leaked. Did you forget to close a response body?
java.lang.Throwable: response.body().close()
at okhttp3.internal.platform.Platform.getStackTraceForCloseable(Platform.java:149)
at okhttp3.internal.connection.Transmitter.callStart(Transmitter.java:116)
at okhttp3.RealCall.enqueue(RealCall.java:92)
at org.infinispan.client.rest.impl.okhttp.RestClientOkHttp.execute(RestClientOkHttp.java:248)
at org.infinispan.client.rest.impl.okhttp.RestCacheClientOkHttp.post(RestCacheClientOkHttp.java:94)
at org.infinispan.rest.resources.CacheV2ResourceTest.testCacheV2KeyOps(CacheV2ResourceTest.java:142)
{noformat}
--
This message was sent by Atlassian Jira
(v7.13.8#713008)
5 years, 4 months
[Red Hat JIRA] (ISPN-12561) CacheV2ResourceTest does not close RestClient responses
by Dan Berindei (Jira)
[ https://issues.redhat.com/browse/ISPN-12561?page=com.atlassian.jira.plugi... ]
Dan Berindei updated ISPN-12561:
--------------------------------
Status: Open (was: New)
> CacheV2ResourceTest does not close RestClient responses
> -------------------------------------------------------
>
> Key: ISPN-12561
> URL: https://issues.redhat.com/browse/ISPN-12561
> Project: Infinispan
> Issue Type: Bug
> Components: REST, Test Suite
> Affects Versions: 12.0.0.Dev07
> Reporter: Dan Berindei
> Assignee: Dan Berindei
> Priority: Minor
> Fix For: 12.0.0.CR1
>
>
> {{RestClient}} needs responses with bodies to be closed, either explicitly, or implicitly by reading the entire body. {{CacheV2ResourceTest}} checks only the HTTP status for most responses, without reading the body.
> OkHttpClient logs a WARN message when a response is not closed. If debug logging is enabled for {{okhttp3.OkHttpClient}}, the message includes a stack trace:
> {noformat}
> 10:22:36,569 WARN (OkHttp ConnectionPool) [OkHttpClient] A connection to https://localhost:43483/ was leaked. Did you forget to close a response body?
> java.lang.Throwable: response.body().close()
> at okhttp3.internal.platform.Platform.getStackTraceForCloseable(Platform.java:149)
> at okhttp3.internal.connection.Transmitter.callStart(Transmitter.java:116)
> at okhttp3.RealCall.enqueue(RealCall.java:92)
> at org.infinispan.client.rest.impl.okhttp.RestClientOkHttp.execute(RestClientOkHttp.java:248)
> at org.infinispan.client.rest.impl.okhttp.RestCacheClientOkHttp.post(RestCacheClientOkHttp.java:94)
> at org.infinispan.rest.resources.CacheV2ResourceTest.testCacheV2KeyOps(CacheV2ResourceTest.java:142)
> {noformat}
--
This message was sent by Atlassian Jira
(v7.13.8#713008)
5 years, 4 months
[Red Hat JIRA] (ISPN-12561) CacheV2ResourceTest does not close RestClient responses
by Dan Berindei (Jira)
[ https://issues.redhat.com/browse/ISPN-12561?page=com.atlassian.jira.plugi... ]
Dan Berindei updated ISPN-12561:
--------------------------------
Priority: Minor (was: Major)
> CacheV2ResourceTest does not close RestClient responses
> -------------------------------------------------------
>
> Key: ISPN-12561
> URL: https://issues.redhat.com/browse/ISPN-12561
> Project: Infinispan
> Issue Type: Bug
> Components: REST, Test Suite
> Affects Versions: 12.0.0.Dev07
> Reporter: Dan Berindei
> Assignee: Dan Berindei
> Priority: Minor
> Fix For: 12.0.0.CR1
>
>
> {{RestClient}} needs responses with bodies to be closed, either explicitly, or implicitly by reading the entire body. {{CacheV2ResourceTest}} checks only the HTTP status for most responses, without reading the body.
> OkHttpClient logs a WARN message when a response is not closed. If debug logging is enabled for {{okhttp3.OkHttpClient}}, the message includes a stack trace:
> {noformat}
> 10:22:36,569 WARN (OkHttp ConnectionPool) [OkHttpClient] A connection to https://localhost:43483/ was leaked. Did you forget to close a response body?
> java.lang.Throwable: response.body().close()
> at okhttp3.internal.platform.Platform.getStackTraceForCloseable(Platform.java:149)
> at okhttp3.internal.connection.Transmitter.callStart(Transmitter.java:116)
> at okhttp3.RealCall.enqueue(RealCall.java:92)
> at org.infinispan.client.rest.impl.okhttp.RestClientOkHttp.execute(RestClientOkHttp.java:248)
> at org.infinispan.client.rest.impl.okhttp.RestCacheClientOkHttp.post(RestCacheClientOkHttp.java:94)
> at org.infinispan.rest.resources.CacheV2ResourceTest.testCacheV2KeyOps(CacheV2ResourceTest.java:142)
> {noformat}
--
This message was sent by Atlassian Jira
(v7.13.8#713008)
5 years, 4 months