Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Event loop blocked inside vertx-pg-client during DNS resolution #1429

Open
sishbi opened this issue Mar 22, 2024 · 12 comments
Open

Event loop blocked inside vertx-pg-client during DNS resolution #1429

sishbi opened this issue Mar 22, 2024 · 12 comments
Labels

Comments

@sishbi
Copy link

sishbi commented Mar 22, 2024

Questions

Thread Thread[vert.x-eventloop-thread-1,5,main] has been blocked for 2806 ms, time limit is 2000 ms

io.vertx.core.VertxException: Thread blocked
	at java.base/java.lang.ClassLoader.defineClass1(Native Method)
	at java.base/java.lang.ClassLoader.defineClass(ClassLoader.java:1027)
	at java.base/java.security.SecureClassLoader.defineClass(SecureClassLoader.java:150)
	at java.base/jdk.internal.loader.BuiltinClassLoader.defineClass(BuiltinClassLoader.java:862)
	at java.base/jdk.internal.loader.BuiltinClassLoader.findClassOnClassPathOrNull(BuiltinClassLoader.java:760)
	at java.base/jdk.internal.loader.BuiltinClassLoader.loadClassOrNull(BuiltinClassLoader.java:681)
	at java.base/jdk.internal.loader.BuiltinClassLoader.loadClass(BuiltinClassLoader.java:639)
	at java.base/jdk.internal.loader.ClassLoaders$AppClassLoader.loadClass(ClassLoaders.java:188)
	at java.base/java.lang.ClassLoader.loadClass(ClassLoader.java:526)
	at io.netty.handler.codec.dns.DatagramDnsQuery.<init>(DatagramDnsQuery.java:43)
	at io.netty.resolver.dns.DatagramDnsQueryContext.newQuery(DatagramDnsQueryContext.java:47)
	at io.netty.resolver.dns.DnsQueryContext.writeQuery(DnsQueryContext.java:215)
	at io.netty.resolver.dns.DnsNameResolver.doQuery(DnsNameResolver.java:1336)
	at io.netty.resolver.dns.DnsResolveContext.query(DnsResolveContext.java:471)
	at io.netty.resolver.dns.DnsResolveContext.query(DnsResolveContext.java:1191)
	at io.netty.resolver.dns.DnsResolveContext.internalResolve(DnsResolveContext.java:384)
	at io.netty.resolver.dns.DnsResolveContext.doSearchDomainQuery(DnsResolveContext.java:310)
	at io.netty.resolver.dns.DnsAddressResolveContext.doSearchDomainQuery(DnsAddressResolveContext.java:100)
	at io.netty.resolver.dns.DnsResolveContext.resolve(DnsResolveContext.java:272)
	at io.netty.resolver.dns.DnsNameResolver.resolveNow(DnsNameResolver.java:1220)
	at io.netty.resolver.dns.DnsNameResolver.doResolveAllUncached0(DnsNameResolver.java:1206)
	at io.netty.resolver.dns.DnsNameResolver.doResolveAllUncached(DnsNameResolver.java:1148)
	at io.netty.resolver.dns.DnsNameResolver.doResolveUncached(DnsNameResolver.java:1050)
	at io.netty.resolver.dns.DnsNameResolver.doResolve(DnsNameResolver.java:992)
	at io.netty.resolver.dns.DnsNameResolver.doResolve(DnsNameResolver.java:824)
	at io.netty.resolver.SimpleNameResolver.resolve(SimpleNameResolver.java:61)
	at io.netty.resolver.dns.InflightNameResolver.resolve(InflightNameResolver.java:100)
	at io.netty.resolver.dns.InflightNameResolver.resolve(InflightNameResolver.java:66)
	at io.netty.resolver.dns.InflightNameResolver.resolve(InflightNameResolver.java:51)
	at io.netty.resolver.InetSocketAddressResolver.doResolve(InetSocketAddressResolver.java:55)
	at io.netty.resolver.InetSocketAddressResolver.doResolve(InetSocketAddressResolver.java:31)
	at io.netty.resolver.AbstractAddressResolver.resolve(AbstractAddressResolver.java:106)
	at io.netty.bootstrap.Bootstrap.doResolveAndConnect0(Bootstrap.java:220)
	at io.netty.bootstrap.Bootstrap.doResolveAndConnect(Bootstrap.java:171)
	at io.netty.bootstrap.Bootstrap.connect(Bootstrap.java:148)
	at io.vertx.core.net.impl.ChannelProvider.handleConnect(ChannelProvider.java:152)
	at io.vertx.core.net.impl.ChannelProvider.connect(ChannelProvider.java:103)
	at io.vertx.core.net.impl.ChannelProvider.connect(ChannelProvider.java:89)
	at io.vertx.core.net.impl.NetClientImpl.connectInternal2(NetClientImpl.java:309)
	at io.vertx.core.net.impl.NetClientImpl.lambda$connectInternal$2(NetClientImpl.java:275)
	at io.vertx.core.impl.future.FutureImpl$4.onSuccess(FutureImpl.java:176)
	at io.vertx.core.impl.future.FutureBase.emitSuccess(FutureBase.java:66)
	at io.vertx.core.impl.future.FutureImpl.addListener(FutureImpl.java:231)
	at io.vertx.core.impl.future.FutureImpl.onComplete(FutureImpl.java:199)
	at io.vertx.core.net.impl.NetClientImpl.connectInternal(NetClientImpl.java:273)
	at io.vertx.core.net.impl.NetClientImpl.connect(NetClientImpl.java:230)
	at io.vertx.core.net.impl.NetClientImpl.connect(NetClientImpl.java:129)
	at io.vertx.core.net.impl.NetClientImpl.connect(NetClientImpl.java:124)
	at io.vertx.pgclient.impl.PgConnectionFactory.doConnect(PgConnectionFactory.java:137)
	at io.vertx.pgclient.impl.PgConnectionFactory.connect(PgConnectionFactory.java:118)
	at io.vertx.pgclient.impl.PgConnectionFactory.connect(PgConnectionFactory.java:98)
	at io.vertx.pgclient.impl.PgConnectionFactory.doConnectInternal(PgConnectionFactory.java:79)
	at io.vertx.sqlclient.impl.ConnectionFactoryBase.doConnectWithRetry(ConnectionFactoryBase.java:104)
	at io.vertx.sqlclient.impl.ConnectionFactoryBase.lambda$connect$0(ConnectionFactoryBase.java:88)
	at io.vertx.core.impl.ContextImpl.emit(ContextImpl.java:328)
	at io.vertx.core.impl.ContextImpl.emit(ContextImpl.java:321)
	at io.vertx.sqlclient.impl.ConnectionFactoryBase.connect(ConnectionFactoryBase.java:88)
	at io.vertx.pgclient.impl.PgConnectionFactory.connect(PgConnectionFactory.java:166)
	at io.vertx.sqlclient.spi.ConnectionFactory.lambda$connect$1(ConnectionFactory.java:26)
	at io.vertx.core.impl.future.Composition.onSuccess(Composition.java:38)
	at io.vertx.core.impl.future.FutureBase.lambda$emitSuccess$0(FutureBase.java:60)
	at io.vertx.core.impl.ContextImpl.execute(ContextImpl.java:298)
	at io.vertx.core.impl.ContextImpl.execute(ContextImpl.java:288)
	at io.vertx.core.impl.future.FutureBase.emitSuccess(FutureBase.java:57)
	at io.vertx.core.impl.future.FutureImpl.addListener(FutureImpl.java:231)
	at io.vertx.core.impl.future.FutureBase.compose(FutureBase.java:90)
	at io.vertx.core.impl.future.FutureImpl.compose(FutureImpl.java:28)
	at io.vertx.core.Future.compose(Future.java:375)
	at io.vertx.sqlclient.spi.ConnectionFactory.connect(ConnectionFactory.java:26)
	at io.vertx.sqlclient.impl.ConnectionFactoryBase.connect(ConnectionFactoryBase.java:94)
	at io.vertx.pgclient.spi.PgDriver.lambda$newPoolImpl$1(PgDriver.java:47)
	at io.vertx.sqlclient.impl.PoolImpl.lambda$new$0(PoolImpl.java:71)
	at io.vertx.sqlclient.impl.pool.SqlConnectionPool$2.connect(SqlConnectionPool.java:111)
	at io.vertx.core.net.impl.pool.SimpleConnectionPool.connect(SimpleConnectionPool.java:253)
	at io.vertx.core.net.impl.pool.SimpleConnectionPool$Acquire$3.run(SimpleConnectionPool.java:595)
	at io.vertx.core.net.impl.pool.Task.runNextTasks(Task.java:43)
	at io.vertx.core.net.impl.pool.CombinerExecutor.submit(CombinerExecutor.java:91)
	at io.vertx.core.net.impl.pool.SimpleConnectionPool.execute(SimpleConnectionPool.java:244)
	at io.vertx.core.net.impl.pool.SimpleConnectionPool.acquire(SimpleConnectionPool.java:639)
	at io.vertx.sqlclient.impl.pool.SqlConnectionPool.acquire(SqlConnectionPool.java:239)
	at io.vertx.sqlclient.impl.PoolImpl.acquire(PoolImpl.java:176)
	at io.vertx.sqlclient.impl.PoolImpl.getConnection(PoolImpl.java:139)
	at io.vertx.sqlclient.impl.PoolBase.getConnection(PoolBase.java:61)
	at com.kodypay.lychee.transactions.TransactionManager$Connection$Companion.transaction(transaction.kt:180)
	at com.kodypay.lychee.transactions.TransactionManager.begin(transaction.kt:47)
	at com.kodypay.lychee.transactions.TransactionManager.begin(transaction.kt:41)
	at com.kodypay.cards.tasks.TaskScheduler$monthly$1$1.invokeSuspend(TaskScheduler.kt:170)
	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
	at kotlinx.coroutines.internal.DispatchedContinuationKt.resumeCancellableWith(DispatchedContinuation.kt:363)
	at kotlinx.coroutines.intrinsics.CancellableKt.startCoroutineCancellable(Cancellable.kt:26)
	at kotlinx.coroutines.intrinsics.CancellableKt.startCoroutineCancellable$default(Cancellable.kt:21)
	at kotlinx.coroutines.CoroutineStart.invoke(CoroutineStart.kt:88)
	at kotlinx.coroutines.AbstractCoroutine.start(AbstractCoroutine.kt:123)
	at kotlinx.coroutines.BuildersKt__Builders_commonKt.launch(Builders.common.kt:52)
	at kotlinx.coroutines.BuildersKt.launch(Unknown Source)
	at kotlinx.coroutines.BuildersKt__Builders_commonKt.launch$default(Builders.common.kt:43)
	at kotlinx.coroutines.BuildersKt.launch$default(Unknown Source)
	at com.kodypay.cards.tasks.TaskScheduler.monthly$lambda$0(TaskScheduler.kt:76)
	at io.vertx.core.impl.VertxImpl$InternalTimerHandler.handle(VertxImpl.java:1053)
	at io.vertx.core.impl.VertxImpl$InternalTimerHandler.handle(VertxImpl.java:1029)
	at io.vertx.core.impl.ContextImpl.emit(ContextImpl.java:328)
	at io.vertx.core.impl.ContextImpl.emit(ContextImpl.java:321)
	at io.vertx.core.impl.ContextInternal.emit(ContextInternal.java:209)
	at io.vertx.core.impl.VertxImpl$InternalTimerHandler.run(VertxImpl.java:1047)
	at io.netty.util.concurrent.PromiseTask.runTask(PromiseTask.java:98)
	at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:159)
	at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:173)
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:166)
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:470)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:569)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:1583)

