cryostatio / cryostat

Other
6 stars 8 forks source link

[Bug] `org.hibernate.exception.GenericJDBCException: Unable to acquire JDBC Connection` #467

Open andrewazores opened 1 month ago

andrewazores commented 1 month ago

Current Behavior

Cryostat becomes unable to open a (pooled) JDBC connection to its Postgres database. It continues responding to healthchecks but most API queries become unusable because the database connection cannot be established.

Related: https://github.com/cryostatio/cryostat3/pull/415 https://github.com/cryostatio/cryostat3/pull/428 https://github.com/cryostatio/cryostat3/pull/325

Expected Behavior

No response

Steps To Reproduce

  1. Deploy using the Operator on OpenShift
  2. Deploy some sample applications. I used the Operator make sample_app scaled up to 2 replicas, and make sample_app_agent on this PR: https://github.com/cryostatio/cryostat-operator/pull/823
  3. Wait some time. This exception will start to occur on its own with no further user interaction

Environment

No response

Anything else?

Seems related to/same as https://github.com/quarkusio/quarkus/issues/9123


2024-05-16 15:22:00,831 WARN  [org.hib.eng.jdb.spi.SqlExceptionHelper] (executor-thread-48) SQL Error: 0, SQLState: null
2024-05-16 15:22:00,831 ERROR [org.hib.eng.jdb.spi.SqlExceptionHelper] (executor-thread-48) Sorry, acquisition timeout!
2024-05-16 15:22:00,831 ERROR [io.fab.kub.cli.inf.imp.cac.SharedProcessor] (executor-thread-48) v1/namespaces/cryostat3/endpoints failed invoking io.cryostat.discovery.KubeApiDiscovery$EndpointsHandler@1043c8be event handler: Unable to acquire JDBC Connection [Sorry, acquisition timeout!] [n/a]: org.hibernate.exception.GenericJDBCException: Unable to acquire JDBC Connection [Sorry, acquisition timeout!] [n/a]
    at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:61)
    at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:108)
    at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:94)
    at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:116)
    at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:143)
    at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.connection(StatementPreparerImpl.java:51)
    at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$5.doPrepare(StatementPreparerImpl.java:150)
    at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:177)
    at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.prepareQueryStatement(StatementPreparerImpl.java:152)
    at org.hibernate.sql.exec.internal.JdbcSelectExecutorStandardImpl.lambda$list$0(JdbcSelectExecutorStandardImpl.java:102)
    at org.hibernate.sql.results.jdbc.internal.DeferredResultSetAccess.executeQuery(DeferredResultSetAccess.java:226)
    at org.hibernate.sql.results.jdbc.internal.DeferredResultSetAccess.getResultSet(DeferredResultSetAccess.java:163)
    at org.hibernate.sql.results.jdbc.internal.JdbcValuesResultSetImpl.advanceNext(JdbcValuesResultSetImpl.java:254)
    at org.hibernate.sql.results.jdbc.internal.JdbcValuesResultSetImpl.processNext(JdbcValuesResultSetImpl.java:134)
    at org.hibernate.sql.results.jdbc.internal.AbstractJdbcValues.next(AbstractJdbcValues.java:19)
    at org.hibernate.sql.results.internal.RowProcessingStateStandardImpl.next(RowProcessingStateStandardImpl.java:66)
    at org.hibernate.sql.results.spi.ListResultsConsumer.consume(ListResultsConsumer.java:198)
    at org.hibernate.sql.results.spi.ListResultsConsumer.consume(ListResultsConsumer.java:33)
    at org.hibernate.sql.exec.internal.JdbcSelectExecutorStandardImpl.doExecuteQuery(JdbcSelectExecutorStandardImpl.java:361)
    at org.hibernate.sql.exec.internal.JdbcSelectExecutorStandardImpl.executeQuery(JdbcSelectExecutorStandardImpl.java:168)
    at org.hibernate.sql.exec.internal.JdbcSelectExecutorStandardImpl.list(JdbcSelectExecutorStandardImpl.java:93)
    at org.hibernate.sql.exec.spi.JdbcSelectExecutor.list(JdbcSelectExecutor.java:31)
    at org.hibernate.query.sqm.internal.ConcreteSqmSelectQueryPlan.lambda$new$0(ConcreteSqmSelectQueryPlan.java:110)
    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.cryostat.discovery.DiscoveryNode.findAllByNodeType(DiscoveryNode.java:130)
    at io.cryostat.discovery.KubeApiDiscovery.handleObservedEndpoints(KubeApiDiscovery.java:289)
    at io.cryostat.discovery.KubeApiDiscovery$EndpointsHandler.lambda$onUpdate$1(KubeApiDiscovery.java:573)
    at io.quarkus.narayana.jta.TransactionRunnerImpl.lambda$run$0(TransactionRunnerImpl.java:27)
    at io.quarkus.narayana.jta.QuarkusTransactionImpl.callInOurTx(QuarkusTransactionImpl.java:136)
    at io.quarkus.narayana.jta.QuarkusTransactionImpl.callJoinExisting(QuarkusTransactionImpl.java:79)
    at io.quarkus.narayana.jta.QuarkusTransactionImpl.call(QuarkusTransactionImpl.java:33)
    at io.quarkus.narayana.jta.TransactionRunnerImpl.run(TransactionRunnerImpl.java:26)
    at io.cryostat.discovery.KubeApiDiscovery$EndpointsHandler.onUpdate(KubeApiDiscovery.java:573)
    at io.cryostat.discovery.KubeApiDiscovery$EndpointsHandler.onUpdate(KubeApiDiscovery.java:556)
    at io.fabric8.kubernetes.client.informers.impl.cache.ProcessorListener$UpdateNotification.handle(ProcessorListener.java:92)
    at io.fabric8.kubernetes.client.informers.impl.cache.ProcessorListener.add(ProcessorListener.java:50)
    at io.fabric8.kubernetes.client.informers.impl.cache.SharedProcessor.lambda$distribute$0(SharedProcessor.java:91)
    at io.fabric8.kubernetes.client.informers.impl.cache.SharedProcessor.lambda$distribute$1(SharedProcessor.java:114)
    at io.fabric8.kubernetes.client.utils.internal.SerialExecutor.lambda$execute$0(SerialExecutor.java:58)
    at io.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:581)
    at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2513)
    at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1512)
    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/java.lang.Thread.run(Thread.java:840)
