Infinispan tests log some warnings/errors on shutdown

[gsmet]

While running the Infinispan tests, we have the following things logged at the end of the tests.

I think it's probably due to something shutting down but I'm wondering if we could fix that?

[INFO] Tests run: 6, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 4.508 s - in io.quarkus.example.test.InfinispanClientFunctionalityTest
2019-03-02 14:54:55,118 WARNING [io.net.uti.con.DefaultPromise] (HotRod-InfinispanServer-ServerIO-4-1) An exception was thrown by org.infinispan.server.hotrod.ClientListenerRegistry$BaseClientEventSender$$Lambda$516/1860786228.operationComplete(): java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.FutureTask@6aa71bb0 rejected from java.util.concurrent.ThreadPoolExecutor@41b519e7[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 1]
	at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2063)
	at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:830)
	at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1379)
	at java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:112)
	at org.infinispan.server.hotrod.ClientListenerRegistry$BaseClientEventSender.lambda$init$1(ClientListenerRegistry.java:322)
	at io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:511)
	at io.netty.util.concurrent.DefaultPromise.notifyListeners0(DefaultPromise.java:504)
	at io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:483)
	at io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:424)
	at io.netty.util.concurrent.DefaultPromise.trySuccess(DefaultPromise.java:103)
	at io.netty.channel.DefaultChannelPromise.trySuccess(DefaultChannelPromise.java:84)
	at io.netty.channel.AbstractChannel$CloseFuture.setClosed(AbstractChannel.java:1148)
	at io.netty.channel.AbstractChannel$AbstractUnsafe.doClose0(AbstractChannel.java:764)
	at io.netty.channel.AbstractChannel$AbstractUnsafe.close(AbstractChannel.java:740)
	at io.netty.channel.AbstractChannel$AbstractUnsafe.close(AbstractChannel.java:611)
	at io.netty.channel.epoll.EpollEventLoop.closeAll(EpollEventLoop.java:377)
	at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:339)
	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:897)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.lang.Thread.run(Thread.java:748)

2019-03-02 14:54:55,121 WARNING [io.net.uti.con.DefaultPromise] (HotRod-InfinispanServer-ServerIO-4-1) An exception was thrown by org.infinispan.server.hotrod.ClientListenerRegistry$BaseClientEventSender$$Lambda$516/1860786228.operationComplete(): java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.FutureTask@3c93f207 rejected from java.util.concurrent.ThreadPoolExecutor@41b519e7[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 1]
	at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2063)
	at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:830)
	at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1379)
	at java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:112)
	at org.infinispan.server.hotrod.ClientListenerRegistry$BaseClientEventSender.lambda$init$1(ClientListenerRegistry.java:322)
	at io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:511)
	at io.netty.util.concurrent.DefaultPromise.notifyListeners0(DefaultPromise.java:504)
	at io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:483)
	at io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:424)
	at io.netty.util.concurrent.DefaultPromise.trySuccess(DefaultPromise.java:103)
	at io.netty.channel.DefaultChannelPromise.trySuccess(DefaultChannelPromise.java:84)
	at io.netty.channel.AbstractChannel$CloseFuture.setClosed(AbstractChannel.java:1148)
	at io.netty.channel.AbstractChannel$AbstractUnsafe.doClose0(AbstractChannel.java:764)
	at io.netty.channel.AbstractChannel$AbstractUnsafe.close(AbstractChannel.java:740)
	at io.netty.channel.AbstractChannel$AbstractUnsafe.close(AbstractChannel.java:611)
	at io.netty.channel.epoll.EpollEventLoop.closeAll(EpollEventLoop.java:377)
	at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:339)
	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:897)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.lang.Thread.run(Thread.java:748)

2019-03-02 14:54:55,121 WARNING [io.net.uti.con.DefaultPromise] (HotRod-InfinispanServer-ServerIO-4-1) An exception was thrown by org.infinispan.server.hotrod.ClientListenerRegistry$BaseClientEventSender$$Lambda$516/1860786228.operationComplete(): java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.FutureTask@5580ae53 rejected from java.util.concurrent.ThreadPoolExecutor@41b519e7[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 1]
	at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2063)
	at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:830)
	at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1379)
	at java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:112)
	at org.infinispan.server.hotrod.ClientListenerRegistry$BaseClientEventSender.lambda$init$1(ClientListenerRegistry.java:322)
	at io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:511)
	at io.netty.util.concurrent.DefaultPromise.notifyListeners0(DefaultPromise.java:504)
	at io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:483)
	at io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:424)
	at io.netty.util.concurrent.DefaultPromise.trySuccess(DefaultPromise.java:103)
	at io.netty.channel.DefaultChannelPromise.trySuccess(DefaultChannelPromise.java:84)
	at io.netty.channel.AbstractChannel$CloseFuture.setClosed(AbstractChannel.java:1148)
	at io.netty.channel.AbstractChannel$AbstractUnsafe.doClose0(AbstractChannel.java:764)
	at io.netty.channel.AbstractChannel$AbstractUnsafe.close(AbstractChannel.java:740)
	at io.netty.channel.AbstractChannel$AbstractUnsafe.close(AbstractChannel.java:611)
	at io.netty.channel.epoll.EpollEventLoop.closeAll(EpollEventLoop.java:377)
	at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:339)
	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:897)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.lang.Thread.run(Thread.java:748)