Version

4.5.4

Context

I think this only occurs during startup on the first time the service needs to lookup the IP address for the database host.
Our service is running within an AWS k8s cluster and uses AWS PostgreSQL RDS.

Do you have a reproducer?

I don't know if the issue is related to class loading or with the DNS request.
We have configured the 'include stack trace' option in the blocked-thread warning at 2 seconds, the same interval as the warning as we are just starting to look at these warnings and found that the reports that don't include the stack are harder to diagnose - it only lists the thread but as it is just a generic 'vertx-thread-1' then we can't find out exactly what was happening at the time.
But is the blocked thread report affected by always including the stack trace? If we didn't include the stack would the ClassLoader be included in the reported stack? Or should we read past that point and look at the first non-class-loader class?
So, in this case: io.netty.handler.codec.dns.DatagramDnsQuery.<init>

Steps to reproduce

  1. Start new container within an AWS k8s cluster
  2. Connect to an RDS
  3. Wait...

Extra

OS: AWS Linux (Docker container), x64 host
JVM: JDK 21, eclipse-temurin:21-jdk (Docker)

@sishbi sishbi added the bug label Mar 22, 2024
@vietj
Copy link
Member

vietj commented Mar 22, 2024

when it happens can you make a thread dump ? how long does it block ?

@sishbi sishbi changed the title Event loop blocking inside vertx-pg-client during DNS resolution Event loop blocked inside vertx-pg-client during DNS resolution Mar 22, 2024
@sishbi
Copy link
Author

sishbi commented Mar 22, 2024

when it happens can you make a thread dump ? how long does it block ?

As reported: 2806 ms

This is on a production instance, so no I don't think I can make a thread dump.
I haven't seen this in a local container, so I am not sure how I would reproduce.

We run our production containers pretty lean, so it may have been CPU throttled during startup:

          resources:
            requests:
              cpu: 200m
              memory: 512Mi
            limits:
              cpu: 1000m
              memory: 1Gi

@vietj
Copy link
Member

vietj commented Mar 22, 2024

does it always happen with the same stack trace ?

@sishbi
Copy link
Author

sishbi commented Mar 22, 2024

does it always happen with the same stack trace ?

We've only just started tracking blocked threads, for some reason we only logged vertx errors and were ignoring warnings. Now we include warnings in our DataDog stack we are getting these.
I will monitor to see when this occurs again and report back if the same stack appears multiple times.

Thanks for the rapid response 😄

@sishbi
Copy link
Author

sishbi commented Mar 23, 2024

Just adding additional stack traces as they occur...
Thread Thread[vert.x-eventloop-thread-1,5,main] has been blocked for 2001 ms, time limit is 2000 ms