Caused by: java.sql.SQLException: Sorry, acquisition timeout!
    at io.agroal.pool.ConnectionPool.handlerFromSharedCache(ConnectionPool.java:294)
    at io.agroal.pool.ConnectionPool.getConnection(ConnectionPool.java:249)
    at io.agroal.pool.DataSource.getConnection(DataSource.java:86)
    at io.quarkus.hibernate.orm.runtime.customized.QuarkusConnectionProvider.getConnection(QuarkusConnectionProvider.java:23)
    at org.hibernate.internal.NonContextualJdbcConnectionAccess.obtainConnection(NonContextualJdbcConnectionAccess.java:38)
    at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:113)
    ... 48 more
andrewazores commented 1 month ago

Example of trying to create a custom target after the server gets into this state:

2024-05-16 15:30:04,035 ERROR [io.qua.ver.htt.run.QuarkusErrorHandler] (executor-thread-11) HTTP Request to /api/v2/targets?storeCredentials=true&dryrun=false failed, error id: a433ec31-df40-4325-8d8f-4b403d5eb450-243: java.lang.RuntimeException: ARJUNA016108: Wrong transaction on thread
    at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.endTransaction(TransactionalInterceptorBase.java:400)
    at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:171)
    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.perform(AroundInvokeInvocationContext.java:30)
    at io.quarkus.arc.impl.InvocationContexts.performAroundInvoke(InvocationContexts.java:27)
    at io.cryostat.discovery.CustomDiscovery_Subclass.create(Unknown Source)
    at io.cryostat.discovery.CustomDiscovery_ClientProxy.create(Unknown Source)
    at io.cryostat.discovery.CustomDiscovery$quarkusrestinvoker$create_a2d4a2d205177c85e611b9c0327c35c9085f99d5.invoke(Unknown Source)
    at org.jboss.resteasy.reactive.server.handlers.InvocationHandler.handle(InvocationHandler.java:29)
    at io.quarkus.resteasy.reactive.server.runtime.QuarkusResteasyReactiveRequestContext.invokeHandler(QuarkusResteasyReactiveRequestContext.java:141)
    at org.jboss.resteasy.reactive.common.core.AbstractResteasyReactiveContext.run(AbstractResteasyReactiveContext.java:145)
    at io.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:576)
    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/java.lang.Thread.run(Thread.java:840)
andrewazores commented 1 month ago

