flow icon indicating copy to clipboard operation
flow copied to clipboard

Published 20 hours ago • verified publisher icon vaadin

Blocked thread on ViteWebsocketConnection creation

Open mcollovati opened this issue 3 months ago • 0 comments

Description of the bug

In a Quarkus application, I noticed that @QuarkusTest tests are hanging because of a blocking call on ViteWebsocketConnection constructor, when creating the web socket client (buildAsync(...).get()). Unfortunately, the issue happens only on GH action and only for that project. I was unable to reproduce it locally, nor on Vaadin Quarkus starter project.

Below, the log printed by Vert.x blocked threads detector and the part of the threads dump, showing blocking operations on ViteWebsocketConnection and ViteWebsocketProxy.

My understating is that there is some sort of deadlock, having ViteWebsocketConnection starting to receiving web socket messages before being completely initialized and forwarding them to ViteWebsocketProxy that in turn is still waiting to get the reference to ViteWebsocketConnection

The tests started to fail after https://github.com/vaadin/flow/pull/19340 has been merged into 24.4 branch. Probably, it worked previously because messages were forwarded asynchronously, letting the blocking call to buildAsync().get() to complete.

Vert.x blocked threads detector 
	Suppressed: io.vertx.core.VertxException: Thread blocked
		at [email protected]/jdk.internal.misc.Unsafe.park(Native Method)
		at [email protected]/java.util.concurrent.locks.LockSupport.park(LockSupport.java:211)
		at [email protected]/java.util.concurrent.CompletableFuture$Signaller.block(CompletableFuture.java:1864)
		at [email protected]/java.util.concurrent.ForkJoinPool.unmanagedBlock(ForkJoinPool.java:3465)
		at [email protected]/java.util.concurrent.ForkJoinPool.managedBlock(ForkJoinPool.java:3436)
		at [email protected]/java.util.concurrent.CompletableFuture.waitingGet(CompletableFuture.java:1898)
		at [email protected]/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2072)
		at com.vaadin.base.devserver.viteproxy.ViteWebsocketConnection.<init>(ViteWebsocketConnection.java:78)
		at com.vaadin.base.devserver.viteproxy.ViteWebsocketProxy.<init>(ViteWebsocketProxy.java:57)
		at com.vaadin.base.devserver.viteproxy.ViteWebsocketEndpoint.onOpen(ViteWebsocketEndpoint.java:96)
		at io.undertow.websockets.EndpointSessionHandler.connected(EndpointSessionHandler.java:119)
		at io.undertow.websockets.vertx.VertxWebSocketHandler$1.accept(VertxWebSocketHandler.java:120)
		at io.undertow.websockets.vertx.VertxWebSocketHandler$1.accept(VertxWebSocketHandler.java:117)
		at io.undertow.websockets.handshake.Handshake$1.accept(Handshake.java:147)
		at io.undertow.websockets.vertx.VertxWebSocketHttpExchange$1.handle(VertxWebSocketHttpExchange.java:129)
		at io.undertow.websockets.vertx.VertxWebSocketHttpExchange$1.handle(VertxWebSocketHttpExchange.java:121)