io.vertx.core.VertxException: Thread blocked
	at java.base/java.lang.ClassLoader.defineClass1(Native Method)
	at java.base/java.lang.ClassLoader.defineClass(ClassLoader.java:1027)
	at java.base/java.security.SecureClassLoader.defineClass(SecureClassLoader.java:150)
	at java.base/jdk.internal.loader.BuiltinClassLoader.defineClass(BuiltinClassLoader.java:862)
	at java.base/jdk.internal.loader.BuiltinClassLoader.findClassOnClassPathOrNull(BuiltinClassLoader.java:760)
	at java.base/jdk.internal.loader.BuiltinClassLoader.loadClassOrNull(BuiltinClassLoader.java:681)
	at java.base/jdk.internal.loader.BuiltinClassLoader.loadClass(BuiltinClassLoader.java:639)
	at java.base/jdk.internal.loader.ClassLoaders$AppClassLoader.loadClass(ClassLoaders.java:188)
	at java.base/java.lang.ClassLoader.loadClass(ClassLoader.java:526)
	at io.netty.resolver.dns.DnsAddressResolverGroup.newResolver(DnsAddressResolverGroup.java:90)
	at io.netty.resolver.dns.DnsAddressResolverGroup.newResolver(DnsAddressResolverGroup.java:77)
	at io.netty.resolver.AddressResolverGroup.getResolver(AddressResolverGroup.java:70)
	at io.netty.bootstrap.Bootstrap.doResolveAndConnect0(Bootstrap.java:208)
	at io.netty.bootstrap.Bootstrap.doResolveAndConnect(Bootstrap.java:171)
	at io.netty.bootstrap.Bootstrap.connect(Bootstrap.java:148)
	at io.vertx.core.net.impl.ChannelProvider.handleConnect(ChannelProvider.java:152)
	at io.vertx.core.net.impl.ChannelProvider.connect(ChannelProvider.java:103)
	at io.vertx.core.net.impl.ChannelProvider.connect(ChannelProvider.java:89)
	at io.vertx.core.net.impl.NetClientImpl.connectInternal2(NetClientImpl.java:309)
	at io.vertx.core.net.impl.NetClientImpl.lambda$connectInternal$2(NetClientImpl.java:275)
	at io.vertx.core.impl.future.FutureImpl$4.onSuccess(FutureImpl.java:176)
	at io.vertx.core.impl.future.FutureBase.emitSuccess(FutureBase.java:66)
	at io.vertx.core.impl.future.FutureImpl.addListener(FutureImpl.java:231)
	at io.vertx.core.impl.future.FutureImpl.onComplete(FutureImpl.java:199)
	at io.vertx.core.net.impl.NetClientImpl.connectInternal(NetClientImpl.java:273)
	at io.vertx.core.net.impl.NetClientImpl.connect(NetClientImpl.java:230)
	at io.vertx.core.net.impl.NetClientImpl.connect(NetClientImpl.java:129)
	at io.vertx.core.net.impl.NetClientImpl.connect(NetClientImpl.java:124)
	at io.vertx.pgclient.impl.PgConnectionFactory.doConnect(PgConnectionFactory.java:137)
	at io.vertx.pgclient.impl.PgConnectionFactory.connect(PgConnectionFactory.java:118)
	at io.vertx.pgclient.impl.PgConnectionFactory.connect(PgConnectionFactory.java:98)
	at io.vertx.pgclient.impl.PgConnectionFactory.doConnectInternal(PgConnectionFactory.java:79)
	at io.vertx.sqlclient.impl.ConnectionFactoryBase.doConnectWithRetry(ConnectionFactoryBase.java:104)
	at io.vertx.sqlclient.impl.ConnectionFactoryBase.lambda$connect$0(ConnectionFactoryBase.java:88)
	at io.vertx.core.impl.ContextImpl.emit(ContextImpl.java:328)
	at io.vertx.core.impl.ContextImpl.emit(ContextImpl.java:321)
	at io.vertx.sqlclient.impl.ConnectionFactoryBase.connect(ConnectionFactoryBase.java:88)
	at io.vertx.pgclient.impl.PgConnectionFactory.connect(PgConnectionFactory.java:166)
	at io.vertx.sqlclient.spi.ConnectionFactory.lambda$connect$1(ConnectionFactory.java:26)
	at io.vertx.core.impl.future.Composition.onSuccess(Composition.java:38)
	at io.vertx.core.impl.future.FutureBase.lambda$emitSuccess$0(FutureBase.java:60)
	at io.vertx.core.impl.ContextImpl.execute(ContextImpl.java:298)
	at io.vertx.core.impl.ContextImpl.execute(ContextImpl.java:288)
	at io.vertx.core.impl.future.FutureBase.emitSuccess(FutureBase.java:57)
	at io.vertx.core.impl.future.FutureImpl.addListener(FutureImpl.java:231)
	at io.vertx.core.impl.future.FutureBase.compose(FutureBase.java:90)
	at io.vertx.core.impl.future.FutureImpl.compose(FutureImpl.java:28)
	at io.vertx.core.Future.compose(Future.java:375)
	at io.vertx.sqlclient.spi.ConnectionFactory.connect(ConnectionFactory.java:26)
	at io.vertx.sqlclient.impl.ConnectionFactoryBase.connect(ConnectionFactoryBase.java:94)
	at io.vertx.pgclient.spi.PgDriver.lambda$newPoolImpl$1(PgDriver.java:47)
	at io.vertx.sqlclient.impl.PoolImpl.lambda$new$0(PoolImpl.java:71)
	at io.vertx.sqlclient.impl.pool.SqlConnectionPool$2.connect(SqlConnectionPool.java:111)
	at io.vertx.core.net.impl.pool.SimpleConnectionPool.connect(SimpleConnectionPool.java:253)
	at io.vertx.core.net.impl.pool.SimpleConnectionPool$Acquire$3.run(SimpleConnectionPool.java:595)
	at io.vertx.core.net.impl.pool.Task.runNextTasks(Task.java:43)
	at io.vertx.core.net.impl.pool.CombinerExecutor.submit(CombinerExecutor.java:91)
	at io.vertx.core.net.impl.pool.SimpleConnectionPool.execute(SimpleConnectionPool.java:244)
	at io.vertx.core.net.impl.pool.SimpleConnectionPool.acquire(SimpleConnectionPool.java:639)
	at io.vertx.sqlclient.impl.pool.SqlConnectionPool.acquire(SqlConnectionPool.java:239)
	at io.vertx.sqlclient.impl.PoolImpl.acquire(PoolImpl.java:176)
	at io.vertx.sqlclient.impl.PoolImpl.getConnection(PoolImpl.java:139)
	at io.vertx.sqlclient.impl.PoolBase.getConnection(PoolBase.java:61)
	at com.kodypay.lychee.transactions.TransactionManager$Connection$Companion.transaction(transaction.kt:180)
	at com.kodypay.lychee.transactions.TransactionManager.begin(transaction.kt:47)
	at com.kodypay.lychee.transactions.TransactionManager.begin(transaction.kt:41)
	at com.kodypay.cards.tasks.TaskScheduler$monthly$1$1.invokeSuspend(TaskScheduler.kt:170)
	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
	at kotlinx.coroutines.internal.DispatchedContinuationKt.resumeCancellableWith(DispatchedContinuation.kt:363)
	at kotlinx.coroutines.intrinsics.CancellableKt.startCoroutineCancellable(Cancellable.kt:26)
	at kotlinx.coroutines.intrinsics.CancellableKt.startCoroutineCancellable$default(Cancellable.kt:21)
	at kotlinx.coroutines.CoroutineStart.invoke(CoroutineStart.kt:88)
	at kotlinx.coroutines.AbstractCoroutine.start(AbstractCoroutine.kt:123)
	at kotlinx.coroutines.BuildersKt__Builders_commonKt.launch(Builders.common.kt:52)
	at kotlinx.coroutines.BuildersKt.launch(Unknown Source)
	at kotlinx.coroutines.BuildersKt__Builders_commonKt.launch$default(Builders.common.kt:43)
	at kotlinx.coroutines.BuildersKt.launch$default(Unknown Source)
	at com.kodypay.cards.tasks.TaskScheduler.monthly$lambda$0(TaskScheduler.kt:76)
	at io.vertx.core.impl.VertxImpl$InternalTimerHandler.handle(VertxImpl.java:1053)
	at io.vertx.core.impl.VertxImpl$InternalTimerHandler.handle(VertxImpl.java:1029)
	at io.vertx.core.impl.ContextImpl.emit(ContextImpl.java:328)
	at io.vertx.core.impl.ContextImpl.emit(ContextImpl.java:321)
	at io.vertx.core.impl.ContextInternal.emit(ContextInternal.java:209)
	at io.vertx.core.impl.VertxImpl$InternalTimerHandler.run(VertxImpl.java:1047)
	at io.netty.util.concurrent.PromiseTask.runTask(PromiseTask.java:98)
	at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:159)
	at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:173)
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:166)
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:470)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:569)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:1583)

@sishbi
Copy link
Author

sishbi commented Mar 23, 2024

Thread Thread[vert.x-eventloop-thread-1,5,main] has been blocked for 3002 ms, time limit is 2000 ms