oc rollout restart deployment <deployment_name> works as a manual workaround, but the problem will re-occur after some time.

andrewazores commented 1 month ago

This stack trace appears shortly after make sample_app_agent:

2024-05-16 15:41:50,170 INFO  [io.cry.tar.Target$Listener] (executor-thread-3) io.smallrye.mutiny.TimeoutException
2024-05-16 15:41:50,214 WARN  [com.arj.ats.arjuna] (executor-thread-3) ARJUNA012094: Commit of action id 0:ffff0a80002a:8e1d:664628f2:4a invoked while multiple threads active within it.
2024-05-16 15:41:50,214 WARN  [com.arj.ats.arjuna] (executor-thread-3) ARJUNA012107: CheckedAction::check - atomic action 0:ffff0a80002a:8e1d:664628f2:4a commiting with 2 threads active!
2024-05-16 15:41:50,216 WARN  [com.arj.ats.jta] (executor-thread-3) ARJUNA016039: onePhaseCommit on < formatId=131077, gtrid_length=35, bqual_length=36, tx_uid=0:ffff0a80002a:8e1d:664628f2:4a, node_name=quarkus, branch_uid=0:ffff0a80002a:8e1d:664628f2:4f, subordinatenodename=null, eis_name=0 > (io.agroal.narayana.LocalXAResource@7a88d22e) failed with exception XAException.XA_RBROLLBACK: javax.transaction.xa.XAException: Error trying to transactionCommit local transaction: Enlisted connection used without active transaction
    at io.agroal.narayana.LocalXAResource.xaException(LocalXAResource.java:140)
    at io.agroal.narayana.LocalXAResource.xaException(LocalXAResource.java:134)
    at io.agroal.narayana.LocalXAResource.commit(LocalXAResource.java:72)
    at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelOnePhaseCommit(XAResourceRecord.java:702)
    at com.arjuna.ats.arjuna.coordinator.BasicAction.onePhaseCommit(BasicAction.java:2400)
    at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1502)
    at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:96)
    at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
    at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1295)
    at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:128)
    at io.quarkus.narayana.jta.runtime.NotifyingTransactionManager.commit(NotifyingTransactionManager.java:70)
    at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.endTransaction(TransactionalInterceptorBase.java:406)
    at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:175)
    at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:107)
    at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequiresNew.doIntercept(TransactionalInterceptorRequiresNew.java:41)
    at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.intercept(TransactionalInterceptorBase.java:61)
    at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequiresNew.intercept(TransactionalInterceptorRequiresNew.java:32)
    at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequiresNew_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.cryostat.discovery.KubeApiDiscovery_Subclass.handleEndpointEvent(Unknown Source)
    at io.cryostat.discovery.KubeApiDiscovery_ClientProxy.handleEndpointEvent(Unknown Source)
    at io.cryostat.discovery.KubeApiDiscovery_VertxInvoker_handleEndpointEvent_635620020fc12efe8e9e350b70fee1eb521fae16.invokeBean(Unknown Source)
    at io.quarkus.vertx.runtime.EventConsumerInvoker.invoke(EventConsumerInvoker.java:41)
    at io.quarkus.vertx.runtime.VertxRecorder$3$1$1.handle(VertxRecorder.java:116)
    at io.quarkus.vertx.runtime.VertxRecorder$3$1$1.handle(VertxRecorder.java:112)
    at io.vertx.core.impl.ContextBase.lambda$executeBlocking$1(ContextBase.java:180)
    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.TaskQueue.run(TaskQueue.java:77)
    at io.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:576)
    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/java.lang.Thread.run(Thread.java:840)
Caused by: java.sql.SQLException: Enlisted connection used without active transaction
    at io.agroal.pool.ConnectionHandler.verifyEnlistment(ConnectionHandler.java:398)
    at io.agroal.pool.ConnectionHandler.transactionCommit(ConnectionHandler.java:355)
    at io.agroal.narayana.LocalXAResource.commit(LocalXAResource.java:69)
    ... 35 more