Threads dump 
Thread ForkJoinPool.commonPool-worker-2: WAITING
Waiting on io.netty.channel.DefaultChannelPromise@511f2565
Stack:
 [email protected]/java.lang.Object.wait(Native Method)
 [email protected]/java.lang.Object.wait(Object.java:338)
 io.netty.util.concurrent.DefaultPromise.await(DefaultPromise.java:254)
 io.netty.channel.DefaultChannelPromise.await(DefaultChannelPromise.java:131)
 io.netty.channel.DefaultChannelPromise.await(DefaultChannelPromise.java:30)
 io.netty.util.concurrent.DefaultPromise.get(DefaultPromise.java:338)
 io.undertow.websockets.WebSocketSessionRemoteEndpoint$BasicWebSocketSessionRemoteEndpoint.sendText(WebSocketSessionRemoteEndpoint.java:257)
 com.vaadin.base.devserver.viteproxy.ViteWebsocketProxy.lambda$new$0(ViteWebsocketProxy.java:59)
 com.vaadin.base.devserver.viteproxy.ViteWebsocketProxy$$Lambda$2473/0x00007f574cbfd1f0.accept(Unknown Source)
 com.vaadin.base.devserver.viteproxy.ViteWebsocketConnection.onText(ViteWebsocketConnection.java:112)
 platform/[email protected]/jdk.internal.net.http.websocket.WebSocketImpl$ReceiveTask.processText(WebSocketImpl.java:635)
 platform/[email protected]/jdk.internal.net.http.websocket.WebSocketImpl$ReceiveTask.run(WebSocketImpl.java:443)
 platform/[email protected]/jdk.internal.net.http.common.SequentialScheduler$CompleteRestartableTask.run(SequentialScheduler.java:149)
 platform/[email protected]/jdk.internal.net.http.common.SequentialScheduler$TryEndDeferredCompleter.complete(SequentialScheduler.java:347)
 platform/[email protected]/jdk.internal.net.http.common.SequentialScheduler$CompleteRestartableTask.run(SequentialScheduler.java:151)
 platform/[email protected]/jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(SequentialScheduler.java:230)
 platform/[email protected]/jdk.internal.net.http.HttpClientImpl$DelegatingExecutor.execute(HttpClientImpl.java:157)
 platform/[email protected]/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:305)
 platform/[email protected]/jdk.internal.net.http.common.SequentialScheduler.runOrSchedule(SequentialScheduler.java:274)
 platform/[email protected]/jdk.internal.net.http.websocket.WebSocketImpl.signalOpen(WebSocketImpl.java:713)
 platform/[email protected]/jdk.internal.net.http.websocket.WebSocketImpl.newInstance(WebSocketImpl.java:155)
 platform/[email protected]/jdk.internal.net.http.websocket.WebSocketImpl.lambda$newInstanceAsync$0(WebSocketImpl.java:125)
 platform/[email protected]/jdk.internal.net.http.websocket.WebSocketImpl$$Lambda$2370/0x00007f574cb58000.apply(Unknown Source)
 [email protected]/java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:646)
 [email protected]/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510)
 [email protected]/java.util.concurrent.CompletableFuture.postFire(CompletableFuture.java:614)
 [email protected]/java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:844)
 [email protected]/java.util.concurrent.CompletableFuture$Completion.exec(CompletableFuture.java:483)
 [email protected]/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:373)
 [email protected]/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1182)
 [email protected]/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1655)
 [email protected]/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1622)
 [email protected]/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:165)
 