io.vertx.core.VertxException: Thread blocked
	at java.base/java.lang.ClassLoader.defineClass1(Native Method)
	at java.base/java.lang.ClassLoader.defineClass(ClassLoader.java:1027)
	at java.base/java.security.SecureClassLoader.defineClass(SecureClassLoader.java:150)
	at java.base/jdk.internal.loader.BuiltinClassLoader.defineClass(BuiltinClassLoader.java:862)
	at java.base/jdk.internal.loader.BuiltinClassLoader.findClassOnClassPathOrNull(BuiltinClassLoader.java:760)
	at java.base/jdk.internal.loader.BuiltinClassLoader.loadClassOrNull(BuiltinClassLoader.java:681)
	at java.base/jdk.internal.loader.BuiltinClassLoader.loadClass(BuiltinClassLoader.java:639)
	at java.base/jdk.internal.loader.ClassLoaders$AppClassLoader.loadClass(ClassLoaders.java:188)
	at java.base/java.lang.ClassLoader.loadClass(ClassLoader.java:526)
	at java.base/java.lang.ClassLoader.defineClass1(Native Method)
	at java.base/java.lang.ClassLoader.defineClass(ClassLoader.java:1027)
	at java.base/java.security.SecureClassLoader.defineClass(SecureClassLoader.java:150)
	at java.base/jdk.internal.loader.BuiltinClassLoader.defineClass(BuiltinClassLoader.java:862)
	at java.base/jdk.internal.loader.BuiltinClassLoader.findClassOnClassPathOrNull(BuiltinClassLoader.java:760)
	at java.base/jdk.internal.loader.BuiltinClassLoader.loadClassOrNull(BuiltinClassLoader.java:681)
	at java.base/jdk.internal.loader.BuiltinClassLoader.loadClass(BuiltinClassLoader.java:639)
	at java.base/jdk.internal.loader.ClassLoaders$AppClassLoader.loadClass(ClassLoaders.java:188)
	at java.base/java.lang.ClassLoader.loadClass(ClassLoader.java:526)
	at io.netty.resolver.dns.DnsNameResolver.resolveNow(DnsNameResolver.java:1217)
	at io.netty.resolver.dns.DnsNameResolver.doResolveAllUncached0(DnsNameResolver.java:1206)
	at io.netty.resolver.dns.DnsNameResolver.doResolveAllUncached(DnsNameResolver.java:1148)
	at io.netty.resolver.dns.DnsNameResolver.doResolveUncached(DnsNameResolver.java:1050)
	at io.netty.resolver.dns.DnsNameResolver.doResolve(DnsNameResolver.java:992)
	at io.netty.resolver.dns.DnsNameResolver.doResolve(DnsNameResolver.java:824)
	at io.netty.resolver.SimpleNameResolver.resolve(SimpleNameResolver.java:61)
	at io.netty.resolver.dns.InflightNameResolver.resolve(InflightNameResolver.java:100)
	at io.netty.resolver.dns.InflightNameResolver.resolve(InflightNameResolver.java:66)
	at io.netty.resolver.dns.InflightNameResolver.resolve(InflightNameResolver.java:51)
	at io.netty.resolver.InetSocketAddressResolver.doResolve(InetSocketAddressResolver.java:55)
	at io.netty.resolver.InetSocketAddressResolver.doResolve(InetSocketAddressResolver.java:31)
	at io.netty.resolver.AbstractAddressResolver.resolve(AbstractAddressResolver.java:106)
	at io.netty.bootstrap.Bootstrap.doResolveAndConnect0(Bootstrap.java:220)
	at io.netty.bootstrap.Bootstrap.doResolveAndConnect(Bootstrap.java:171)
	at io.netty.bootstrap.Bootstrap.connect(Bootstrap.java:148)
	at io.vertx.core.net.impl.ChannelProvider.handleConnect(ChannelProvider.java:152)
	at io.vertx.core.net.impl.ChannelProvider.connect(ChannelProvider.java:103)
	at io.vertx.core.net.impl.ChannelProvider.connect(ChannelProvider.java:89)
	at io.vertx.core.net.impl.NetClientImpl.connectInternal2(NetClientImpl.java:309)
	at io.vertx.core.net.impl.NetClientImpl.lambda$connectInternal$2(NetClientImpl.java:275)
	at io.vertx.core.impl.future.FutureImpl$4.onSuccess(FutureImpl.java:176)
	at io.vertx.core.impl.future.FutureBase.emitSuccess(FutureBase.java:66)
	at io.vertx.core.impl.future.FutureImpl.addListener(FutureImpl.java:231)
	at io.vertx.core.impl.future.FutureImpl.onComplete(FutureImpl.java:199)
	at io.vertx.core.net.impl.NetClientImpl.connectInternal(NetClientImpl.java:273)
	at io.vertx.core.net.impl.NetClientImpl.connect(NetClientImpl.java:230)
	at io.vertx.core.net.impl.NetClientImpl.connect(NetClientImpl.java:129)
	at io.vertx.core.net.impl.NetClientImpl.connect(NetClientImpl.java:124)
	at io.vertx.pgclient.impl.PgConnectionFactory.doConnect(PgConnectionFactory.java:137)
	at io.vertx.pgclient.impl.PgConnectionFactory.connect(PgConnectionFactory.java:118)
	at io.vertx.pgclient.impl.PgConnectionFactory.connect(PgConnectionFactory.java:98)
	at io.vertx.pgclient.impl.PgConnectionFactory.doConnectInternal(PgConnectionFactory.java:79)
	at io.vertx.sqlclient.impl.ConnectionFactoryBase.doConnectWithRetry(ConnectionFactoryBase.java:104)
	at io.vertx.sqlclient.impl.ConnectionFactoryBase.lambda$connect$0(ConnectionFactoryBase.java:88)
	at io.vertx.core.impl.ContextImpl.emit(ContextImpl.java:328)
	at io.vertx.core.impl.ContextImpl.emit(ContextImpl.java:321)
	at io.vertx.sqlclient.impl.ConnectionFactoryBase.connect(ConnectionFactoryBase.java:88)
	at io.vertx.pgclient.impl.PgConnectionFactory.connect(PgConnectionFactory.java:166)
	at io.vertx.sqlclient.spi.ConnectionFactory.lambda$connect$1(ConnectionFactory.java:26)
	at io.vertx.core.impl.future.Composition.onSuccess(Composition.java:38)
	at io.vertx.core.impl.future.FutureBase.lambda$emitSuccess$0(FutureBase.java:60)
	at io.vertx.core.impl.ContextImpl.execute(ContextImpl.java:298)
	at io.vertx.core.impl.ContextImpl.execute(ContextImpl.java:288)
	at io.vertx.core.impl.future.FutureBase.emitSuccess(FutureBase.java:57)
	at io.vertx.core.impl.future.FutureImpl.addListener(FutureImpl.java:231)
	at io.vertx.core.impl.future.FutureBase.compose(FutureBase.java:90)
	at io.vertx.core.impl.future.FutureImpl.compose(FutureImpl.java:28)
	at io.vertx.core.Future.compose(Future.java:375)
	at io.vertx.sqlclient.spi.ConnectionFactory.connect(ConnectionFactory.java:26)
	at io.vertx.sqlclient.impl.ConnectionFactoryBase.connect(ConnectionFactoryBase.java:94)
	at io.vertx.pgclient.spi.PgDriver.lambda$newPoolImpl$1(PgDriver.java:47)
	at io.vertx.sqlclient.impl.PoolImpl.lambda$new$0(PoolImpl.java:71)
	at io.vertx.sqlclient.impl.pool.SqlConnectionPool$2.connect(SqlConnectionPool.java:111)
	at io.vertx.core.net.impl.pool.SimpleConnectionPool.connect(SimpleConnectionPool.java:253)
	at io.vertx.core.net.impl.pool.SimpleConnectionPool$Acquire$3.run(SimpleConnectionPool.java:595)
	at io.vertx.core.net.impl.pool.Task.runNextTasks(Task.java:43)
	at io.vertx.core.net.impl.pool.CombinerExecutor.submit(CombinerExecutor.java:91)
	at io.vertx.core.net.impl.pool.SimpleConnectionPool.execute(SimpleConnectionPool.java:244)
	at io.vertx.core.net.impl.pool.SimpleConnectionPool.acquire(SimpleConnectionPool.java:639)
	at io.vertx.sqlclient.impl.pool.SqlConnectionPool.acquire(SqlConnectionPool.java:239)
	at io.vertx.sqlclient.impl.PoolImpl.acquire(PoolImpl.java:176)
	at io.vertx.sqlclient.impl.PoolImpl.getConnection(PoolImpl.java:139)
	at io.vertx.sqlclient.impl.PoolBase.getConnection(PoolBase.java:61)
	at com.kodypay.lychee.transactions.TransactionManager$Connection$Companion.transaction(transaction.kt:180)
	at com.kodypay.lychee.transactions.TransactionManager.begin(transaction.kt:47)
	at com.kodypay.lychee.transactions.TransactionManager.begin(transaction.kt:41)
	at com.kodypay.cards.tasks.TaskScheduler$monthly$1$1.invokeSuspend(TaskScheduler.kt:170)
	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
	at kotlinx.coroutines.internal.DispatchedContinuationKt.resumeCancellableWith(DispatchedContinuation.kt:363)
	at kotlinx.coroutines.intrinsics.CancellableKt.startCoroutineCancellable(Cancellable.kt:26)
	at kotlinx.coroutines.intrinsics.CancellableKt.startCoroutineCancellable$default(Cancellable.kt:21)
	at kotlinx.coroutines.CoroutineStart.invoke(CoroutineStart.kt:88)
	at kotlinx.coroutines.AbstractCoroutine.start(AbstractCoroutine.kt:123)
	at kotlinx.coroutines.BuildersKt__Builders_commonKt.launch(Builders.common.kt:52)
	at kotlinx.coroutines.BuildersKt.launch(Unknown Source)
	at kotlinx.coroutines.BuildersKt__Builders_commonKt.launch$default(Builders.common.kt:43)
	at kotlinx.coroutines.BuildersKt.launch$default(Unknown Source)
	at com.kodypay.cards.tasks.TaskScheduler.monthly$lambda$0(TaskScheduler.kt:76)
	at io.vertx.core.impl.VertxImpl$InternalTimerHandler.handle(VertxImpl.java:1053)
	at io.vertx.core.impl.VertxImpl$InternalTimerHandler.handle(VertxImpl.java:1029)
	at io.vertx.core.impl.ContextImpl.emit(ContextImpl.java:328)
	at io.vertx.core.impl.ContextImpl.emit(ContextImpl.java:321)
	at io.vertx.core.impl.ContextInternal.emit(ContextInternal.java:209)
	at io.vertx.core.impl.VertxImpl$InternalTimerHandler.run(VertxImpl.java:1047)
	at io.netty.util.concurrent.PromiseTask.runTask(PromiseTask.java:98)
	at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:159)
	at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:173)
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:166)
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:470)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:569)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:1583)