2024-05-16 15:41:50,223 ERROR [io.qua.ver.cor.run.VertxCoreRecorder] (vert.x-eventloop-thread-3) Uncaught exception received by Vert.x: io.quarkus.arc.ArcUndeclaredThrowableException: Error invoking subclass method
    at io.cryostat.discovery.KubeApiDiscovery_Subclass.handleEndpointEvent(Unknown Source)
    at io.cryostat.discovery.KubeApiDiscovery_ClientProxy.handleEndpointEvent(Unknown Source)
    at io.cryostat.discovery.KubeApiDiscovery_VertxInvoker_handleEndpointEvent_635620020fc12efe8e9e350b70fee1eb521fae16.invokeBean(Unknown Source)
    at io.quarkus.vertx.runtime.EventConsumerInvoker.invoke(EventConsumerInvoker.java:41)
    at io.quarkus.vertx.runtime.VertxRecorder$3$1$1.handle(VertxRecorder.java:116)
    at io.quarkus.vertx.runtime.VertxRecorder$3$1$1.handle(VertxRecorder.java:112)
    at io.vertx.core.impl.ContextBase.lambda$executeBlocking$1(ContextBase.java:180)
    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.TaskQueue.run(TaskQueue.java:77)
    at io.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:576)
    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/java.lang.Thread.run(Thread.java:840)
Caused by: jakarta.transaction.RollbackException: ARJUNA016053: Could not commit transaction.
    at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1307)
    at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:128)
    at io.quarkus.narayana.jta.runtime.NotifyingTransactionManager.commit(NotifyingTransactionManager.java:70)
    at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.endTransaction(TransactionalInterceptorBase.java:406)
    at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:175)
    at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:107)
    at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequiresNew.doIntercept(TransactionalInterceptorRequiresNew.java:41)
    at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.intercept(TransactionalInterceptorBase.java:61)
    at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequiresNew.intercept(TransactionalInterceptorRequiresNew.java:32)
    at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequiresNew_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)
    ... 17 more
    Suppressed: javax.transaction.xa.XAException: Error trying to transactionCommit local transaction: Enlisted connection used without active transaction
        at io.agroal.narayana.LocalXAResource.xaException(LocalXAResource.java:140)
        at io.agroal.narayana.LocalXAResource.xaException(LocalXAResource.java:134)
        at io.agroal.narayana.LocalXAResource.commit(LocalXAResource.java:72)
        at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelOnePhaseCommit(XAResourceRecord.java:702)
        at com.arjuna.ats.arjuna.coordinator.BasicAction.onePhaseCommit(BasicAction.java:2400)
        at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1502)
        at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:96)
        at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
        at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1295)
        ... 29 more
    Caused by: java.sql.SQLException: Enlisted connection used without active transaction
        at io.agroal.pool.ConnectionHandler.verifyEnlistment(ConnectionHandler.java:398)
        at io.agroal.pool.ConnectionHandler.transactionCommit(ConnectionHandler.java:355)
        at io.agroal.narayana.LocalXAResource.commit(LocalXAResource.java:69)
        ... 35 more