Thread vert.x-eventloop-thread-1: WAITING
Waiting on java.util.concurrent.CompletableFuture$Signaller@63800567
Stack:
 [email protected]/jdk.internal.misc.Unsafe.park(Native Method)
 [email protected]/java.util.concurrent.locks.LockSupport.park(LockSupport.java:211)
 [email protected]/java.util.concurrent.CompletableFuture$Signaller.block(CompletableFuture.java:1864)
 [email protected]/java.util.concurrent.ForkJoinPool.unmanagedBlock(ForkJoinPool.java:3465)
 [email protected]/java.util.concurrent.ForkJoinPool.managedBlock(ForkJoinPool.java:3436)
 [email protected]/java.util.concurrent.CompletableFuture.waitingGet(CompletableFuture.java:1898)
 [email protected]/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2072)
 com.vaadin.base.devserver.viteproxy.ViteWebsocketConnection.<init>(ViteWebsocketConnection.java:78)
 com.vaadin.base.devserver.viteproxy.ViteWebsocketProxy.<init>(ViteWebsocketProxy.java:57)
 com.vaadin.base.devserver.viteproxy.ViteWebsocketEndpoint.onOpen(ViteWebsocketEndpoint.java:96)
 io.undertow.websockets.EndpointSessionHandler.connected(EndpointSessionHandler.java:119)
 io.undertow.websockets.vertx.VertxWebSocketHandler$1.accept(VertxWebSocketHandler.java:120)
 io.undertow.websockets.vertx.VertxWebSocketHandler$1.accept(VertxWebSocketHandler.java:117)
 io.undertow.websockets.handshake.Handshake$1.accept(Handshake.java:147)
 io.undertow.websockets.vertx.VertxWebSocketHttpExchange$1.handle(VertxWebSocketHttpExchange.java:129)
 io.undertow.websockets.vertx.VertxWebSocketHttpExchange$1.handle(VertxWebSocketHttpExchange.java:121)
 io.vertx.core.impl.future.FutureImpl$4.onSuccess(FutureImpl.java:176)
 io.vertx.core.impl.future.FutureBase.lambda$emitSuccess$0(FutureBase.java:60)
 io.vertx.core.impl.future.FutureBase$$Lambda$1813/0x00007f574c9e4000.run(Unknown Source)
 io.vertx.core.impl.ContextImpl.execute(ContextImpl.java:298)
 io.vertx.core.impl.DuplicatedContext.execute(DuplicatedContext.java:171)
 io.vertx.core.impl.future.FutureBase.emitSuccess(FutureBase.java:57)
 io.vertx.core.impl.future.FutureImpl.tryComplete(FutureImpl.java:259)
 io.vertx.core.Promise.complete(Promise.java:66)
 io.vertx.core.impl.future.PromiseImpl.operationComplete(PromiseImpl.java:65)
 io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:590)
 io.netty.util.concurrent.DefaultPromise.notifyListeners0(DefaultPromise.java:583)
 io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:559)
 io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:492)
 io.netty.util.concurrent.DefaultPromise.setValue0(DefaultPromise.java:636)
 io.netty.util.concurrent.DefaultPromise.setSuccess0(DefaultPromise.java:625)
 io.netty.util.concurrent.DefaultPromise.trySuccess(DefaultPromise.java:105)
 io.netty.util.internal.PromiseNotificationUtil.trySuccess(PromiseNotificationUtil.java:48)
 io.netty.channel.ChannelOutboundBuffer.safeSuccess(ChannelOutboundBuffer.java:748)
 io.netty.channel.ChannelOutboundBuffer.remove(ChannelOutboundBuffer.java:303)
 io.netty.channel.ChannelOutboundBuffer.removeBytes(ChannelOutboundBuffer.java:383)
 io.netty.channel.socket.nio.NioSocketChannel.doWrite(NioSocketChannel.java:421)
 io.netty.channel.AbstractChannel$AbstractUnsafe.flush0(AbstractChannel.java:931)
 io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.flush0(AbstractNioChannel.java:359)
 io.netty.channel.AbstractChannel$AbstractUnsafe.flush(AbstractChannel.java:895)
 io.netty.channel.DefaultChannelPipeline$HeadContext.flush(DefaultChannelPipeline.java:1372)
 io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:935)
 io.netty.channel.AbstractChannelHandlerContext.invokeFlush(AbstractChannelHandlerContext.java:921)
 io.netty.channel.AbstractChannelHandlerContext.flush(AbstractChannelHandlerContext.java:[907]
 io.vertx.core.net.impl.ConnectionBase.endReadAndFlush(ConnectionBase.java:146)
 io.vertx.core.net.impl.VertxHandler.channelReadComplete(VertxHandler.java:148)
 io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:484)
 io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:463)
 io.netty.channel.AbstractChannelHandlerContext.fireChannelReadComplete(AbstractChannelHandlerContext.java:456)
 io.netty.handler.timeout.IdleStateHandler.channelReadComplete(IdleStateHandler.java:298)
 io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:484)
 io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:463)
 io.netty.channel.AbstractChannelHandlerContext.fireChannelReadComplete(AbstractChannelHandlerContext.java:456)
 io.netty.handler.codec.ByteToMessageDecoder.channelReadComplete(ByteToMessageDecoder.java:359)
 io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:486)
 io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:463)
 io.netty.channel.AbstractChannelHandlerContext.fireChannelReadComplete(AbstractChannelHandlerContext.java:456)
 io.netty.channel.DefaultChannelPipeline$HeadContext.channelReadComplete(DefaultChannelPipeline.java:1415)
 io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:482)
 io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:463)
 io.netty.channel.DefaultChannelPipeline.fireChannelReadComplete(DefaultChannelPipeline.java:[925]
 io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:171)
 io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:788)
 io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:724)
 io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:650)
 io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:562)
 io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997)
 io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
 io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
 [email protected]/java.lang.Thread.run(Thread.java:840)

Expected behavior

ViteWebsocketConnection being able to establish the web socket connection and thread does not hang on buildAsync(...).get()

Minimal reproducible example

Unfortunately, it seems to happen only in some project/environments (Quarkus app + GH actions). So, no reproducer at the moment,

Versions

  • Vaadin / Flow version: 24.4
  • Java version: 17
  • OS version: Ubuntu 22.04.4 (GH actions image)
  • Application Server: Quarkus + Undertow + Vert.x

mcollovati avatar May 16 '24 11:05 mcollovati