search

Hyperfoil / Horreum

Benchmark results repository service
https://horreum.hyperfoil.io/
Apache License 2.0
33 stars 30 forks source link

Worker pool threads blocked #655

Open johnaohara opened 10 months ago

johnaohara commented 10 months ago

The vert.x io.ver.cor.imp.BlockedThreadChecker is reporting worker threads blocked;

2023-09-18 13:59:29,033 WARN  [io.ver.cor.imp.BlockedThreadChecker] (vertx-blocked-thread-checker) Thread Thread[vert.x-worker-thread-2,5,build group] has been blocked for 329912 ms, time limit is 60000 ms: io.vertx.core.VertxException: Thread blocked
    at org.hibernate.persister.entity.AbstractEntityPersister.getPropertyValue(AbstractEntityPersister.java:4237)
    at org.hibernate.persister.entity.EntityPersister.getValue(EntityPersister.java:920)
    at org.hibernate.engine.internal.Cascade.cascade(Cascade.java:184)
    at org.hibernate.event.internal.AbstractFlushingEventListener.cascadeOnFlush(AbstractFlushingEventListener.java:155)
    at org.hibernate.event.internal.AbstractFlushingEventListener.prepareEntityFlushes(AbstractFlushingEventListener.java:145)
    at org.hibernate.event.internal.AbstractFlushingEventListener.flushEverythingToExecutions(AbstractFlushingEventListener.java:79)
    at org.hibernate.event.internal.DefaultAutoFlushEventListener.onAutoFlush(DefaultAutoFlushEventListener.java:48)
    at org.hibernate.internal.SessionImpl$$Lambda$3128/0x00007fe45137d328.accept(Unknown Source)
    at org.hibernate.event.service.internal.EventListenerGroupImpl.fireEventOnEachListener(EventListenerGroupImpl.java:127)
    at org.hibernate.internal.SessionImpl.autoFlushIfRequired(SessionImpl.java:1375)
    at org.hibernate.query.sqm.internal.ConcreteSqmSelectQueryPlan.lambda$new$0(ConcreteSqmSelectQueryPlan.java:108)
    at org.hibernate.query.sqm.internal.ConcreteSqmSelectQueryPlan$$Lambda$3248/0x00007fe451465e48.interpret(Unknown Source)
    at org.hibernate.query.sqm.internal.ConcreteSqmSelectQueryPlan.withCacheableSqmInterpretation(ConcreteSqmSelectQueryPlan.java:303)
    at org.hibernate.query.sqm.internal.ConcreteSqmSelectQueryPlan.performList(ConcreteSqmSelectQueryPlan.java:244)
    at org.hibernate.query.sqm.internal.QuerySqmImpl.doList(QuerySqmImpl.java:518)
    at org.hibernate.query.spi.AbstractSelectionQuery.list(AbstractSelectionQuery.java:367)
    at org.hibernate.query.Query.getResultList(Query.java:119)
    at io.quarkus.hibernate.orm.panache.common.runtime.CommonPanacheQueryImpl.list(CommonPanacheQueryImpl.java:280)
    at io.quarkus.hibernate.orm.panache.runtime.PanacheQueryImpl.list(PanacheQueryImpl.java:149)
    at io.hyperfoil.tools.horreum.svc.AlertingServiceImpl.runChangeDetection(AlertingServiceImpl.java:640)
    at io.hyperfoil.tools.horreum.svc.AlertingServiceImpl.onNewDataPoint(AlertingServiceImpl.java:555)
    at io.hyperfoil.tools.horreum.svc.AlertingServiceImpl_Subclass.onNewDataPoint$$superforward(Unknown Source)
    at io.hyperfoil.tools.horreum.svc.AlertingServiceImpl_Subclass$$function$$48.apply(Unknown Source)
    at io.quarkus.arc.impl.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:73)
    at io.quarkus.arc.impl.AroundInvokeInvocationContext$NextAroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:97)
    at io.hyperfoil.tools.horreum.server.RolesInterceptor.intercept(RolesInterceptor.java:70)
    at io.hyperfoil.tools.horreum.server.RolesInterceptor_Bean.intercept(Unknown Source)
    at io.quarkus.arc.impl.InterceptorInvocation.invoke(InterceptorInvocation.java:42)
    at io.quarkus.arc.impl.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:70)
    at io.quarkus.arc.impl.AroundInvokeInvocationContext$NextAroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:97)
    at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:136)
    at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:107)
    at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequired.doIntercept(TransactionalInterceptorRequired.java:38)
    at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.intercept(TransactionalInterceptorBase.java:61)
    at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequired.intercept(TransactionalInterceptorRequired.java:32)
    at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequired_Bean.intercept(Unknown Source)
    at io.quarkus.arc.impl.InterceptorInvocation.invoke(InterceptorInvocation.java:42)
    at io.quarkus.arc.impl.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:70)
    at io.quarkus.arc.impl.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:62)
    at io.hyperfoil.tools.horreum.server.BaseTransactionRetryInterceptor.intercept(BaseTransactionRetryInterceptor.java:29)
    at io.hyperfoil.tools.horreum.server.BaseTransactionRetryInterceptor_RequiredTransactionRetryInterceptor_Bean.intercept(Unknown Source)
    at io.quarkus.arc.impl.InterceptorInvocation.invoke(InterceptorInvocation.java:42)
    at io.quarkus.arc.impl.AroundInvokeInvocationContext.perform(AroundInvokeInvocationContext.java:30)
    at io.quarkus.arc.impl.InvocationContexts.performAroundInvoke(InvocationContexts.java:27)
    at io.hyperfoil.tools.horreum.svc.AlertingServiceImpl_Subclass.onNewDataPoint(Unknown Source)
    at io.hyperfoil.tools.horreum.svc.AlertingServiceImpl$$Lambda$3200/0x00007fe4513c27d0.handle(Unknown Source)
    at io.hyperfoil.tools.horreum.bus.MessageBus.lambda$subscribe$3(MessageBus.java:157)
    at io.hyperfoil.tools.horreum.bus.MessageBus$$Lambda$3741/0x00007fe4517c4898.run(Unknown Source)
    at io.smallrye.context.impl.wrappers.SlowContextualRunnable.run(SlowContextualRunnable.java:19)
    at io.hyperfoil.tools.horreum.svc.Util.lambda$wrapForBlockingExecution$3(Util.java:496)
    at io.hyperfoil.tools.horreum.svc.Util$$Lambda$3735/0x00007fe4517c4228.run(Unknown Source)
    at io.hyperfoil.tools.horreum.bus.TaskQueue.executeOrAdd(TaskQueue.java:27)
    at io.hyperfoil.tools.horreum.bus.MessageBus.lambda$executeForTest$9(MessageBus.java:295)
    at io.hyperfoil.tools.horreum.bus.MessageBus$$Lambda$3743/0x00007fe4517c4d18.handle(Unknown Source)
    at io.vertx.core.impl.ContextBase.lambda$executeBlocking$1(ContextBase.java:180)
    at io.vertx.core.impl.ContextBase$$Lambda$3226/0x00007fe4513d8800.handle(Unknown Source)
    at io.vertx.core.impl.ContextInternal.dispatch(ContextInternal.java:277)
    at io.vertx.core.impl.ContextBase.lambda$internalExecuteBlocking$2(ContextBase.java:199)
    at io.vertx.core.impl.ContextBase$$Lambda$3227/0x00007fe4513d8c28.run(Unknown Source)
    at io.vertx.core.impl.TaskQueue.run(TaskQueue.java:76)
    at io.vertx.core.impl.TaskQueue$$Lambda$2534/0x00007fe450dd8d28.run(Unknown Source)
    at org.jboss.threads.ContextHandler$1.runWith(ContextHandler.java:18)
    at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2513)
    at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1538)
    at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)
    at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)
    at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
    at java.base@17.0.8/java.lang.Thread.run(Thread.java:833)