andrewazores commented 1 month ago
2024-05-16 15:42:10,020 ERROR [io.fab.kub.cli.inf.imp.cac.SharedProcessor] (executor-thread-3) v1/namespaces/cryostat3/endpoints failed invoking io.cryostat.discovery.KubeApiDiscovery$EndpointsHandler@6c6125f0 event handler: Cannot load from object array because "values" is null: java.lang.NullPointerException: Cannot load from object array because "values" is null
    at org.hibernate.persister.entity.AbstractEntityPersister.initializeLazyPropertiesFromDatastore(AbstractEntityPersister.java:1573)
    at org.hibernate.persister.entity.AbstractEntityPersister.initializeLazyProperty(AbstractEntityPersister.java:1497)
    at org.hibernate.bytecode.enhance.spi.interceptor.LazyAttributeLoadingInterceptor.lambda$loadAttribute$0(LazyAttributeLoadingInterceptor.java:112)
    at org.hibernate.bytecode.enhance.spi.interceptor.EnhancementHelper.performWork(EnhancementHelper.java:206)
    at org.hibernate.bytecode.enhance.spi.interceptor.LazyAttributeLoadingInterceptor.loadAttribute(LazyAttributeLoadingInterceptor.java:82)
    at org.hibernate.bytecode.enhance.spi.interceptor.LazyAttributeLoadingInterceptor.fetchAttribute(LazyAttributeLoadingInterceptor.java:78)
    at org.hibernate.bytecode.enhance.spi.interceptor.LazyAttributeLoadingInterceptor.handleRead(LazyAttributeLoadingInterceptor.java:59)
    at org.hibernate.bytecode.enhance.spi.interceptor.AbstractInterceptor.readObject(AbstractInterceptor.java:152)
    at io.cryostat.discovery.DiscoveryNode.$$_hibernate_read_target(DiscoveryNode.java)
    at io.cryostat.discovery.DiscoveryNode.getTarget(DiscoveryNode.java)
    at io.cryostat.discovery.KubeApiDiscovery.lambda$handleObservedEndpoints$4(KubeApiDiscovery.java:299)
    at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197)
    at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1625)
    at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509)
    at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499)
    at java.base/java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:921)
    at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
    at java.base/java.util.stream.ReferencePipeline.collect(ReferencePipeline.java:682)
    at io.cryostat.discovery.KubeApiDiscovery.handleObservedEndpoints(KubeApiDiscovery.java:299)
    at io.cryostat.discovery.KubeApiDiscovery$EndpointsHandler.lambda$onUpdate$1(KubeApiDiscovery.java:573)
    at io.quarkus.narayana.jta.TransactionRunnerImpl.lambda$run$0(TransactionRunnerImpl.java:27)
    at io.quarkus.narayana.jta.QuarkusTransactionImpl.callInOurTx(QuarkusTransactionImpl.java:136)
    at io.quarkus.narayana.jta.QuarkusTransactionImpl.callJoinExisting(QuarkusTransactionImpl.java:79)
    at io.quarkus.narayana.jta.QuarkusTransactionImpl.call(QuarkusTransactionImpl.java:33)
    at io.quarkus.narayana.jta.TransactionRunnerImpl.run(TransactionRunnerImpl.java:26)
    at io.cryostat.discovery.KubeApiDiscovery$EndpointsHandler.onUpdate(KubeApiDiscovery.java:573)
    at io.cryostat.discovery.KubeApiDiscovery$EndpointsHandler.onUpdate(KubeApiDiscovery.java:556)
    at io.fabric8.kubernetes.client.informers.impl.cache.ProcessorListener$UpdateNotification.handle(ProcessorListener.java:92)
    at io.fabric8.kubernetes.client.informers.impl.cache.ProcessorListener.add(ProcessorListener.java:50)
    at io.fabric8.kubernetes.client.informers.impl.cache.SharedProcessor.lambda$distribute$0(SharedProcessor.java:91)
    at io.fabric8.kubernetes.client.informers.impl.cache.SharedProcessor.lambda$distribute$1(SharedProcessor.java:114)
    at io.fabric8.kubernetes.client.utils.internal.SerialExecutor.lambda$execute$0(SerialExecutor.java:58)
    at io.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:581)
    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/java.lang.Thread.run(Thread.java:840)