@sishbi
Copy link
Author

sishbi commented Mar 23, 2024

Thread Thread[vert.x-eventloop-thread-1,5,main] has been blocked for 2012 ms, time limit is 2000 ms

io.vertx.core.VertxException: Thread blocked
	at java.base/java.lang.ClassLoader.defineClass1(Native Method)
	at java.base/java.lang.ClassLoader.defineClass(ClassLoader.java:1027)
	at java.base/java.security.SecureClassLoader.defineClass(SecureClassLoader.java:150)
	at java.base/jdk.internal.loader.BuiltinClassLoader.defineClass(BuiltinClassLoader.java:862)
	at java.base/jdk.internal.loader.BuiltinClassLoader.findClassOnClassPathOrNull(BuiltinClassLoader.java:760)
	at java.base/jdk.internal.loader.BuiltinClassLoader.loadClassOrNull(BuiltinClassLoader.java:681)
	at java.base/jdk.internal.loader.BuiltinClassLoader.loadClass(BuiltinClassLoader.java:639)
	at java.base/jdk.internal.loader.ClassLoaders$AppClassLoader.loadClass(ClassLoaders.java:188)
	at java.base/java.lang.ClassLoader.loadClass(ClassLoader.java:526)
	at io.netty.resolver.dns.DnsNameResolver.<init>(DnsNameResolver.java:502)
	at io.netty.resolver.dns.DnsNameResolverBuilder.build(DnsNameResolverBuilder.java:570)
	at io.netty.resolver.dns.DnsAddressResolverGroup.newNameResolver(DnsAddressResolverGroup.java:114)
	at io.netty.resolver.dns.DnsAddressResolverGroup.newResolver(DnsAddressResolverGroup.java:92)
	at io.netty.resolver.dns.DnsAddressResolverGroup.newResolver(DnsAddressResolverGroup.java:77)
	at io.netty.resolver.AddressResolverGroup.getResolver(AddressResolverGroup.java:70)
	at io.netty.bootstrap.Bootstrap.doResolveAndConnect0(Bootstrap.java:208)
	at io.netty.bootstrap.Bootstrap.doResolveAndConnect(Bootstrap.java:171)
	at io.netty.bootstrap.Bootstrap.connect(Bootstrap.java:148)
	at io.vertx.core.net.impl.ChannelProvider.handleConnect(ChannelProvider.java:152)
	at io.vertx.core.net.impl.ChannelProvider.connect(ChannelProvider.java:103)
	at io.vertx.core.net.impl.ChannelProvider.connect(ChannelProvider.java:89)
	at io.vertx.core.net.impl.NetClientImpl.connectInternal2(NetClientImpl.java:309)
	at io.vertx.core.net.impl.NetClientImpl.lambda$connectInternal$2(NetClientImpl.java:275)
	at io.vertx.core.impl.future.FutureImpl$4.onSuccess(FutureImpl.java:176)
	at io.vertx.core.impl.future.FutureBase.emitSuccess(FutureBase.java:66)
	at io.vertx.core.impl.future.FutureImpl.addListener(FutureImpl.java:231)
	at io.vertx.core.impl.future.FutureImpl.onComplete(FutureImpl.java:199)
	at io.vertx.core.net.impl.NetClientImpl.connectInternal(NetClientImpl.java:273)
	at io.vertx.core.net.impl.NetClientImpl.connect(NetClientImpl.java:230)
	at io.vertx.core.net.impl.NetClientImpl.connect(NetClientImpl.java:129)
	at io.vertx.core.net.impl.NetClientImpl.connect(NetClientImpl.java:124)
	at io.vertx.pgclient.impl.PgConnectionFactory.doConnect(PgConnectionFactory.java:137)
	at io.vertx.pgclient.impl.PgConnectionFactory.connect(PgConnectionFactory.java:118)
	at io.vertx.pgclient.impl.PgConnectionFactory.connect(PgConnectionFactory.java:98)
	at io.vertx.pgclient.impl.PgConnectionFactory.doConnectInternal(PgConnectionFactory.java:79)
	at io.vertx.sqlclient.impl.ConnectionFactoryBase.doConnectWithRetry(ConnectionFactoryBase.java:104)
	at io.vertx.sqlclient.impl.ConnectionFactoryBase.lambda$connect$0(ConnectionFactoryBase.java:88)
	at io.vertx.core.impl.ContextImpl.emit(ContextImpl.java:328)
	at io.vertx.core.impl.ContextImpl.emit(ContextImpl.java:321)
	at io.vertx.sqlclient.impl.ConnectionFactoryBase.connect(ConnectionFactoryBase.java:88)
	at io.vertx.pgclient.impl.PgConnectionFactory.connect(PgConnectionFactory.java:166)
	at io.vertx.sqlclient.spi.ConnectionFactory.lambda$connect$1(ConnectionFactory.java:26)
	at io.vertx.core.impl.future.Composition.onSuccess(Composition.java:38)
	at io.vertx.core.impl.future.FutureBase.lambda$emitSuccess$0(FutureBase.java:60)
	at io.vertx.core.impl.ContextImpl.execute(ContextImpl.java:298)
	at io.vertx.core.impl.ContextImpl.execute(ContextImpl.java:288)
	at io.vertx.core.impl.future.FutureBase.emitSuccess(FutureBase.java:57)
	at io.vertx.core.impl.future.FutureImpl.addListener(FutureImpl.java:231)
	at io.vertx.core.impl.future.FutureBase.compose(FutureBase.java:90)
	at io.vertx.core.impl.future.FutureImpl.compose(FutureImpl.java:28)
	at io.vertx.core.Future.compose(Future.java:375)
	at io.vertx.sqlclient.spi.ConnectionFactory.connect(ConnectionFactory.java:26)
	at io.vertx.sqlclient.impl.ConnectionFactoryBase.connect(ConnectionFactoryBase.java:94)
	at io.vertx.pgclient.spi.PgDriver.lambda$newPoolImpl$1(PgDriver.java:47)
	at io.vertx.sqlclient.impl.PoolImpl.lambda$new$0(PoolImpl.java:71)
	at io.vertx.sqlclient.impl.pool.SqlConnectionPool$2.connect(SqlConnectionPool.java:111)
	at io.vertx.core.net.impl.pool.SimpleConnectionPool.connect(SimpleConnectionPool.java:253)
	at io.vertx.core.net.impl.pool.SimpleConnectionPool$Acquire$3.run(SimpleConnectionPool.java:595)
	at io.vertx.core.net.impl.pool.Task.runNextTasks(Task.java:43)
	at io.vertx.core.net.impl.pool.CombinerExecutor.submit(CombinerExecutor.java:91)
	at io.vertx.core.net.impl.pool.SimpleConnectionPool.execute(SimpleConnectionPool.java:244)
	at io.vertx.core.net.impl.pool.SimpleConnectionPool.acquire(SimpleConnectionPool.java:639)
	at io.vertx.sqlclient.impl.pool.SqlConnectionPool.acquire(SqlConnectionPool.java:239)
	at io.vertx.sqlclient.impl.PoolImpl.acquire(PoolImpl.java:176)
	at io.vertx.sqlclient.impl.PoolImpl.getConnection(PoolImpl.java:139)
	at io.vertx.sqlclient.impl.PoolBase.getConnection(PoolBase.java:61)
	at com.kodypay.lychee.transactions.TransactionManager$Connection$Companion.transaction(transaction.kt:180)
	at com.kodypay.lychee.transactions.TransactionManager.begin(transaction.kt:47)
	at com.kodypay.lychee.transactions.TransactionManager.begin(transaction.kt:41)
	at com.kodypay.cards.tasks.TaskScheduler$monthly$1$1.invokeSuspend(TaskScheduler.kt:170)
	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
	at kotlinx.coroutines.internal.DispatchedContinuationKt.resumeCancellableWith(DispatchedContinuation.kt:363)
	at kotlinx.coroutines.intrinsics.CancellableKt.startCoroutineCancellable(Cancellable.kt:26)
	at kotlinx.coroutines.intrinsics.CancellableKt.startCoroutineCancellable$default(Cancellable.kt:21)
	at kotlinx.coroutines.CoroutineStart.invoke(CoroutineStart.kt:88)
	at kotlinx.coroutines.AbstractCoroutine.start(AbstractCoroutine.kt:123)
	at kotlinx.coroutines.BuildersKt__Builders_commonKt.launch(Builders.common.kt:52)
	at kotlinx.coroutines.BuildersKt.launch(Unknown Source)
	at kotlinx.coroutines.BuildersKt__Builders_commonKt.launch$default(Builders.common.kt:43)
	at kotlinx.coroutines.BuildersKt.launch$default(Unknown Source)
	at com.kodypay.cards.tasks.TaskScheduler.monthly$lambda$0(TaskScheduler.kt:76)
	at io.vertx.core.impl.VertxImpl$InternalTimerHandler.handle(VertxImpl.java:1053)
	at io.vertx.core.impl.VertxImpl$InternalTimerHandler.handle(VertxImpl.java:1029)
	at io.vertx.core.impl.ContextImpl.emit(ContextImpl.java:328)
	at io.vertx.core.impl.ContextImpl.emit(ContextImpl.java:321)
	at io.vertx.core.impl.ContextInternal.emit(ContextInternal.java:209)
	at io.vertx.core.impl.VertxImpl$InternalTimerHandler.run(VertxImpl.java:1047)
	at io.netty.util.concurrent.PromiseTask.runTask(PromiseTask.java:98)
	at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:159)
	at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:173)
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:166)
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:470)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:569)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:1583)