Stack trace of stuck thread:

"vert.x-worker-thread-2" #339 prio=5 os_prio=0 cpu=135792.24ms elapsed=1510.73s tid=0x00007fe1c832e5b0 nid=0x21fbf runnable  [0x00007fe2a4df1000]
   java.lang.Thread.State: RUNNABLE
    at sun.nio.ch.Net.poll(java.base@17.0.8/Native Method)
    at sun.nio.ch.NioSocketImpl.park(java.base@17.0.8/NioSocketImpl.java:186)
    at sun.nio.ch.NioSocketImpl.park(java.base@17.0.8/NioSocketImpl.java:195)
    at sun.nio.ch.NioSocketImpl.implRead(java.base@17.0.8/NioSocketImpl.java:319)
    at sun.nio.ch.NioSocketImpl.read(java.base@17.0.8/NioSocketImpl.java:355)
    at sun.nio.ch.NioSocketImpl$1.read(java.base@17.0.8/NioSocketImpl.java:808)
    at java.net.Socket$SocketInputStream.read(java.base@17.0.8/Socket.java:966)
    at org.postgresql.core.VisibleBufferedInputStream.readMore(VisibleBufferedInputStream.java:161)
    at org.postgresql.core.VisibleBufferedInputStream.ensureBytes(VisibleBufferedInputStream.java:128)
    at org.postgresql.core.VisibleBufferedInputStream.ensureBytes(VisibleBufferedInputStream.java:113)
    at org.postgresql.core.VisibleBufferedInputStream.read(VisibleBufferedInputStream.java:73)
    at org.postgresql.core.PGStream.receiveChar(PGStream.java:465)
    at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2155)
    at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:368)
    at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:498)
    at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:415)
    at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:190)
    at org.postgresql.jdbc.PgPreparedStatement.executeQuery(PgPreparedStatement.java:134)
    at io.agroal.pool.wrapper.PreparedStatementWrapper.executeQuery(PreparedStatementWrapper.java:78)
    at org.hibernate.sql.results.jdbc.internal.DeferredResultSetAccess.executeQuery(DeferredResultSetAccess.java:239)
    at org.hibernate.sql.results.jdbc.internal.DeferredResultSetAccess.getResultSet(DeferredResultSetAccess.java:163)
    at org.hibernate.sql.results.jdbc.internal.AbstractResultSetAccess.getMetaData(AbstractResultSetAccess.java:36)
    at org.hibernate.sql.results.jdbc.internal.AbstractResultSetAccess.getColumnCount(AbstractResultSetAccess.java:52)
    at org.hibernate.query.results.ResultSetMappingImpl.resolve(ResultSetMappingImpl.java:193)
    at org.hibernate.sql.exec.internal.JdbcSelectExecutorStandardImpl.resolveJdbcValuesSource(JdbcSelectExecutorStandardImpl.java:477)
    at org.hibernate.sql.exec.internal.JdbcSelectExecutorStandardImpl.doExecuteQuery(JdbcSelectExecutorStandardImpl.java:267)
    at org.hibernate.sql.exec.internal.JdbcSelectExecutorStandardImpl.executeQueryScroll(JdbcSelectExecutorStandardImpl.java:193)
    at org.hibernate.sql.exec.internal.JdbcSelectExecutorStandardImpl.scroll(JdbcSelectExecutorStandardImpl.java:116)
    at org.hibernate.query.sql.internal.NativeSelectQueryPlanImpl.performScroll(NativeSelectQueryPlanImpl.java:139)
    at org.hibernate.query.sql.internal.NativeQueryImpl.doScroll(NativeQueryImpl.java:830)
    at org.hibernate.query.spi.AbstractSelectionQuery.scroll(AbstractSelectionQuery.java:445)
    at org.hibernate.query.spi.AbstractSelectionQuery.stream(AbstractSelectionQuery.java:457)
    at org.hibernate.query.Query.getResultStream(Query.java:168)
    at io.hyperfoil.tools.horreum.svc.AlertingServiceImpl.runChangeDetection(AlertingServiceImpl.java:582)
    at io.hyperfoil.tools.horreum.svc.AlertingServiceImpl.onNewDataPoint(AlertingServiceImpl.java:555)
    at io.hyperfoil.tools.horreum.svc.AlertingServiceImpl_Subclass.onNewDataPoint$$superforward(Unknown Source)
    at io.hyperfoil.tools.horreum.svc.AlertingServiceImpl_Subclass$$function$$48.apply(Unknown Source)
    at io.quarkus.arc.impl.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:73)
    at io.quarkus.arc.impl.AroundInvokeInvocationContext$NextAroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:97)
    at io.hyperfoil.tools.horreum.server.RolesInterceptor.intercept(RolesInterceptor.java:70)
    at io.hyperfoil.tools.horreum.server.RolesInterceptor_Bean.intercept(Unknown Source)
    at io.quarkus.arc.impl.InterceptorInvocation.invoke(InterceptorInvocation.java:42)
    at io.quarkus.arc.impl.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:70)
    at io.quarkus.arc.impl.AroundInvokeInvocationContext$NextAroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:97)
    at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:136)
    at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:107)
    at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequired.doIntercept(TransactionalInterceptorRequired.java:38)
    at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.intercept(TransactionalInterceptorBase.java:61)
    at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequired.intercept(TransactionalInterceptorRequired.java:32)
    at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequired_Bean.intercept(Unknown Source)
    at io.quarkus.arc.impl.InterceptorInvocation.invoke(InterceptorInvocation.java:42)
    at io.quarkus.arc.impl.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:70)
    at io.quarkus.arc.impl.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:62)
    at io.hyperfoil.tools.horreum.server.BaseTransactionRetryInterceptor.intercept(BaseTransactionRetryInterceptor.java:29)
    at io.hyperfoil.tools.horreum.server.BaseTransactionRetryInterceptor_RequiredTransactionRetryInterceptor_Bean.intercept(Unknown Source)
    at io.quarkus.arc.impl.InterceptorInvocation.invoke(InterceptorInvocation.java:42)
    at io.quarkus.arc.impl.AroundInvokeInvocationContext.perform(AroundInvokeInvocationContext.java:30)
    at io.quarkus.arc.impl.InvocationContexts.performAroundInvoke(InvocationContexts.java:27)
    at io.hyperfoil.tools.horreum.svc.AlertingServiceImpl_Subclass.onNewDataPoint(Unknown Source)
    at io.hyperfoil.tools.horreum.svc.AlertingServiceImpl$$Lambda$3200/0x00007fe4513c27d0.handle(Unknown Source)
    at io.hyperfoil.tools.horreum.bus.MessageBus.lambda$subscribe$3(MessageBus.java:157)
    at io.hyperfoil.tools.horreum.bus.MessageBus$$Lambda$3741/0x00007fe4517c4898.run(Unknown Source)
    at io.smallrye.context.impl.wrappers.SlowContextualRunnable.run(SlowContextualRunnable.java:19)
    at io.hyperfoil.tools.horreum.svc.Util.lambda$wrapForBlockingExecution$3(Util.java:496)
    at io.hyperfoil.tools.horreum.svc.Util$$Lambda$3735/0x00007fe4517c4228.run(Unknown Source)
    at io.hyperfoil.tools.horreum.bus.TaskQueue.executeOrAdd(TaskQueue.java:27)
    at io.hyperfoil.tools.horreum.bus.MessageBus.lambda$executeForTest$9(MessageBus.java:295)
    at io.hyperfoil.tools.horreum.bus.MessageBus$$Lambda$3743/0x00007fe4517c4d18.handle(Unknown Source)
    at io.vertx.core.impl.ContextBase.lambda$executeBlocking$1(ContextBase.java:180)
    at io.vertx.core.impl.ContextBase$$Lambda$3226/0x00007fe4513d8800.handle(Unknown Source)
    at io.vertx.core.impl.ContextInternal.dispatch(ContextInternal.java:277)
    at io.vertx.core.impl.ContextBase.lambda$internalExecuteBlocking$2(ContextBase.java:199)
    at io.vertx.core.impl.ContextBase$$Lambda$3227/0x00007fe4513d8c28.run(Unknown Source)
    at io.vertx.core.impl.TaskQueue.run(TaskQueue.java:76)
    at io.vertx.core.impl.TaskQueue$$Lambda$2534/0x00007fe450dd8d28.run(Unknown Source)
    at org.jboss.threads.ContextHandler$1.runWith(ContextHandler.java:18)
    at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2513)
    at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1538)
    at org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)
    at org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)
    at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
    at java.lang.Thread.run(java.base@17.0.8/Thread.java:833)
johnaohara commented 10 months ago

This might be caused by re-calculating a large dataset in the backgroud