andrewazores commented 1 month ago
2024-05-16 15:42:50,420 WARN  [com.arj.ats.arjuna] (Transaction Reaper) ARJUNA012117: TransactionReaper::check processing TX 0:ffff0a80002a:8e1d:664628f2:70 in state  RUN
2024-05-16 15:42:50,421 WARN  [com.arj.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012095: Abort of action id 0:ffff0a80002a:8e1d:664628f2:70 invoked while multiple threads active within it.
2024-05-16 15:42:50,422 WARN  [com.arj.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012381: Action id 0:ffff0a80002a:8e1d:664628f2:70 completed with multiple threads - thread executor-thread-4 was in progress with io.cryostat.targets.TargetConnectionManager.lambda$executeConnectedTaskUni$1(TargetConnectionManager.java:201)
io.cryostat.targets.TargetConnectionManager$$Lambda$2012/0x00007f31bfc5a598.apply(Unknown Source)
io.smallrye.mutiny.unchecked.UncheckedFunction.lambda$toFunction$0(UncheckedFunction.java:45)
io.smallrye.mutiny.unchecked.UncheckedFunction$$Lambda$2013/0x00007f31bfc5a7f0.apply(Unknown Source)
io.smallrye.context.impl.wrappers.SlowContextualFunction.apply(SlowContextualFunction.java:21)
io.smallrye.mutiny.operators.uni.UniOnItemTransform$UniOnItemTransformProcessor.onItem(UniOnItemTransform.java:36)
io.smallrye.mutiny.operators.uni.builders.UniCreateFromCompletionStage$CompletionStageUniSubscription.forwardResult(UniCreateFromCompletionStage.java:63)
io.smallrye.mutiny.operators.uni.builders.UniCreateFromCompletionStage$CompletionStageUniSubscription$$Lambda$2014/0x00007f31bfc5acb8.accept(Unknown Source)
java.base@17.0.11/java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:863)
java.base@17.0.11/java.util.concurrent.CompletableFuture.uniWhenCompleteStage(CompletableFuture.java:887)
java.base@17.0.11/java.util.concurrent.CompletableFuture.whenComplete(CompletableFuture.java:2325)
java.base@17.0.11/java.util.concurrent.CompletableFuture.whenComplete(CompletableFuture.java:144)
io.smallrye.mutiny.operators.uni.builders.UniCreateFromCompletionStage$CompletionStageUniSubscription.forward(UniCreateFromCompletionStage.java:51)
io.smallrye.mutiny.operators.uni.builders.UniCreateFromCompletionStage.subscribe(UniCreateFromCompletionStage.java:35)
io.smallrye.mutiny.operators.AbstractUni.subscribe(AbstractUni.java:36)
io.smallrye.mutiny.operators.uni.UniOnItemTransform.subscribe(UniOnItemTransform.java:22)
io.smallrye.mutiny.operators.AbstractUni.subscribe(AbstractUni.java:36)
io.smallrye.mutiny.operators.uni.UniOnFailureTransform.subscribe(UniOnFailureTransform.java:31)
io.smallrye.mutiny.operators.AbstractUni.subscribe(AbstractUni.java:36)
io.smallrye.mutiny.operators.uni.UniOnItemConsume.subscribe(UniOnItemConsume.java:30)
io.smallrye.mutiny.operators.AbstractUni.subscribe(AbstractUni.java:36)
io.smallrye.mutiny.operators.uni.UniOnFailureTransform.subscribe(UniOnFailureTransform.java:31)
io.smallrye.mutiny.operators.AbstractUni.subscribe(AbstractUni.java:36)
io.smallrye.mutiny.operators.uni.UniOnFailureTransform.subscribe(UniOnFailureTransform.java:31)
io.smallrye.mutiny.operators.AbstractUni.subscribe(AbstractUni.java:36)
io.smallrye.mutiny.operators.uni.UniOnFailureTransform.subscribe(UniOnFailureTransform.java:31)
io.smallrye.mutiny.operators.AbstractUni.subscribe(AbstractUni.java:36)
io.smallrye.mutiny.operators.uni.UniOnFailureTransform.subscribe(UniOnFailureTransform.java:31)
io.smallrye.mutiny.operators.AbstractUni.subscribe(AbstractUni.java:36)
io.smallrye.mutiny.converters.uni.UniToMultiPublisher$UniToMultiSubscription.request(UniToMultiPublisher.java:73)
io.smallrye.mutiny.subscription.SwitchableSubscriptionSubscriber.setOrSwitchUpstream(SwitchableSubscriptionSubscriber.java:205)
io.smallrye.mutiny.subscription.SwitchableSubscriptionSubscriber.onSubscribe(SwitchableSubscriptionSubscriber.java:107)
io.smallrye.mutiny.converters.uni.UniToMultiPublisher.subscribe(UniToMultiPublisher.java:25)
io.smallrye.mutiny.groups.MultiCreate$1.subscribe(MultiCreate.java:165)
io.smallrye.mutiny.operators.multi.MultiRetryWhenOp.subscribe(MultiRetryWhenOp.java:68)
io.smallrye.mutiny.operators.multi.MultiRetryWhenOp.subscribe(MultiRetryWhenOp.java:74)
io.smallrye.mutiny.operators.AbstractMulti.subscribe(AbstractMulti.java:39)
io.smallrye.mutiny.operators.uni.builders.UniCreateFromPublisher$PublisherSubscriber.forward(UniCreateFromPublisher.java:41)
io.smallrye.mutiny.operators.uni.builders.UniCreateFromPublisher.subscribe(UniCreateFromPublisher.java:26)
io.smallrye.mutiny.operators.AbstractUni.subscribe(AbstractUni.java:36)
io.smallrye.mutiny.operators.uni.UniOnFailureTransform.subscribe(UniOnFailureTransform.java:31)
io.smallrye.mutiny.operators.AbstractUni.subscribe(AbstractUni.java:36)
io.smallrye.mutiny.operators.uni.UniBlockingAwait.await(UniBlockingAwait.java:60)
io.smallrye.mutiny.groups.UniAwait.atMost(UniAwait.java:65)
io.cryostat.targets.TargetConnectionManager.executeConnectedTask(TargetConnectionManager.java:207)
io.cryostat.targets.TargetConnectionManager_ClientProxy.executeConnectedTask(Unknown Source)
io.cryostat.recordings.RecordingHelper.listActiveRecordingsImpl(RecordingHelper.java:234)
io.cryostat.recordings.RecordingHelper.lambda$listActiveRecordings$1(RecordingHelper.java:222)
io.cryostat.recordings.RecordingHelper$$Lambda$1999/0x00007f31bfc58698.call(Unknown Source)
io.quarkus.narayana.jta.QuarkusTransactionImpl.callInTheirTx(QuarkusTransactionImpl.java:173)
io.quarkus.narayana.jta.QuarkusTransactionImpl.callJoinExisting(QuarkusTransactionImpl.java:77)
io.quarkus.narayana.jta.QuarkusTransactionImpl.call(QuarkusTransactionImpl.java:33)
io.quarkus.narayana.jta.TransactionRunnerImpl.call(TransactionRunnerImpl.java:34)
io.cryostat.recordings.RecordingHelper.listActiveRecordings(RecordingHelper.java:222)
io.cryostat.recordings.RecordingHelper_ClientProxy.listActiveRecordings(Unknown Source)
io.cryostat.recordings.Recordings.listForTarget(Recordings.java:451)
io.cryostat.recordings.Recordings_Subclass.listForTarget$$superforward(Unknown Source)
io.cryostat.recordings.Recordings_Subclass$$function$$10.apply(Unknown Source)
io.quarkus.arc.impl.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:73)
io.quarkus.arc.impl.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:62)
io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:136)
io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:107)
io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequired.doIntercept(TransactionalInterceptorRequired.java:38)
io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.intercept(TransactionalInterceptorBase.java:61)
io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequired.intercept(TransactionalInterceptorRequired.java:32)
io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorRequired_Bean.intercept(Unknown Source)
io.quarkus.arc.impl.InterceptorInvocation.invoke(InterceptorInvocation.java:42)
io.quarkus.arc.impl.AroundInvokeInvocationContext.perform(AroundInvokeInvocationContext.java:30)
io.quarkus.arc.impl.InvocationContexts.performAroundInvoke(InvocationContexts.java:27)
io.cryostat.recordings.Recordings_Subclass.listForTarget(Unknown Source)
io.cryostat.recordings.Recordings$quarkusrestinvoker$listForTarget_1e269b18e4d790f0de6d6b4d5c89580a98e9a128.invoke(Unknown Source)
org.jboss.resteasy.reactive.server.handlers.InvocationHandler.handle(InvocationHandler.java:29)
io.quarkus.resteasy.reactive.server.runtime.QuarkusResteasyReactiveRequestContext.invokeHandler(QuarkusResteasyReactiveRequestContext.java:141)
org.jboss.resteasy.reactive.common.core.AbstractResteasyReactiveContext.run(AbstractResteasyReactiveContext.java:145)
io.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:576)
org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2513)
org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1538)
org.jboss.threads.DelegatingRunnable.run(DelegatingRunnable.java:29)
org.jboss.threads.ThreadLocalResettingRunnable.run(ThreadLocalResettingRunnable.java:29)
io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
java.base@17.0.11/java.lang.Thread.run(Thread.java:840)
andrewazores commented 1 month ago
2024-05-16 15:53:09,938 ERROR [io.qua.ver.htt.run.QuarkusErrorHandler] (executor-thread-21) HTTP Request to /api/v3/targets/4/recordings failed, error id: 64a20332-7fac-4182-b5e0-f2ba9bfdba81-2: jakarta.transaction.RollbackException: ARJUNA016053: Could not commit transaction.
    at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1307)
    at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:128)
    at io.quarkus.narayana.jta.runtime.NotifyingTransactionManager.commit(NotifyingTransactionManager.java:70)
    at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.endTransaction(TransactionalInterceptorBase.java:406)
    at io.quarkus.narayana.jta.runtime.interceptor.TransactionalInterceptorBase.invokeInOurTx(TransactionalInterceptorBase.java:171)
    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.perform(AroundInvokeInvocationContext.java:30)
    at io.quarkus.arc.impl.InvocationContexts.performAroundInvoke(InvocationContexts.java:27)
    at io.cryostat.recordings.Recordings_Subclass.listForTarget(Unknown Source)
    at io.cryostat.recordings.Recordings$quarkusrestinvoker$listForTarget_1e269b18e4d790f0de6d6b4d5c89580a98e9a128.invoke(Unknown Source)
    at org.jboss.resteasy.reactive.server.handlers.InvocationHandler.handle(InvocationHandler.java:29)
    at io.quarkus.resteasy.reactive.server.runtime.QuarkusResteasyReactiveRequestContext.invokeHandler(QuarkusResteasyReactiveRequestContext.java:141)
    at org.jboss.resteasy.reactive.common.core.AbstractResteasyReactiveContext.run(AbstractResteasyReactiveContext.java:145)
    at io.quarkus.vertx.core.runtime.VertxCoreRecorder$14.runWith(VertxCoreRecorder.java:576)
    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/java.lang.Thread.run(Thread.java:840)
    Suppressed: javax.transaction.xa.XAException: Error trying to transactionCommit local transaction: Enlisted connection used without active transaction
        at io.agroal.narayana.LocalXAResource.xaException(LocalXAResource.java:140)
        at io.agroal.narayana.LocalXAResource.xaException(LocalXAResource.java:134)
        at io.agroal.narayana.LocalXAResource.commit(LocalXAResource.java:72)
        at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelOnePhaseCommit(XAResourceRecord.java:702)
        at com.arjuna.ats.arjuna.coordinator.BasicAction.onePhaseCommit(BasicAction.java:2400)
        at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1502)
        at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:96)
        at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162)
        at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1295)
        ... 24 more
    Caused by: java.sql.SQLException: Enlisted connection used without active transaction
        at io.agroal.pool.ConnectionHandler.verifyEnlistment(ConnectionHandler.java:398)
        at io.agroal.pool.ConnectionHandler.transactionCommit(ConnectionHandler.java:355)
        at io.agroal.narayana.LocalXAResource.commit(LocalXAResource.java:69)
        ... 30 more
