mesh
mesh copied to clipboard
Published
20 hours ago •
gentics
gentics
Lock in writes is throwing blocking thread errors in logs
Gentics Mesh Version, operating system, or hardware.
- v1.4.4.
Problem
When a topology lock timeout is define (for example 60 000ms) AND node is entering in backup process AND we are modifying node we can see theses errors logs:
getmesh-staging-master-0 getmesh 14:14:44.308 WARN [vertx-blocked-thread-checker] [i.v.c.i.BlockedThreadChecker] - Thread Thread[vert.x-eventloop-thread-3,5,main]=Thread[vert.x-eventloop-thread-3,5,main] has been blocked for 46755 ms, time limit is 2000 ms
getmesh-staging-master-0 getmesh io.vertx.core.VertxException: Thread blocked
getmesh-staging-master-0 getmesh at [email protected]/java.lang.Thread.sleep(Native Method)
getmesh-staging-master-0 getmesh at app//com.gentics.mesh.graphdb.OrientDBDatabase.blockingTopologyLockCheck(OrientDBDatabase.java:391)
getmesh-staging-master-0 getmesh at app//com.syncleus.ferma.ext.orientdb3.OrientDBTx.close(OrientDBTx.java:61)
getmesh-staging-master-0 getmesh at app//com.gentics.mesh.graphdb.OrientDBDatabase.tx(OrientDBDatabase.java:417)
getmesh-staging-master-0 getmesh at app//com.gentics.madl.tx.TxFactory.tx(TxFactory.java:70)
getmesh-staging-master-0 getmesh at app//com.gentics.mesh.auth.handler.MeshAnonymousAuthHandler.handle(MeshAnonymousAuthHandler.java:85)
getmesh-staging-master-0 getmesh at app//com.gentics.mesh.auth.MeshAuthChain.lambda$secure$1(MeshAuthChain.java:48)
getmesh-staging-master-0 getmesh at app//com.gentics.mesh.auth.MeshAuthChain$$Lambda$587/0x0000000100b51040.handle(Unknown Source)
getmesh-staging-master-0 getmesh at app//io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1034)
getmesh-staging-master-0 getmesh at app//io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:95)
getmesh-staging-master-0 getmesh at app//io.vertx.ext.web.impl.RoutingContextWrapper.next(RoutingContextWrapper.java:160)
getmesh-staging-master-0 getmesh at app//com.gentics.mesh.auth.MeshOAuth2ServiceImpl.lambda$secure$2(MeshOAuth2ServiceImpl.java:147)
getmesh-staging-master-0 getmesh at app//com.gentics.mesh.auth.MeshOAuth2ServiceImpl$$Lambda$582/0x0000000100b50040.handle(Unknown Source)
getmesh-staging-master-0 getmesh at app//io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1034)
getmesh-staging-master-0 getmesh at app//io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:95)
getmesh-staging-master-0 getmesh at app//io.vertx.ext.web.impl.RoutingContextWrapper.next(RoutingContextWrapper.java:160)
getmesh-staging-master-0 getmesh at app//com.gentics.mesh.auth.MeshOAuth2ServiceImpl.lambda$secure$0(MeshOAuth2ServiceImpl.java:132)
getmesh-staging-master-0 getmesh at app//com.gentics.mesh.auth.MeshOAuth2ServiceImpl$$Lambda$577/0x0000000100b45840.handle(Unknown Source)
getmesh-staging-master-0 getmesh at app//io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1034)
getmesh-staging-master-0 getmesh at app//io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:95)
getmesh-staging-master-0 getmesh at app//io.vertx.ext.web.impl.RoutingContextWrapper.next(RoutingContextWrapper.java:160)
getmesh-staging-master-0 getmesh at app//com.gentics.mesh.auth.handler.MeshJWTAuthHandler.handleJWTAuth(MeshJWTAuthHandler.java:139)
getmesh-staging-master-0 getmesh at app//com.gentics.mesh.auth.handler.MeshJWTAuthHandler.handle(MeshJWTAuthHandler.java:89)
getmesh-staging-master-0 getmesh at app//com.gentics.mesh.auth.MeshAuthChain.lambda$secure$0(MeshAuthChain.java:40)
getmesh-staging-master-0 getmesh at app//com.gentics.mesh.auth.MeshAuthChain$$Lambda$572/0x0000000100b46040.handle(Unknown Source)
getmesh-staging-master-0 getmesh at app//io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1034)
getmesh-staging-master-0 getmesh at app//io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:131)
getmesh-staging-master-0 getmesh at app//io.vertx.ext.web.impl.RoutingContextWrapper.next(RoutingContextWrapper.java:160)
getmesh-staging-master-0 getmesh at app//io.vertx.ext.web.impl.RoutingContextWrapper.next(RoutingContextWrapper.java:162)
getmesh-staging-master-0 getmesh at app//io.vertx.ext.web.impl.RouterImpl.handleContext(RouterImpl.java:235)
getmesh-staging-master-0 getmesh at app//io.vertx.ext.web.impl.RouteImpl$$Lambda$556/0x0000000100b41040.handle(Unknown Source)
getmesh-staging-master-0 getmesh at app//io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1034)
getmesh-staging-master-0 getmesh at app//io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:131)
getmesh-staging-master-0 getmesh at app//io.vertx.ext.web.impl.RoutingContextWrapper.next(RoutingContextWrapper.java:160)
getmesh-staging-master-0 getmesh at app//io.vertx.ext.web.handler.impl.CookieHandlerImpl.handle(CookieHandlerImpl.java:39)
getmesh-staging-master-0 getmesh at app//io.vertx.ext.web.handler.impl.CookieHandlerImpl.handle(CookieHandlerImpl.java:35)
getmesh-staging-master-0 getmesh at app//io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1034)
getmesh-staging-master-0 getmesh at app//io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:131)
getmesh-staging-master-0 getmesh at app//io.vertx.ext.web.impl.RoutingContextWrapper.next(RoutingContextWrapper.java:160)
getmesh-staging-master-0 getmesh at app//io.vertx.ext.web.handler.impl.BodyHandlerImpl$BHandler.doEnd(BodyHandlerImpl.java:296)
getmesh-staging-master-0 getmesh at app//io.vertx.ext.web.handler.impl.BodyHandlerImpl$BHandler.end(BodyHandlerImpl.java:276)
getmesh-staging-master-0 getmesh at app//io.vertx.ext.web.handler.impl.BodyHandlerImpl.lambda$handle$0(BodyHandlerImpl.java:87)
getmesh-staging-master-0 getmesh at app//io.vertx.ext.web.handler.impl.BodyHandlerImpl$$Lambda$1444/0x0000000100de2c40.handle(Unknown Source)
getmesh-staging-master-0 getmesh at app//io.vertx.core.http.impl.HttpServerRequestImpl.onEnd(HttpServerRequestImpl.java:530)
getmesh-staging-master-0 getmesh at app//io.vertx.core.http.impl.HttpServerRequestImpl.handleEnd(HttpServerRequestImpl.java:516)
getmesh-staging-master-0 getmesh at app//io.vertx.core.http.impl.Http1xServerConnection.handleEnd(Http1xServerConnection.java:176)
getmesh-staging-master-0 getmesh at app//io.vertx.core.http.impl.Http1xServerConnection.handleMessage(Http1xServerConnection.java:138)
getmesh-staging-master-0 getmesh at app//io.vertx.core.net.impl.VertxHandler$$Lambda$1429/0x0000000100de7040.handle(Unknown Source)
getmesh-staging-master-0 getmesh at app//io.vertx.core.impl.ContextImpl.executeTask(ContextImpl.java:369)
getmesh-staging-master-0 getmesh at app//io.vertx.core.impl.EventLoopContext.execute(EventLoopContext.java:43)
getmesh-staging-master-0 getmesh at app//io.vertx.core.impl.ContextImpl.executeFromIO(ContextImpl.java:232)
getmesh-staging-master-0 getmesh at app//io.vertx.core.net.impl.VertxHandler.channelRead(VertxHandler.java:173)
getmesh-staging-master-0 getmesh at app//io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:374)
getmesh-staging-master-0 getmesh at app//io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:360)
getmesh-staging-master-0 getmesh at app//io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:352)
getmesh-staging-master-0 getmesh at app//io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:93)
getmesh-staging-master-0 getmesh at app//io.netty.handler.codec.http.websocketx.extensions.WebSocketServerExtensionHandler.channelRead(WebSocketServerExtensionHandler.java:102)
getmesh-staging-master-0 getmesh at app//io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:374)
getmesh-staging-master-0 getmesh at app//io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:360)
getmesh-staging-master-0 getmesh at app//io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:352)
getmesh-staging-master-0 getmesh at app//io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:102)
getmesh-staging-master-0 getmesh at app//io.netty.handler.codec.MessageToMessageCodec.channelRead(MessageToMessageCodec.java:111)
getmesh-staging-master-0 getmesh at app//io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:374)
getmesh-staging-master-0 getmesh at app//io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:360)
getmesh-staging-master-0 getmesh at app//io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:352)
getmesh-staging-master-0 getmesh at app//io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:328)
getmesh-staging-master-0 getmesh at app//io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:302)
getmesh-staging-master-0 getmesh at app//io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:374)
getmesh-staging-master-0 getmesh at app//io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:360)
getmesh-staging-master-0 getmesh at app//io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:352)
getmesh-staging-master-0 getmesh at app//io.vertx.core.http.impl.Http1xOrH2CHandler.end(Http1xOrH2CHandler.java:61)
getmesh-staging-master-0 getmesh at app//io.vertx.core.http.impl.Http1xOrH2CHandler.channelRead(Http1xOrH2CHandler.java:38)
getmesh-staging-master-0 getmesh at app//io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:374)
getmesh-staging-master-0 getmesh at app//io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:360)
getmesh-staging-master-0 getmesh at app//io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:352)
getmesh-staging-master-0 getmesh at app//io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1422)
getmesh-staging-master-0 getmesh at app//io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:374)
getmesh-staging-master-0 getmesh at app//io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:360)
getmesh-staging-master-0 getmesh at app//io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:931)
getmesh-staging-master-0 getmesh at app//io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:792)
getmesh-staging-master-0 getmesh at app//io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:483)
getmesh-staging-master-0 getmesh at app//io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:383)
getmesh-staging-master-0 getmesh at app//io.netty.util.concurrent.SingleThreadEventExecutor$6.run(SingleThreadEventExecutor.java:1044)
getmesh-staging-master-0 getmesh at app//io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
getmesh-staging-master-0 getmesh at app//io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
getmesh-staging-master-0 getmesh at [email protected]/java.lang.Thread.run(Unknown Source)
Reproducer
Start a node in cluster mode, and with topology lock timeout setted to a large value, launch a backup, then modify a node. the lock wait mechanism is throwing error in logs
Expected behaviour and actual behaviour
no errors in logs.
Seems that the lock mechanism is working fine, but the lock is not 'reactive'
Vert.x will always log blocked threads. This works as designed. We hope to use a dedicated worker thread for transactions and thus be able to configure the logs.
Additionally I noticed that MeshAuthChain is running a tx in the eventloop. This should not happen. We need to address this.