2019-03-02 14:54:55,122 WARNING [io.net.uti.con.DefaultPromise] (HotRod-InfinispanServer-ServerIO-4-1) An exception was thrown by org.infinispan.server.hotrod.ClientListenerRegistry$BaseClientEventSender$$Lambda$516/1860786228.operationComplete(): java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.FutureTask@fe273b6 rejected from java.util.concurrent.ThreadPoolExecutor@41b519e7[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 1]
	at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2063)
	at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:830)
	at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1379)
	at java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:112)
	at org.infinispan.server.hotrod.ClientListenerRegistry$BaseClientEventSender.lambda$init$1(ClientListenerRegistry.java:322)
	at io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:511)
	at io.netty.util.concurrent.DefaultPromise.notifyListeners0(DefaultPromise.java:504)
	at io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:483)
	at io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:424)
	at io.netty.util.concurrent.DefaultPromise.trySuccess(DefaultPromise.java:103)
	at io.netty.channel.DefaultChannelPromise.trySuccess(DefaultChannelPromise.java:84)
	at io.netty.channel.AbstractChannel$CloseFuture.setClosed(AbstractChannel.java:1148)
	at io.netty.channel.AbstractChannel$AbstractUnsafe.doClose0(AbstractChannel.java:764)
	at io.netty.channel.AbstractChannel$AbstractUnsafe.close(AbstractChannel.java:740)
	at io.netty.channel.AbstractChannel$AbstractUnsafe.close(AbstractChannel.java:611)
	at io.netty.channel.epoll.EpollEventLoop.closeAll(EpollEventLoop.java:377)
	at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:339)
	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:897)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.lang.Thread.run(Thread.java:748)

2019-03-02 14:54:55,182 ERROR [org.inf.cli.hot.imp.ope.RetryOnFailureOperation] (HotRod-client-async-pool-1) ISPN004007: Exception encountered. Retry 10 out of 10: io.netty.channel.AbstractChannel$AnnotatedConnectException: syscall:getsockopt(..) failed: Connection refused: localhost/127.0.0.1:11232
	at io.netty.channel.unix.Socket.finishConnect(..)(Unknown Source)
Caused by: io.netty.channel.unix.Errors$NativeConnectException: syscall:getsockopt(..) failed: Connection refused
	... 1 more

2019-03-02 14:54:55,182 ERROR [org.inf.cli.hot.imp.ope.RetryOnFailureOperation] (HotRod-client-async-pool-15) ISPN004007: Exception encountered. Retry 10 out of 10: io.netty.channel.AbstractChannel$AnnotatedConnectException: syscall:getsockopt(..) failed: Connection refused: localhost/127.0.0.1:11232
	at io.netty.channel.unix.Socket.finishConnect(..)(Unknown Source)
Caused by: io.netty.channel.unix.Errors$NativeConnectException: syscall:getsockopt(..) failed: Connection refused
	... 1 more

2019-03-02 14:54:55,183 ERROR [org.inf.cli.hot.imp.ope.RetryOnFailureOperation] (HotRod-client-async-pool-2) ISPN004007: Exception encountered. Retry 10 out of 10: io.netty.channel.AbstractChannel$AnnotatedConnectException: syscall:getsockopt(..) failed: Connection refused: localhost/127.0.0.1:11232
	at io.netty.channel.unix.Socket.finishConnect(..)(Unknown Source)
Caused by: io.netty.channel.unix.Errors$NativeConnectException: syscall:getsockopt(..) failed: Connection refused
	... 1 more

2019-03-02 14:54:55,188 ERROR [org.inf.cli.hot.imp.ope.RetryOnFailureOperation] (HotRod-client-async-pool-8) ISPN004007: Exception encountered. Retry 10 out of 10: io.netty.channel.AbstractChannel$AnnotatedConnectException: syscall:getsockopt(..) failed: Connection refused: localhost/127.0.0.1:11232
	at io.netty.channel.unix.Socket.finishConnect(..)(Unknown Source)
Caused by: io.netty.channel.unix.Errors$NativeConnectException: syscall:getsockopt(..) failed: Connection refused
	... 1 more

[gsmet]

@wburns any chance you could take a look to this one and fix it if it's not hard? Thanks.

[wburns]

This is caused by the Quarkus test resource not being shut down properly. The class https://github.com/quarkusio/quarkus/blob/master/test-framework/junit5/src/main/java/io/quarkus/test/junit/QuarkusTestExtension.java needs to have an afterAll method that shuts down the ExtensionState.Closeable resource. However when I tweaked the class to do that it fixed the output, however other modules started to actually fail, so I didn't change it. To note it didn't seem to shutdown the native process properly either.

[wburns]

Should be fixed in #1241