eclipse-vertx / vertx-sql-client

High performance reactive SQL Client written in Java
Apache License 2.0
891 stars 199 forks source link

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

Open sishbi opened 6 months ago

sishbi commented 6 months ago

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)

vietj commented 6 months ago

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

sishbi commented 6 months ago

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 commented 6 months ago

does it always happen with the same stack trace ?

sishbi commented 6 months ago

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 commented 6 months ago

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 commented 6 months ago

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 commented 6 months ago

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 commented 6 months ago

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 commented 6 months ago

Thanks for your reports @sishbi . A few questions:

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 commented 6 months ago

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 commented 6 months ago

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 commented 6 months ago

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