@sishbi
Copy link
Author

sishbi commented Mar 23, 2024

For all of these additional stack traces, the pod had started 2 minutes prior - so this would be one of the first DNS lookups when connecting to the DB host

@tsegismont
Copy link
Contributor

Thanks for your reports @sishbi . A few questions:

  • Does the application reach a steady state eventually? Or is it constantly logging these warnings?
  • Can you confirm the applications runs using SecurityManager? In this case, can you test without the security manager?

I read in the bug report that you use K8S. Perhaps the combined cost of SecureClassLoader and reading class files from a container FS is the cause of problem.

@sishbi
Copy link
Author

sishbi commented Mar 23, 2024

Thanks for your reports @sishbi . A few questions:

  • Does the application reach a steady state eventually? Or is it constantly logging these warnings?

It only seems to report this just after container start. So I would say it reaches a steady state.

  • Can you confirm the applications runs using SecurityManager? In this case, can you test without the security manager?

I am not sure what you mean to test without a security manager. This is a deployed application bundled in a jar running in JDK 21.
How would we run it outside of a security manager?
As this is production I would rather not. But can try in a development environment. Please provide some instructions. If it is just a case of setting an environment variable then I can do that quickly and safely in a single environment.

I read in the bug report that you use K8S. Perhaps the combined cost of SecureClassLoader and reading class files from a container FS is the cause of problem.

I would guess that to be the case.
By the way, this application is packaged by gradle using their distribution bundle which is a tar ball containing a start script and a set of jar files. The start script lists all of the jars on the classpath. This is not a spring-boot style multi-jar or a maven shaded jar

Thanks again for the help and advice.
I am just reporting this to help improve vertx as I was not expecting internal vertx operations to be included in the blocking thread reports!

@sishbi
Copy link
Author

sishbi commented Mar 26, 2024

After another deployment, I see a blocked thread again - it was reported twice for the same thread, here are the 2 reports:

Thread Thread[vert.x-eventloop-thread-1,5,main] has been blocked for 3746 ms, time limit is 2000 ms

