EventLoop thread blocked on Vertx.clusteredVertx()

[chemist777]

Vertx 3.2.1.
Sometimes EventLoop thread blocked on Vertx.clusteredVertx().
Method Vertx.clusteredVertx() called on the main java thread on application startup.

Stacktrace:

19:30:48.633 [vertx-blocked-thread-checker] WARN  i.v.core.impl.BlockedThreadChecker - Thread Thread[vert.x-eventloop-thread-0,5,main] has been blocked for 5660 ms, time limit is 2000
io.vertx.core.VertxException: Thread blocked
    at java.lang.Object.wait(Native Method) ~[na:1.8.0]
    at com.hazelcast.spi.impl.operationservice.impl.InvocationFuture.pollResponse(InvocationFuture.java:299) ~[hazelcast-3.5.2.jar:3.5.2]
    at com.hazelcast.spi.impl.operationservice.impl.InvocationFuture.waitForResponse(InvocationFuture.java:247) ~[hazelcast-3.5.2.jar:3.5.2]
    at com.hazelcast.spi.impl.operationservice.impl.InvocationFuture.get(InvocationFuture.java:224) ~[hazelcast-3.5.2.jar:3.5.2]
    at com.hazelcast.spi.impl.operationservice.impl.InvocationFuture.get(InvocationFuture.java:204) ~[hazelcast-3.5.2.jar:3.5.2]
    at com.hazelcast.map.impl.proxy.MapProxySupport.invokeOperation(MapProxySupport.java:456) ~[hazelcast-3.5.2.jar:3.5.2]
    at com.hazelcast.map.impl.proxy.MapProxySupport.putInternal(MapProxySupport.java:417) ~[hazelcast-3.5.2.jar:3.5.2]
    at com.hazelcast.map.impl.proxy.MapProxyImpl.put(MapProxyImpl.java:97) ~[hazelcast-3.5.2.jar:3.5.2]
    at com.hazelcast.map.impl.proxy.MapProxyImpl.put(MapProxyImpl.java:87) ~[hazelcast-3.5.2.jar:3.5.2]
    at io.vertx.core.impl.HAManager.<init>(HAManager.java:145) ~[vertx-core-3.2.1.jar:na]
    at io.vertx.core.impl.VertxImpl.lambda$new$270(VertxImpl.java:152) ~[vertx-core-3.2.1.jar:na]
    at io.vertx.core.impl.VertxImpl$$Lambda$3/852445367.handle(Unknown Source) ~[na:na]
    at io.vertx.core.impl.FutureImpl.checkCallHandler(FutureImpl.java:158) ~[vertx-core-3.2.1.jar:na]
    at io.vertx.core.impl.FutureImpl.setHandler(FutureImpl.java:100) ~[vertx-core-3.2.1.jar:na]
    at io.vertx.core.impl.ContextImpl.lambda$null$16(ContextImpl.java:305) ~[vertx-core-3.2.1.jar:na]
    at io.vertx.core.impl.ContextImpl$$Lambda$7/299713639.handle(Unknown Source) ~[na:na]
    at io.vertx.core.impl.ContextImpl.lambda$wrapTask$18(ContextImpl.java:335) ~[vertx-core-3.2.1.jar:na]
    at io.vertx.core.impl.ContextImpl$$Lambda$8/977225900.run(Unknown Source) ~[na:na]
    at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:358) ~[netty-common-4.0.33.Final.jar:4.0.33.Final]
    at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:357) ~[netty-transport-4.0.33.Final.jar:4.0.33.Final]
    at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112) ~[netty-common-4.0.33.Final.jar:4.0.33.Final]
    at java.lang.Thread.run(Thread.java:744) ~[na:1.8.0]

[peterhendriks]

We see similar stack traces during shutdown. We think it may relate to our shutdown strategy (we shutdown all running applications at the same time). This does not always happen, but the "beforeLeave" method seems to block for a timeout of 60 seconds before dropping off.

14:08:19.735 WARN  - Thread Thread[vert.x-eventloop-thread-0,5,main] has been blocked for 55494 ms, time limit is 2000
io.vertx.core.VertxException: Thread blocked
        at java.lang.Object.wait(Native Method) ~[na:1.8.0_45]
        at com.hazelcast.spi.impl.operationservice.impl.InvocationFuture.pollResponse(InvocationFuture.java:299) ~[hazelcast-3.5.2.jar:3.5.2]
        at com.hazelcast.spi.impl.operationservice.impl.InvocationFuture.waitForResponse(InvocationFuture.java:247) ~[hazelcast-3.5.2.jar:3.5.2]
        at com.hazelcast.spi.impl.operationservice.impl.InvocationFuture.get(InvocationFuture.java:224) ~[hazelcast-3.5.2.jar:3.5.2]
        at com.hazelcast.spi.impl.operationservice.impl.InvocationFuture.get(InvocationFuture.java:204) ~[hazelcast-3.5.2.jar:3.5.2]
        at com.hazelcast.concurrent.lock.LockProxySupport.tryLock(LockProxySupport.java:112) ~[hazelcast-3.5.2.jar:3.5.2]
        at com.hazelcast.concurrent.lock.LockProxy.tryLock(LockProxy.java:95) ~[hazelcast-3.5.2.jar:3.5.2]
        at io.vertx.spi.cluster.hazelcast.HazelcastClusterManager.beforeLeave(HazelcastClusterManager.java:314) ~[vertx-hazelcast-3.2.0.jar:na]
        at io.vertx.core.impl.VertxImpl.closeClusterManager(VertxImpl.java:434) ~[vertx-core-3.2.0.jar:na]
        at io.vertx.core.impl.VertxImpl.lambda$null$273(VertxImpl.java:464) ~[vertx-core-3.2.0.jar:na]
        at io.vertx.core.impl.VertxImpl$$Lambda$161/1184067991.handle(Unknown Source) ~[na:na]
        at io.vertx.core.eventbus.impl.clustered.ClusteredEventBus.lambda$null$127(ClusteredEventBus.java:127) ~[vertx-core-3.2.0.jar:na]
        at io.vertx.core.eventbus.impl.clustered.ClusteredEventBus$$Lambda$164/766519636.handle(Unknown Source) ~[na:na]
        at io.vertx.core.net.impl.NetServerImpl.lambda$executeCloseDone$35(NetServerImpl.java:401) ~[vertx-core-3.2.0.jar:na]
        at io.vertx.core.net.impl.NetServerImpl$$Lambda$166/60718830.handle(Unknown Source) ~[na:na]
        at io.vertx.core.impl.ContextImpl.lambda$wrapTask$16(ContextImpl.java:335) ~[vertx-core-3.2.0.jar:na]
        at io.vertx.core.impl.ContextImpl$$Lambda$25/973990248.run(Unknown Source) ~[na:na]
        at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:358) ~[netty-common-4.0.33.Final.jar:4.0.33.Final]
        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:357) ~[netty-transport-4.0.33.Final.jar:4.0.33.Final]
        at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112) ~[netty-common-4.0.33.Final.jar:4.0.33.Final]

[vietj]

@tsegismont what's your opinion on this ?

[tsegismont]

@vietj I don't know why the haInfo map was created as a sync map in the first place. But since it was created like this, it is possible that some operations block the event loop. To fix that properly, we should wrap its usage with executeBlocking, but that means changing a few HAManager methods signature. I wouldn't do that for 3.4.

[vietj]

@tsegismont can you provide a patch to fix this for 3.6.0 ?

[vietj]

assigned to you @tsegismont