andrewazores commented 1 month ago
2024-05-16 16:42:21,020 INFO  [org.qua.cor.JobRunShell] (QuarkusQuartzScheduler_Worker-16) Job periodic.cdd7ca77-4c3b-45b3-ae1e-32a32c7c5a03 threw a JobExecutionException: : org.quartz.JobExecutionException: jakarta.enterprise.context.ContextNotActiveException: Cannot use the EntityManager/Session because neither a transaction nor a CDI request context is active. Consider adding @Transactional to your method to automatically activate a transaction, or @ActivateRequestContext if you have valid reasons not to use transactions. [See nested exception: jakarta.enterprise.context.ContextNotActiveException: Cannot use the EntityManager/Session because neither a transaction nor a CDI request context is active. Consider adding @Transactional to your method to automatically activate a transaction, or @ActivateRequestContext if you have valid reasons not to use transactions.]
    at io.cryostat.discovery.Discovery$RefreshPluginJob.execute(Discovery.java:429)
    at org.quartz.core.JobRunShell.run(JobRunShell.java:202)
    at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573)
Caused by: jakarta.enterprise.context.ContextNotActiveException: Cannot use the EntityManager/Session because neither a transaction nor a CDI request context is active. Consider adding @Transactional to your method to automatically activate a transaction, or @ActivateRequestContext if you have valid reasons not to use transactions.
    at io.quarkus.hibernate.orm.runtime.session.TransactionScopedSession.acquireSession(TransactionScopedSession.java:107)
    at io.quarkus.hibernate.orm.runtime.session.TransactionScopedSession.createQuery(TransactionScopedSession.java:366)
    at org.hibernate.engine.spi.SessionLazyDelegator.createQuery(SessionLazyDelegator.java:548)
    at org.hibernate.engine.spi.SessionLazyDelegator.createQuery(SessionLazyDelegator.java:66)
    at org.hibernate.Session_3a974b6a18ac399f675913d732c105426414d370_Synthetic_ClientProxy.createQuery(Unknown Source)
    at io.quarkus.hibernate.orm.panache.common.runtime.CommonPanacheQueryImpl.createBaseQuery(CommonPanacheQueryImpl.java:366)
    at io.quarkus.hibernate.orm.panache.common.runtime.CommonPanacheQueryImpl.createQuery(CommonPanacheQueryImpl.java:327)
    at io.quarkus.hibernate.orm.panache.common.runtime.CommonPanacheQueryImpl.singleResult(CommonPanacheQueryImpl.java:307)
    at io.quarkus.hibernate.orm.panache.runtime.PanacheQueryImpl.singleResult(PanacheQueryImpl.java:169)
    at io.cryostat.discovery.Discovery$RefreshPluginJob.execute(Discovery.java:412)
    ... 2 more