io.vertx.core.VertxException: Thread blocked
	at io.netty.resolver.InetSocketAddressResolver.doResolve(InetSocketAddressResolver.java:55)
	at io.netty.resolver.InetSocketAddressResolver.doResolve(InetSocketAddressResolver.java:31)
	at io.netty.resolver.AbstractAddressResolver.resolve(AbstractAddressResolver.java:106)
	at io.netty.bootstrap.Bootstrap.doResolveAndConnect0(Bootstrap.java:220)
	at io.netty.bootstrap.Bootstrap.doResolveAndConnect(Bootstrap.java:171)
	at io.netty.bootstrap.Bootstrap.connect(Bootstrap.java:148)
	at io.vertx.core.net.impl.ChannelProvider.handleConnect(ChannelProvider.java:152)
	at io.vertx.core.net.impl.ChannelProvider.connect(ChannelProvider.java:103)
	at io.vertx.core.net.impl.ChannelProvider.connect(ChannelProvider.java:89)
	at io.vertx.core.net.impl.NetClientImpl.connectInternal2(NetClientImpl.java:309)
	at io.vertx.core.net.impl.NetClientImpl.lambda$connectInternal$2(NetClientImpl.java:275)
	at io.vertx.core.impl.future.FutureImpl$4.onSuccess(FutureImpl.java:176)
	at io.vertx.core.impl.future.FutureBase.emitSuccess(FutureBase.java:66)
	at io.vertx.core.impl.future.FutureImpl.addListener(FutureImpl.java:231)
	at io.vertx.core.impl.future.FutureImpl.onComplete(FutureImpl.java:199)
	at io.vertx.core.net.impl.NetClientImpl.connectInternal(NetClientImpl.java:273)
	at io.vertx.core.net.impl.NetClientImpl.connect(NetClientImpl.java:230)
	at io.vertx.core.net.impl.NetClientImpl.connect(NetClientImpl.java:129)
	at io.vertx.core.net.impl.NetClientImpl.connect(NetClientImpl.java:124)
	at io.vertx.pgclient.impl.PgConnectionFactory.doConnect(PgConnectionFactory.java:137)
	at io.vertx.pgclient.impl.PgConnectionFactory.connect(PgConnectionFactory.java:118)
	at io.vertx.pgclient.impl.PgConnectionFactory.connect(PgConnectionFactory.java:98)
	at io.vertx.pgclient.impl.PgConnectionFactory.doConnectInternal(PgConnectionFactory.java:79)
	at io.vertx.sqlclient.impl.ConnectionFactoryBase.doConnectWithRetry(ConnectionFactoryBase.java:104)
	at io.vertx.sqlclient.impl.ConnectionFactoryBase.lambda$connect$0(ConnectionFactoryBase.java:88)
	at io.vertx.core.impl.ContextImpl.emit(ContextImpl.java:328)
	at io.vertx.core.impl.ContextImpl.emit(ContextImpl.java:321)
	at io.vertx.sqlclient.impl.ConnectionFactoryBase.connect(ConnectionFactoryBase.java:88)
	at io.vertx.pgclient.impl.PgConnectionFactory.connect(PgConnectionFactory.java:166)
	at io.vertx.sqlclient.spi.ConnectionFactory.lambda$connect$1(ConnectionFactory.java:26)
	at io.vertx.core.impl.future.Composition.onSuccess(Composition.java:38)
	at io.vertx.core.impl.future.FutureBase.lambda$emitSuccess$0(FutureBase.java:60)
	at io.vertx.core.impl.ContextImpl.execute(ContextImpl.java:298)
	at io.vertx.core.impl.ContextImpl.execute(ContextImpl.java:288)
	at io.vertx.core.impl.future.FutureBase.emitSuccess(FutureBase.java:57)
	at io.vertx.core.impl.future.FutureImpl.addListener(FutureImpl.java:231)
	at io.vertx.core.impl.future.FutureBase.compose(FutureBase.java:90)
	at io.vertx.core.impl.future.FutureImpl.compose(FutureImpl.java:28)
	at io.vertx.core.Future.compose(Future.java:375)
	at io.vertx.sqlclient.spi.ConnectionFactory.connect(ConnectionFactory.java:26)
	at io.vertx.sqlclient.impl.ConnectionFactoryBase.connect(ConnectionFactoryBase.java:94)
	at io.vertx.pgclient.spi.PgDriver.lambda$newPoolImpl$1(PgDriver.java:47)
	at io.vertx.sqlclient.impl.PoolImpl.lambda$new$0(PoolImpl.java:71)
	at io.vertx.sqlclient.impl.pool.SqlConnectionPool$2.connect(SqlConnectionPool.java:111)
	at io.vertx.core.net.impl.pool.SimpleConnectionPool.connect(SimpleConnectionPool.java:253)
	at io.vertx.core.net.impl.pool.SimpleConnectionPool$Acquire$3.run(SimpleConnectionPool.java:595)
	at io.vertx.core.net.impl.pool.Task.runNextTasks(Task.java:43)
	at io.vertx.core.net.impl.pool.CombinerExecutor.submit(CombinerExecutor.java:91)
	at io.vertx.core.net.impl.pool.SimpleConnectionPool.execute(SimpleConnectionPool.java:244)
	at io.vertx.core.net.impl.pool.SimpleConnectionPool.acquire(SimpleConnectionPool.java:639)
	at io.vertx.sqlclient.impl.pool.SqlConnectionPool.acquire(SqlConnectionPool.java:239)
	at io.vertx.sqlclient.impl.PoolImpl.acquire(PoolImpl.java:176)
	at io.vertx.sqlclient.impl.PoolImpl.getConnection(PoolImpl.java:139)
	at io.vertx.sqlclient.impl.PoolBase.getConnection(PoolBase.java:61)
	at com.kodypay.lychee.transactions.TransactionManager$Connection$Companion.transaction(transaction.kt:180)
	at com.kodypay.lychee.transactions.TransactionManager.begin(transaction.kt:47)
	at com.kodypay.lychee.transactions.TransactionManager.begin(transaction.kt:41)
	at com.kodypay.cards.tasks.TaskScheduler$monthly$1$1.invokeSuspend(TaskScheduler.kt:170)
	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
	at kotlinx.coroutines.internal.DispatchedContinuationKt.resumeCancellableWith(DispatchedContinuation.kt:363)
	at kotlinx.coroutines.intrinsics.CancellableKt.startCoroutineCancellable(Cancellable.kt:26)
	at kotlinx.coroutines.intrinsics.CancellableKt.startCoroutineCancellable$default(Cancellable.kt:21)
	at kotlinx.coroutines.CoroutineStart.invoke(CoroutineStart.kt:88)
	at kotlinx.coroutines.AbstractCoroutine.start(AbstractCoroutine.kt:123)
	at kotlinx.coroutines.BuildersKt__Builders_commonKt.launch(Builders.common.kt:52)
	at kotlinx.coroutines.BuildersKt.launch(Unknown Source)
	at kotlinx.coroutines.BuildersKt__Builders_commonKt.launch$default(Builders.common.kt:43)
	at kotlinx.coroutines.BuildersKt.launch$default(Unknown Source)
	at com.kodypay.cards.tasks.TaskScheduler.monthly$lambda$0(TaskScheduler.kt:76)
	at io.vertx.core.impl.VertxImpl$InternalTimerHandler.handle(VertxImpl.java:1053)
	at io.vertx.core.impl.VertxImpl$InternalTimerHandler.handle(VertxImpl.java:1029)
	at io.vertx.core.impl.ContextImpl.emit(ContextImpl.java:328)
	at io.vertx.core.impl.ContextImpl.emit(ContextImpl.java:321)
	at io.vertx.core.impl.ContextInternal.emit(ContextInternal.java:209)
	at io.vertx.core.impl.VertxImpl$InternalTimerHandler.run(VertxImpl.java:1047)
	at io.netty.util.concurrent.PromiseTask.runTask(PromiseTask.java:98)
	at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:159)
	at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:173)
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:166)
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:470)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:569)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:1583)

Thread Thread[vert.x-eventloop-thread-1,5,main] has been blocked for 2745 ms, time limit is 2000 ms

io.vertx.core.VertxException: Thread blocked
	at java.base/java.lang.ClassLoader.defineClass1(Native Method)
	at java.base/java.lang.ClassLoader.defineClass(ClassLoader.java:1027)
	at java.base/java.security.SecureClassLoader.defineClass(SecureClassLoader.java:150)
	at java.base/jdk.internal.loader.BuiltinClassLoader.defineClass(BuiltinClassLoader.java:862)
	at java.base/jdk.internal.loader.BuiltinClassLoader.findClassOnClassPathOrNull(BuiltinClassLoader.java:760)
	at java.base/jdk.internal.loader.BuiltinClassLoader.loadClassOrNull(BuiltinClassLoader.java:681)
	at java.base/jdk.internal.loader.BuiltinClassLoader.loadClass(BuiltinClassLoader.java:639)
	at java.base/jdk.internal.loader.ClassLoaders$AppClassLoader.loadClass(ClassLoaders.java:188)
	at java.base/java.lang.ClassLoader.loadClass(ClassLoader.java:526)
	at io.netty.resolver.dns.NoopDnsQueryLifecycleObserverFactory.newDnsQueryLifecycleObserver(NoopDnsQueryLifecycleObserverFactory.java:28)
	at io.netty.resolver.dns.DnsResolveContext.newDnsQueryLifecycleObserver(DnsResolveContext.java:1196)
	at io.netty.resolver.dns.DnsResolveContext.query(DnsResolveContext.java:1191)
	at io.netty.resolver.dns.DnsResolveContext.internalResolve(DnsResolveContext.java:384)
	at io.netty.resolver.dns.DnsResolveContext.doSearchDomainQuery(DnsResolveContext.java:310)
	at io.netty.resolver.dns.DnsAddressResolveContext.doSearchDomainQuery(DnsAddressResolveContext.java:100)
	at io.netty.resolver.dns.DnsResolveContext.resolve(DnsResolveContext.java:272)
	at io.netty.resolver.dns.DnsNameResolver.resolveNow(DnsNameResolver.java:1220)
	at io.netty.resolver.dns.DnsNameResolver.doResolveAllUncached0(DnsNameResolver.java:1206)
	at io.netty.resolver.dns.DnsNameResolver.doResolveAllUncached(DnsNameResolver.java:1148)
	at io.netty.resolver.dns.DnsNameResolver.doResolveUncached(DnsNameResolver.java:1050)
	at io.netty.resolver.dns.DnsNameResolver.doResolve(DnsNameResolver.java:992)
	at io.netty.resolver.dns.DnsNameResolver.doResolve(DnsNameResolver.java:824)
	at io.netty.resolver.SimpleNameResolver.resolve(SimpleNameResolver.java:61)
	at io.netty.resolver.dns.InflightNameResolver.resolve(InflightNameResolver.java:100)
	at io.netty.resolver.dns.InflightNameResolver.resolve(InflightNameResolver.java:66)
	at io.netty.resolver.dns.InflightNameResolver.resolve(InflightNameResolver.java:51)
	at io.netty.resolver.InetSocketAddressResolver.doResolve(InetSocketAddressResolver.java:55)
	at io.netty.resolver.InetSocketAddressResolver.doResolve(InetSocketAddressResolver.java:31)
	at io.netty.resolver.AbstractAddressResolver.resolve(AbstractAddressResolver.java:106)
	at io.netty.bootstrap.Bootstrap.doResolveAndConnect0(Bootstrap.java:220)
	at io.netty.bootstrap.Bootstrap.doResolveAndConnect(Bootstrap.java:171)
	at io.netty.bootstrap.Bootstrap.connect(Bootstrap.java:148)
	at io.vertx.core.net.impl.ChannelProvider.handleConnect(ChannelProvider.java:152)
	at io.vertx.core.net.impl.ChannelProvider.connect(ChannelProvider.java:103)
	at io.vertx.core.net.impl.ChannelProvider.connect(ChannelProvider.java:89)
	at io.vertx.core.net.impl.NetClientImpl.connectInternal2(NetClientImpl.java:309)
	at io.vertx.core.net.impl.NetClientImpl.lambda$connectInternal$2(NetClientImpl.java:275)
	at io.vertx.core.impl.future.FutureImpl$4.onSuccess(FutureImpl.java:176)
	at io.vertx.core.impl.future.FutureBase.emitSuccess(FutureBase.java:66)
	at io.vertx.core.impl.future.FutureImpl.addListener(FutureImpl.java:231)
	at io.vertx.core.impl.future.FutureImpl.onComplete(FutureImpl.java:199)
	at io.vertx.core.net.impl.NetClientImpl.connectInternal(NetClientImpl.java:273)
	at io.vertx.core.net.impl.NetClientImpl.connect(NetClientImpl.java:230)
	at io.vertx.core.net.impl.NetClientImpl.connect(NetClientImpl.java:129)
	at io.vertx.core.net.impl.NetClientImpl.connect(NetClientImpl.java:124)
	at io.vertx.pgclient.impl.PgConnectionFactory.doConnect(PgConnectionFactory.java:137)
	at io.vertx.pgclient.impl.PgConnectionFactory.connect(PgConnectionFactory.java:118)
	at io.vertx.pgclient.impl.PgConnectionFactory.connect(PgConnectionFactory.java:98)
	at io.vertx.pgclient.impl.PgConnectionFactory.doConnectInternal(PgConnectionFactory.java:79)
	at io.vertx.sqlclient.impl.ConnectionFactoryBase.doConnectWithRetry(ConnectionFactoryBase.java:104)
	at io.vertx.sqlclient.impl.ConnectionFactoryBase.lambda$connect$0(ConnectionFactoryBase.java:88)
	at io.vertx.core.impl.ContextImpl.emit(ContextImpl.java:328)
	at io.vertx.core.impl.ContextImpl.emit(ContextImpl.java:321)
	at io.vertx.sqlclient.impl.ConnectionFactoryBase.connect(ConnectionFactoryBase.java:88)
	at io.vertx.pgclient.impl.PgConnectionFactory.connect(PgConnectionFactory.java:166)
	at io.vertx.sqlclient.spi.ConnectionFactory.lambda$connect$1(ConnectionFactory.java:26)
	at io.vertx.core.impl.future.Composition.onSuccess(Composition.java:38)
	at io.vertx.core.impl.future.FutureBase.lambda$emitSuccess$0(FutureBase.java:60)
	at io.vertx.core.impl.ContextImpl.execute(ContextImpl.java:298)
	at io.vertx.core.impl.ContextImpl.execute(ContextImpl.java:288)
	at io.vertx.core.impl.future.FutureBase.emitSuccess(FutureBase.java:57)
	at io.vertx.core.impl.future.FutureImpl.addListener(FutureImpl.java:231)
	at io.vertx.core.impl.future.FutureBase.compose(FutureBase.java:90)
	at io.vertx.core.impl.future.FutureImpl.compose(FutureImpl.java:28)
	at io.vertx.core.Future.compose(Future.java:375)
	at io.vertx.sqlclient.spi.ConnectionFactory.connect(ConnectionFactory.java:26)
	at io.vertx.sqlclient.impl.ConnectionFactoryBase.connect(ConnectionFactoryBase.java:94)
	at io.vertx.pgclient.spi.PgDriver.lambda$newPoolImpl$1(PgDriver.java:47)
	at io.vertx.sqlclient.impl.PoolImpl.lambda$new$0(PoolImpl.java:71)
	at io.vertx.sqlclient.impl.pool.SqlConnectionPool$2.connect(SqlConnectionPool.java:111)
	at io.vertx.core.net.impl.pool.SimpleConnectionPool.connect(SimpleConnectionPool.java:253)
	at io.vertx.core.net.impl.pool.SimpleConnectionPool$Acquire$3.run(SimpleConnectionPool.java:595)
	at io.vertx.core.net.impl.pool.Task.runNextTasks(Task.java:43)
	at io.vertx.core.net.impl.pool.CombinerExecutor.submit(CombinerExecutor.java:91)
	at io.vertx.core.net.impl.pool.SimpleConnectionPool.execute(SimpleConnectionPool.java:244)
	at io.vertx.core.net.impl.pool.SimpleConnectionPool.acquire(SimpleConnectionPool.java:639)
	at io.vertx.sqlclient.impl.pool.SqlConnectionPool.acquire(SqlConnectionPool.java:239)
	at io.vertx.sqlclient.impl.PoolImpl.acquire(PoolImpl.java:176)
	at io.vertx.sqlclient.impl.PoolImpl.getConnection(PoolImpl.java:139)
	at io.vertx.sqlclient.impl.PoolBase.getConnection(PoolBase.java:61)
	at com.kodypay.lychee.transactions.TransactionManager$Connection$Companion.transaction(transaction.kt:180)
	at com.kodypay.lychee.transactions.TransactionManager.begin(transaction.kt:47)
	at com.kodypay.lychee.transactions.TransactionManager.begin(transaction.kt:41)
	at com.kodypay.cards.tasks.TaskScheduler$monthly$1$1.invokeSuspend(TaskScheduler.kt:170)
	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33)
	at kotlinx.coroutines.internal.DispatchedContinuationKt.resumeCancellableWith(DispatchedContinuation.kt:363)
	at kotlinx.coroutines.intrinsics.CancellableKt.startCoroutineCancellable(Cancellable.kt:26)
	at kotlinx.coroutines.intrinsics.CancellableKt.startCoroutineCancellable$default(Cancellable.kt:21)
	at kotlinx.coroutines.CoroutineStart.invoke(CoroutineStart.kt:88)
	at kotlinx.coroutines.AbstractCoroutine.start(AbstractCoroutine.kt:123)
	at kotlinx.coroutines.BuildersKt__Builders_commonKt.launch(Builders.common.kt:52)
	at kotlinx.coroutines.BuildersKt.launch(Unknown Source)
	at kotlinx.coroutines.BuildersKt__Builders_commonKt.launch$default(Builders.common.kt:43)
	at kotlinx.coroutines.BuildersKt.launch$default(Unknown Source)
	at com.kodypay.cards.tasks.TaskScheduler.monthly$lambda$0(TaskScheduler.kt:76)
	at io.vertx.core.impl.VertxImpl$InternalTimerHandler.handle(VertxImpl.java:1053)
	at io.vertx.core.impl.VertxImpl$InternalTimerHandler.handle(VertxImpl.java:1029)
	at io.vertx.core.impl.ContextImpl.emit(ContextImpl.java:328)
	at io.vertx.core.impl.ContextImpl.emit(ContextImpl.java:321)
	at io.vertx.core.impl.ContextInternal.emit(ContextInternal.java:209)
	at io.vertx.core.impl.VertxImpl$InternalTimerHandler.run(VertxImpl.java:1047)
	at io.netty.util.concurrent.PromiseTask.runTask(PromiseTask.java:98)
	at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:159)
	at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:173)
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:166)
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:470)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:569)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:1583)

@vietj
Copy link
Member

vietj commented Mar 26, 2024

it is not clear why this is happening, what is the activity done with the PG pool when this happen ?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

3 participants