Why doesn't my wildfly invalidate and reconnect a closed connection in the pool?

363 views
Skip to first unread message

Mark Wright

unread,
May 27, 2025, 2:42:35 PM5/27/25
to WildFly
We run a couple dozen applications, all on AWS's kubernetes service (EKS) and each connecting to their own RDS mariadb instance.  This has been working great until the last month or so, when we started getting intermittent "database connection closed" errors that persist for multiple minutes and require a manual reboot of the instance to correct.

But ... we have the following set in our standalone.xml!  I would assume that this would set a maximum of 30 seconds that a bad connection remains in the pool, but the bad connection persists until I restart the instance.   Why wouldnt this fix the issue?
```
<validation>
    <check-valid-connection-sql>${env.DATABASE_CONNECTION_CHECK:SELECT 1;}</check-valid-connection-sql>
    <validate-on-match>false</validate-on-match>
    <background-validation>true</background-validation>
    <background-validation-millis>30000</background-validation-millis>
</validation>
```

We're using `wildfly-33.0.2.Final` and v3.4.1 of the mariadb jdbc driver.

From the logs, it looks like we check out the connection from JCA, fail with "Connection is closed" and then return the bad connection to the pool to be re-used:
```
2025-05-27 14:55:24,215+0000 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (default task-205385) supplying ManagedConnection from pool: org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@79556d29[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@60f03c5e connection handles=0 lastReturned=1748357723111 lastValidated=1748083905749 lastCheckedOut=1748357723111 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@49c9f088 mcp=SemaphoreConcurrentLinkedDequeManagedConnectionPool@24743974[pool=appds] xaResource=LocalXAResourceImpl@4febd7ba[connectionListener=79556d29 connectionManager=492782c4 warned=false currentXid=null productName=MariaDB productVersion=10.11.10-MariaDB-log jndiName=java:/AppDS] txSync=null]
2025-05-27 14:55:24,215+0000 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (default task-205385) Got connection from pool: org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@79556d29[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@60f03c5e connection handles=0 lastReturned=1748357723111 lastValidated=1748083905749 lastCheckedOut=1748357724215 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@49c9f088 mcp=SemaphoreConcurrentLinkedDequeManagedConnectionPool@24743974[pool=appds] xaResource=LocalXAResourceImpl@4febd7ba[connectionListener=79556d29 connectionManager=492782c4 warned=false currentXid=null productName=MariaDB productVersion=10.11.10-MariaDB-log jndiName=java:/AppDS] txSync=null]
2025-05-27 14:55:24,215+0000 DEBUG [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (default task-205385) java.sql.Connection#beginRequest has been invoked
2025-05-27 14:55:24,215+0000 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (default task-205385) No transaction, no need to enlist: org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@79556d29[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@60f03c5e connection handles=0 lastReturned=1748357723111 lastValidated=1748083905749 lastCheckedOut=1748357724215 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@49c9f088 mcp=SemaphoreConcurrentLinkedDequeManagedConnectionPool@24743974[pool=appds] xaResource=LocalXAResourceImpl@4febd7ba[connectionListener=79556d29 connectionManager=492782c4 warned=false currentXid=null productName=MariaDB productVersion=10.11.10-MariaDB-log jndiName=java:/AppDS] txSync=null]
2025-05-27 14:55:24,215+0000 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (default task-205385) [TxConnectionListener@79556d29] registerConnection: org.jboss.jca.adapters.jdbc.jdk8.WrappedConnectionJDK8@2ab4dda6 [size=1] ([org.jboss.jca.adapters.jdbc.jdk8.WrappedConnectionJDK8@2ab4dda6])
2025-05-27 14:55:24,215+0000 TRACE [org.jboss.jca.core.api.connectionmanager.ccm.CachedConnectionManager] (default task-205385) registering connection from connection manager: org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl@492782c4, connection : org.jboss.jca.adapters.jdbc.jdk8.WrappedConnectionJDK8@2ab4dda6, key: org.jboss.as.connector.deployers.ra.processors.CachedConnectionManagerSetupProcessor$CachedConnectionManagerSetupAction@38ad7344
2025-05-27 14:55:24,215+0000 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (default task-205385) Lock: HeldByCurrentThread: No, Locked: No, HoldCount: 0, QueueLength: 0
2025-05-27 14:55:24,215+0000 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (default task-205385) Unlock: HeldByCurrentThread: Yes, Locked: Yes, HoldCount: 1, QueueLength: 0
2025-05-27 14:55:24,215+0000 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (default task-205385) Owner: Thread[default task-205385,5,main]
2025-05-27 14:55:24,215+0000 WARN  [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (default task-205385) SQL Error: 1220, SQLState: 08000
2025-05-27 14:55:24,215+0000 ERROR [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (default task-205385) (conn=210181) Connection is closed
2025-05-27 14:55:24,215+0000 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (default task-205385) Lock: HeldByCurrentThread: No, Locked: No, HoldCount: 0, QueueLength: 0
2025-05-27 14:55:24,215+0000 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (default task-205385) Unlock: HeldByCurrentThread: Yes, Locked: Yes, HoldCount: 1, QueueLength: 0
2025-05-27 14:55:24,215+0000 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (default task-205385) Owner: Thread[default task-205385,5,main]
2025-05-27 14:55:24,215+0000 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (default task-205385) connectionClosed called mc=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@60f03c5e
2025-05-27 14:55:24,215+0000 TRACE [org.jboss.jca.core.api.connectionmanager.ccm.CachedConnectionManager] (default task-205385) unregistering connection from connection manager: org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl@492782c4, connection: org.jboss.jca.adapters.jdbc.jdk8.WrappedConnectionJDK8@2ab4dda6, key: org.jboss.as.connector.deployers.ra.processors.CachedConnectionManagerSetupProcessor$CachedConnectionManagerSetupAction@38ad7344
2025-05-27 14:55:24,215+0000 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (default task-205385) [TxConnectionListener@79556d29] unregisterConnection: 0 handles left ([])
2025-05-27 14:55:24,215+0000 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (default task-205385) [TxConnectionListener@79556d29] isManagedConnectionFree: true
2025-05-27 14:55:24,215+0000 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (default task-205385) delisting org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@79556d29[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@60f03c5e connection handles=0 lastReturned=1748357723111 lastValidated=1748083905749 lastCheckedOut=1748357724215 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@49c9f088 mcp=SemaphoreConcurrentLinkedDequeManagedConnectionPool@24743974[pool=appds] xaResource=LocalXAResourceImpl@4febd7ba[connectionListener=79556d29 connectionManager=492782c4 warned=false currentXid=null productName=MariaDB productVersion=10.11.10-MariaDB-log jndiName=java:/AppDS] txSync=null]
2025-05-27 14:55:24,215+0000 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (default task-205385) [TxConnectionListener@79556d29] isManagedConnectionFree: true
2025-05-27 14:55:24,215+0000 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (default task-205385) delisted org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@79556d29[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@60f03c5e connection handles=0 lastReturned=1748357723111 lastValidated=1748083905749 lastCheckedOut=1748357724215 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@49c9f088 mcp=SemaphoreConcurrentLinkedDequeManagedConnectionPool@24743974[pool=appds] xaResource=LocalXAResourceImpl@4febd7ba[connectionListener=79556d29 connectionManager=492782c4 warned=false currentXid=null productName=MariaDB productVersion=10.11.10-MariaDB-log jndiName=java:/AppDS] txSync=null]
2025-05-27 14:55:24,215+0000 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (default task-205385) isManagedConnectionFree=true mc=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@60f03c5e
2025-05-27 14:55:24,215+0000 DEBUG [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (default task-205385) java.sql.Connection#endRequest has been invoked
2025-05-27 14:55:24,215+0000 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (default task-205385) returnConnection(79556d29, false)
Method: returnConnection(79556d29, false)
  Subject: null
  CRI: null
ManagedConnectionPool:
  Class: org.jboss.jca.core.connectionmanager.pool.mcp.SemaphoreConcurrentLinkedDequeManagedConnectionPool
  Object: 24743974
ManagedConnectionFactory:
  Class: org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory
  Object: 66415817
ConnectionManager:
  Class: org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl
  Object: 492782c4
Pool:
  Name: appds
  Class: org.jboss.jca.core.connectionmanager.pool.strategy.OnePool
  Object: 49c9f088
  FIFO: false
PoolConfiguration:
  MinSize: 10
  InitialSize: 10
  MaxSize: 150
  BlockingTimeout: 30000
  IdleTimeoutMinutes: 3
  ValidateOnMatch: false
  BackgroundValidation: true
  BackgroundValidationMillis: 30000
  StrictMin: false
  UseFastFail: false
  Decrementer: org.jboss.jca.core.connectionmanager.pool.capacity.TimedOutDecrementer
Available (9):
  66da2e8c (NORMAL) (Returned: 1747930545547) (Validated: 1748083710721) (Pool: 427178668)
  552a2fe (NORMAL) (Returned: 1748013739062) (Validated: 1748083710723) (Pool: 343985153)
  5748bafb (NORMAL) (Returned: 1748048181971) (Validated: 1748083725731) (Pool: 309542244)
  bb4120e (NORMAL) (Returned: 1748062499050) (Validated: 1748083710725) (Pool: 295225165)
  2c2a1016 (NORMAL) (Returned: 1748069723776) (Validated: 1748083710727) (Pool: 288000439)
  3d07664b (NORMAL) (Returned: 1748083725231) (Validated: 1748083710729) (Pool: 273998984)
  254168e9 (NORMAL) (Returned: 1748083725755) (Validated: 1748083725755) (Pool: 273998460)
  1cd85eb0 (NORMAL) (Returned: 1748083725766) (Validated: 1748083725766) (Pool: 273998449)
  7ad1c241 (NORMAL) (Returned: 1748302512678) (Validated: 1748083725776) (Pool: 55211537)
InUse (1):
  79556d29 (NORMAL) (CheckedOut: 1748357724215) (Validated: 1748083905749) (Usage: 0)
Statistics:
  ActiveCount: 0
  AvailableCount: 0
  AverageBlockingTime: 0
  AverageCreationTime: 0
  AverageGetTime: 0
  AveragePoolTime: 0
  AverageUsageTime: 0
  BlockingFailureCount: 0
  CreatedCount: 0
  DestroyedCount: 0
  IdleCount: 0
  InUseCount: 0
  MaxCreationTime: 0
  MaxGetTime: 0
  MaxPoolTime: 0
  MaxUsageTime: 0
  MaxUsedCount: 0
  MaxWaitTime: 0
  TimedOut: 0
  TotalBlockingTime: 0
  TotalCreationTime: 0
  TotalGetTime: 0
  TotalPoolTime: 0
  TotalUsageTime: 0
  WaitCount: 0
XAResource:
  CommitCount: 0
  CommitTotalTime: 0
  CommitAverageTime: 0
  CommitMaxTime: 0
  EndCount: 0
  EndTotalTime: 0
  EndAverageTime: 0
  EndMaxTime: 0
  ForgetCount: 0
  ForgetTotalTime: 0
  ForgetAverageTime: 0
  ForgetMaxTime: 0
  PrepareCount: 0
  PrepareTotalTime: 0
  PrepareAverageTime: 0
  PrepareMaxTime: 0
  RecoverCount: 0
  RecoverTotalTime: 0
  RecoverAverageTime: 0
  RecoverMaxTime: 0
  RollbackCount: 0
  RollbackTotalTime: 0
  RollbackAverageTime: 0
  RollbackMaxTime: 0
  StartCount: 0
  StartTotalTime: 0
  StartAverageTime: 0
  StartMaxTime: 0
2025-05-27 14:55:24,215+0000 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (default task-205385) Returning connection to pool org.jboss.jca.core.connectionmanager.listener.TxConnectionListener@79556d29[state=NORMAL managed connection=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@60f03c5e connection handles=0 lastReturned=1748357724215 lastValidated=1748083905749 lastCheckedOut=1748357724215 trackByTx=false pool=org.jboss.jca.core.connectionmanager.pool.strategy.OnePool@49c9f088 mcp=SemaphoreConcurrentLinkedDequeManagedConnectionPool@24743974[pool=appds] xaResource=LocalXAResourceImpl@4febd7ba[connectionListener=79556d29 connectionManager=492782c4 warned=false currentXid=null productName=MariaDB productVersion=10.11.10-MariaDB-log jndiName=java:/AppDS] txSync=null]
2025-05-27 14:55:24,215+0000 ERROR [org.ejbca.core.ejb.config.HealthCheckSessionBean] (default task-205385) Error creating connection to database.: org.hibernate.exception.JDBCConnectionException: could not prepare statement [(conn=210181) Connection is closed] [SELECT 1 FROM CertificateData WHERE fingerprint='XX']
at org.hi...@6.4.4.Final//org.hibernate.exception.internal.SQLExceptionTypeDelegate.convert(SQLExceptionTypeDelegate.java:51)
at org.hi...@6.4.4.Final//org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:58)
at org.hi...@6.4.4.Final//org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:108)
at org.hi...@6.4.4.Final//org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:194)
at org.hi...@6.4.4.Final//org.hibernate.engine.jdbc.internal.StatementPreparerImpl.prepareQueryStatement(StatementPreparerImpl.java:155)
at org.hi...@6.4.4.Final//org.hibernate.sql.exec.spi.JdbcSelectExecutor.lambda$list$0(JdbcSelectExecutor.java:85)
at org.hi...@6.4.4.Final//org.hibernate.sql.results.jdbc.internal.DeferredResultSetAccess.executeQuery(DeferredResultSetAccess.java:231)
at org.hi...@6.4.4.Final//org.hibernate.sql.results.jdbc.internal.DeferredResultSetAccess.getResultSet(DeferredResultSetAccess.java:167)
at org.hi...@6.4.4.Final//org.hibernate.sql.results.jdbc.internal.AbstractResultSetAccess.getMetaData(AbstractResultSetAccess.java:36)
at org.hi...@6.4.4.Final//org.hibernate.sql.results.jdbc.internal.AbstractResultSetAccess.getColumnCount(AbstractResultSetAccess.java:52)
at org.hi...@6.4.4.Final//org.hibernate.query.results.ResultSetMappingImpl.resolve(ResultSetMappingImpl.java:193)
at org.hi...@6.4.4.Final//org.hibernate.sql.exec.internal.JdbcSelectExecutorStandardImpl.resolveJdbcValuesSource(JdbcSelectExecutorStandardImpl.java:325)
at org.hi...@6.4.4.Final//org.hibernate.sql.exec.internal.JdbcSelectExecutorStandardImpl.doExecuteQuery(JdbcSelectExecutorStandardImpl.java:115)
at org.hi...@6.4.4.Final//org.hibernate.sql.exec.internal.JdbcSelectExecutorStandardImpl.executeQuery(JdbcSelectExecutorStandardImpl.java:83)
at org.hi...@6.4.4.Final//org.hibernate.sql.exec.spi.JdbcSelectExecutor.list(JdbcSelectExecutor.java:76)
at org.hi...@6.4.4.Final//org.hibernate.sql.exec.spi.JdbcSelectExecutor.list(JdbcSelectExecutor.java:65)
at org.hi...@6.4.4.Final//org.hibernate.query.sql.internal.NativeSelectQueryPlanImpl.performList(NativeSelectQueryPlanImpl.java:138)
at org.hi...@6.4.4.Final//org.hibernate.query.sql.internal.NativeQueryImpl.doList(NativeQueryImpl.java:621)
at org.hi...@6.4.4.Final//org.hibernate.query.spi.AbstractSelectionQuery.list(AbstractSelectionQuery.java:427)
at org.hi...@6.4.4.Final//org.hibernate.query.Query.getResultList(Query.java:120)
at org.jbos...@33.0.2.Final//org.jboss.as.jpa.container.QueryNonTxInvocationDetacher.getResultList(QueryNonTxInvocationDetacher.java:41)
at deployment.ejbca.ear.ejbca-ejb.jar//org.ejbca.core.ejb.config.HealthCheckSessionBean.getDatabaseStatus(HealthCheckSessionBean.java:42)
at jdk.internal.reflect.GeneratedMethodAccessor562.invoke(Unknown Source)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
at java.base/java.lang.reflect.Method.invoke(Unknown Source)
at org.jbo...@33.0.2.Final//org.jboss.as.ee.component.ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptor.java:35)
at org.jboss....@2.0.1.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss....@2.0.1.Final//org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
at org.jboss.as...@33.0.2.Final//org.jboss.as.weld.interceptors.Jsr299BindingsInterceptor.delegateInterception(Jsr299BindingsInterceptor.java:62)
at org.jboss.as...@33.0.2.Final//org.jboss.as.weld.interceptors.Jsr299BindingsInterceptor.doMethodInterception(Jsr299BindingsInterceptor.java:72)
at org.jboss.as...@33.0.2.Final//org.jboss.as.weld.interceptors.Jsr299BindingsInterceptor.processInvocation(Jsr299BindingsInterceptor.java:85)
at org.jbo...@33.0.2.Final//org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:46)
at org.jboss....@2.0.1.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jbos...@33.0.2.Final//org.jboss.as.ejb3.component.invocationmetrics.ExecutionTimeInterceptor.processInvocation(ExecutionTimeInterceptor.java:26)
at org.jboss....@2.0.1.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jbos...@33.0.2.Final//org.jboss.as.jpa.interceptor.SBInvocationInterceptor.processInvocation(SBInvocationInterceptor.java:30)
at org.jboss....@2.0.1.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jbo...@33.0.2.Final//org.jboss.as.ee.concurrent.ConcurrentContextInterceptor.processInvocation(ConcurrentContextInterceptor.java:28)
at org.jboss....@2.0.1.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss....@2.0.1.Final//org.jboss.invocation.InitialInterceptor.processInvocation(InitialInterceptor.java:40)
at org.jboss....@2.0.1.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss....@2.0.1.Final//org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53)
at org.jbo...@33.0.2.Final//org.jboss.as.ee.component.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java:35)
at org.jboss....@2.0.1.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jbos...@33.0.2.Final//org.jboss.as.ejb3.component.pool.PooledInstanceInterceptor.processInvocation(PooledInstanceInterceptor.java:34)
at org.jboss....@2.0.1.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jbos...@33.0.2.Final//org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:39)
at org.jboss....@2.0.1.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jbos...@33.0.2.Final//org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInNoTx(CMTTxInterceptor.java:215)
at org.jbos...@33.0.2.Final//org.jboss.as.ejb3.tx.CMTTxInterceptor.supports(CMTTxInterceptor.java:429)
at org.jbos...@33.0.2.Final//org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:147)
at org.jboss....@2.0.1.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss....@2.0.1.Final//org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
at org.jboss...@5.1.2.Final//org.jboss.weld.module.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:87)
at org.jboss.as...@33.0.2.Final//org.jboss.as.weld.ejb.EjbRequestScopeActivationInterceptor.processInvocation(EjbRequestScopeActivationInterceptor.java:72)
at org.jboss....@2.0.1.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jbos...@33.0.2.Final//org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:24)
at org.jboss....@2.0.1.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jbos...@33.0.2.Final//org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:30)
at org.jboss....@2.0.1.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jbos...@33.0.2.Final//org.jboss.as.ejb3.security.IdentityOutflowInterceptor.processInvocation(IdentityOutflowInterceptor.java:56)
at org.jboss....@2.0.1.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jbos...@33.0.2.Final//org.jboss.as.ejb3.security.SecurityDomainInterceptor.processInvocation(SecurityDomainInterceptor.java:27)
at org.jboss....@2.0.1.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jbos...@33.0.2.Final//org.jboss.as.ejb3.deployment.processors.StartupAwaitInterceptor.processInvocation(StartupAwaitInterceptor.java:27)
at org.jboss....@2.0.1.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jbos...@33.0.2.Final//org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:47)
at org.jboss....@2.0.1.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jbos...@33.0.2.Final//org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:50)
at org.jboss....@2.0.1.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jbo...@33.0.2.Final//org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:33)
at org.jboss....@2.0.1.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss....@2.0.1.Final//org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:60)
at org.jboss....@2.0.1.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss....@2.0.1.Final//org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:438)
at org.wildfly.secu...@2.5.2.Final//org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:633)
at org.jboss....@2.0.1.Final//org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:57)
at org.jboss....@2.0.1.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss....@2.0.1.Final//org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53)
at org.jbo...@33.0.2.Final//org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:181)
at org.jbo...@33.0.2.Final//org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:174)
at org.jboss....@2.0.1.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jbos...@33.0.2.Final//org.jboss.as.ejb3.security.IdentityInterceptor.lambda$processInvocation$0(IdentityInterceptor.java:30)
at org.wildfly.secu...@2.5.2.Final//org.wildfly.security.auth.server.SecurityIdentity.runAsFunctionEx(SecurityIdentity.java:421)
at org.wildfly.secu...@2.5.2.Final//org.wildfly.security.auth.server.Scoped.runAsFunctionEx(Scoped.java:161)
at org.wildfly.secu...@2.5.2.Final//org.wildfly.security.auth.server.Scoped.runAsSupplierEx(Scoped.java:229)
at org.jbos...@33.0.2.Final//org.jboss.as.ejb3.security.IdentityInterceptor.processInvocation(IdentityInterceptor.java:30)
at org.jboss....@2.0.1.Final//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss....@2.0.1.Final//org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53)
at org.jbo...@33.0.2.Final//org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:64)
at deployment.ejbca.ear.ejbca-ejb.jar//org.ejbca.core.ejb.config.HealthCheckSessionLocal$$$view175.getDatabaseStatus(Unknown Source)
at deployment.ejbca.ear.healthcheck.war//org.ejbca.ui.web.pub.HealthCheckServlet.doAllHealthChecks(HealthCheckServlet.java:298)
at deployment.ejbca.ear.healthcheck.war//org.ejbca.ui.web.pub.HealthCheckServlet.getRateLimitedResult(HealthCheckServlet.java:228)
at deployment.ejbca.ear.healthcheck.war//org.ejbca.ui.web.pub.HealthCheckServlet.doGet(HealthCheckServlet.java:200)
at jakarta.s...@6.0.0//jakarta.servlet.http.HttpServlet.service(HttpServlet.java:527)
at jakarta.s...@6.0.0//jakarta.servlet.http.HttpServlet.service(HttpServlet.java:614)
at io.undert...@2.3.17.Final//io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:74)
at io.undert...@2.3.17.Final//io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
at io.undert...@2.3.17.Final//io.undertow.servlet.handlers.ServletChain$1.handleRequest(ServletChain.java:68)
at io.undert...@2.3.17.Final//io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
at org.wildfly.security.ely...@4.1.0.Final//org.wildfly.elytron.web.undertow.server.ElytronRunAsHandler.lambda$handleRequest$1(ElytronRunAsHandler.java:68)
at org.wildfly.secu...@2.5.2.Final//org.wildfly.security.auth.server.FlexibleIdentityAssociation.runAsFunctionEx(FlexibleIdentityAssociation.java:103)
at org.wildfly.secu...@2.5.2.Final//org.wildfly.security.auth.server.Scoped.runAsFunctionEx(Scoped.java:161)
at org.wildfly.secu...@2.5.2.Final//org.wildfly.security.auth.server.Scoped.runAs(Scoped.java:73)
at org.wildfly.security.ely...@4.1.0.Final//org.wildfly.elytron.web.undertow.server.ElytronRunAsHandler.handleRequest(ElytronRunAsHandler.java:67)
at io.undert...@2.3.17.Final//io.undertow.servlet.handlers.RedirectDirHandler.handleRequest(RedirectDirHandler.java:68)
at io.undert...@2.3.17.Final//io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:117)
at io.undert...@2.3.17.Final//io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
at io.under...@2.3.17.Final//io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at io.under...@2.3.17.Final//io.undertow.security.handlers.AuthenticationConstraintHandler.handleRequest(AuthenticationConstraintHandler.java:53)
at io.under...@2.3.17.Final//io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
at io.undert...@2.3.17.Final//io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
at io.undert...@2.3.17.Final//io.undertow.servlet.handlers.security.ServletSecurityConstraintHandler.handleRequest(ServletSecurityConstraintHandler.java:60)
at io.under...@2.3.17.Final//io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43)
at org.wildfly.security.elytron...@4.1.0.Final//org.wildfly.elytron.web.undertow.server.servlet.CleanUpHandler.handleRequest(CleanUpHandler.java:38)
at io.under...@2.3.17.Final//io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at org.wildfly.ext...@33.0.2.Final//org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:44)
at io.under...@2.3.17.Final//io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at org.wildfly.ext...@33.0.2.Final//org.wildfly.extension.undertow.deployment.GlobalRequestControllerHandler.handleRequest(GlobalRequestControllerHandler.java:51)
at io.undert...@2.3.17.Final//io.undertow.servlet.handlers.SendErrorPageHandler.handleRequest(SendErrorPageHandler.java:52)
at io.under...@2.3.17.Final//io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
at io.undert...@2.3.17.Final//io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:276)
at io.undert...@2.3.17.Final//io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:135)
at io.undert...@2.3.17.Final//io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:132)
at io.undert...@2.3.17.Final//io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
at io.undert...@2.3.17.Final//io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
at org.wildfly.ext...@33.0.2.Final//org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1421)
at org.wildfly.ext...@33.0.2.Final//org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1421)
at org.wildfly.ext...@33.0.2.Final//org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1421)
at org.wildfly.ext...@33.0.2.Final//org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1421)
at org.wildfly.ext...@33.0.2.Final//org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1421)
at io.undert...@2.3.17.Final//io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:256)
at io.undert...@2.3.17.Final//io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:101)
at io.under...@2.3.17.Final//io.undertow.server.Connectors.executeRootHandler(Connectors.java:395)
at io.under...@2.3.17.Final//io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:859)
at org.jbos...@2.4.0.Final//org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
at org.jbos...@2.4.0.Final//org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1990)
at org.jbos...@2.4.0.Final//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1486)
at org.jbos...@2.4.0.Final//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1377)
at org.jbo...@3.8.16.Final//org.xnio.XnioWorker$WorkerThreadFactory$1$1.run(XnioWorker.java:1282)
at java.base/java.lang.Thread.run(Unknown Source)
Caused by: java.sql.SQLNonTransientConnectionException: (conn=210181) Connection is closed
at deployment.jdbc-driver.jar//org.mariadb.jdbc.export.ExceptionFactory.createException(ExceptionFactory.java:300)
at deployment.jdbc-driver.jar//org.mariadb.jdbc.export.ExceptionFactory.create(ExceptionFactory.java:378)
at deployment.jdbc-driver.jar//org.mariadb.jdbc.Connection.checkNotClosed(Connection.java:700)
at deployment.jdbc-driver.jar//org.mariadb.jdbc.Connection.prepareInternal(Connection.java:162)
at deployment.jdbc-driver.jar//org.mariadb.jdbc.Connection.prepareStatement(Connection.java:497)
at org.jboss.ironjac...@3.0.9.Final//org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnection.doPrepareStatement(BaseWrapperManagedConnection.java:790)
at org.jboss.ironjac...@3.0.9.Final//org.jboss.jca.adapters.jdbc.BaseWrapperManagedConnection.prepareStatement(BaseWrapperManagedConnection.java:765)
at org.jboss.ironjac...@3.0.9.Final//org.jboss.jca.adapters.jdbc.WrappedConnection$4.produce(WrappedConnection.java:478)
at org.jboss.ironjac...@3.0.9.Final//org.jboss.jca.adapters.jdbc.WrappedConnection$4.produce(WrappedConnection.java:476)
at org.jboss.ironjac...@3.0.9.Final//org.jboss.jca.adapters.jdbc.SecurityActions.executeInTccl(SecurityActions.java:103)
at org.jboss.ironjac...@3.0.9.Final//org.jboss.jca.adapters.jdbc.WrappedConnection.prepareStatement(WrappedConnection.java:476)
at org.hi...@6.4.4.Final//org.hibernate.engine.jdbc.internal.StatementPreparerImpl$5.doPrepare(StatementPreparerImpl.java:153)
at org.hi...@6.4.4.Final//org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:183)
... 137 more

2025-05-27 14:55:24,216+0000 TRACE [org.jboss.jca.core.api.connectionmanager.ccm.CachedConnectionManager] (default task-205385) popped object: org.jboss.as.connector.deployers.ra.processors.CachedConnectionManagerSetupProcessor$CachedConnectionManagerSetupAction@38ad7344
2025-05-27 14:55:24,216+0000 TRACE [org.jboss.jca.core.api.connectionmanager.ccm.CachedConnectionManager] (default task-205385) popped object: org.jboss.as.connector.deployers.ra.processors.CachedConnectionManagerSetupProcessor$CachedConnectionManagerSetupAction@38ad7344
2025-05-27 14:55:24,216+0000 TRACE [org.jboss.jca.core.api.connectionmanager.ccm.CachedConnectionManager] (default task-205385) popped object: org.jboss.as.connector.deployers.ra.processors.CachedConnectionManagerSetupProcessor$CachedConnectionManagerSetupAction@796545dc
2025-05-27 14:55:24,216+0000 TRACE [org.jboss.jca.core.api.connectionmanager.ccm.CachedConnectionManager] (default task-205385) popped object: org.jboss.as.connector.deployers.ra.processors.CachedConnectionManagerSetupProcessor$CachedConnectionManagerSetupAction@796545dc
2025-05-27 14:55:24,262+0000 TRACE [org.jboss.jca.core.api.connectionmanager.ccm.CachedConnectionManager] (default task-205385) new stack for key: org.jboss.as.connector.deployers.ra.processors.CachedConnectionManagerSetupProcessor$CachedConnectionManagerSetupAction@796545dc
2025-05-27 14:55:24,262+0000 TRACE [org.jboss.jca.core.api.connectionmanager.ccm.CachedConnectionManager] (default task-205385) new stack for key: org.jboss.as.connector.deployers.ra.processors.CachedConnectionManagerSetupProcessor$CachedConnectionManagerSetupAction@796545dc
2025-05-27 14:55:24,262+0000 TRACE [org.jboss.jca.core.api.connectionmanager.ccm.CachedConnectionManager] (default task-205385) old stack for key: org.jboss.as.connector.deployers.ra.processors.CachedConnectionManagerSetupProcessor$CachedConnectionManagerSetupAction@796545dc
2025-05-27 14:55:24,262+0000 TRACE [org.jboss.jca.core.api.connectionmanager.ccm.CachedConnectionManager] (default task-205385) new stack for key: org.jboss.as.connector.deployers.ra.processors.CachedConnectionManagerSetupProcessor$CachedConnectionManagerSetupAction@38ad7344
2025-05-27 14:55:24,262+0000 TRACE [org.jboss.jca.core.api.connectionmanager.ccm.CachedConnectionManager] (default task-205385) old stack for key: org.jboss.as.connector.deployers.ra.processors.CachedConnectionManagerSetupProcessor$CachedConnectionManagerSetupAction@796545dc
2025-05-27 14:55:24,262+0000 TRACE [org.jboss.jca.core.api.connectionmanager.ccm.CachedConnectionManager] (default task-205385) new stack for key: org.jboss.as.connector.deployers.ra.processors.CachedConnectionManagerSetupProcessor$CachedConnectionManagerSetupAction@38ad7344
2025-05-27 14:55:24,263+0000 TRACE [org.jboss.jca.core.connectionmanager.TxConnectionManager] (default task-205385) Subject: null
2025-05-27 14:55:24,263+0000 TRACE [org.jboss.jca.core.connectionmanager.TxConnectionManager] (default task-205385) getManagedConnection interleaving=false , tx=null
2025-05-27 14:55:24,263+0000 TRACE [org.jboss.jca.core.connectionmanager.pool.strategy.OnePool] (default task-205385) getConnection(null, WrappedConnectionRequestInfo@675cdea5[userName=zFiMWJEmcc])
...
```



Stephen Sill II

unread,
May 27, 2025, 3:14:41 PM5/27/25
to WildFly
back when I had a similar problem, I can't remember which version of wildfly it was,  a couple years ago I ended up doing similar, for postgresql(cloud sql on gcp)

I run a .cli on container start and it does this

echo Configuring datasources
# configure db connection validation
/subsystem=datasources/data-source=myDS:write-attribute(name=validate-on-match, value=true)
/subsystem=datasources/data-source=myDS:write-attribute(name=use-fast-fail, value=false)
/subsystem=datasources/data-source=myDS:write-attribute(name=check-valid-connection-sql,value="SELECT 1")
/subsystem=datasources/data-source=myDS:write-attribute(name=max-pool-size,value=${MY_DB_POOL_SIZE})


And I've not had any issues since.   I'm currently on wildfly 36.0.1 without any issues.    I've only ever used postgresql so I can't say for mariadb specifically.

Mark Wright

unread,
May 27, 2025, 3:37:00 PM5/27/25
to WildFly
I was worried that would be the answer.  Doesn't it mean there's an extra database round trip for each query when "validate-on-match" is true?

Stephen Sill II

unread,
May 27, 2025, 3:46:14 PM5/27/25
to WildFly
I've not found it to be an issue that I'm aware of.  Having reliable connections and not having to restart my container to resolve has made it so I don't think about this problem anymore.   But I'd be open to hearing what the wildfly guys say.

Mark Wright

unread,
May 28, 2025, 8:44:12 AM5/28/25
to WildFly
I believe I've figured this out.  What my datasource validator config is missing is a an `exception-sorter` entry.  Looking at the IronJacamar source, it appears that without this, exceptions during connection use do not mark the connection as invalid.   I guess this makes sense - there must be some exceptions returned from the underlying JDBC driver that don't indicate that the connection is bad (SQL syntax error might be an example).

See here:

It looks like if I had MySQLExceptionSorter set as my exception sorter, my `SQL Error: 1220, SQLState: 08000` error would have been interpreted as a connection-closing event:

The periodic connection health validation considers *any* exception as a indication that the conneciton should be closed:

My error is occurring in a frequently-called healthcheck code path, so that conneciton never gets a chance to become "idle" and never gets removed from the pool by the periodic validator.

So, the answer is to be sure to set an ExceptionSorter when configuring your data source - for me:
```
<validation>
...
<exception-sorter class-name="org.jboss.jca.adapters.jdbc.extensions.mysql.MySQLExceptionSorter"/>
...
</validation>
```

Stephen Sill II

unread,
May 28, 2025, 9:13:36 AM5/28/25
to WildFly
that's good info!   thanks for sharing!

Aaron Ogburn

unread,
Jun 2, 2025, 9:00:54 PM6/2/25
to WildFly
For other db implementations, there are as you noted vendor specific exception-sorter classes provided that improve handling so the connection is closed and not returned to the pool after such exceptions.  For MariaDB  or other DBs that aren't covered by a provided vendor specific sorter class though, yaou could use the ListExceptionSorter to set your own fatal exception error codes as needed.  So if 210181 or anything else is the error code the MariaDB driver is often returning in this case (or add a comma separated list if multiple):


<validation>
    <check-valid-connection-sql>${env.DATABASE_CONNECTION_CHECK:SELECT 1;}</check-valid-connection-sql>
    <validate-on-match>false</validate-on-match>
    <background-validation>true</background-validation>
    <background-validation-millis>30000</background-validation-millis>
    <exception-sorter class-name="org.jboss.jca.adapters.jdbc.extensions.novendor.ListExceptionSorter">
        <config-property name="FatalExceptions">210181</>
    <exception-sorter/>
</validation>

If an SQLException is ever thrown during the validation attempt, that should result in the connection being invalidated as seen at https://github.com/ironjacamar/ironjacamar/blob/main/adapters/src/main/java/org/jboss/jca/adapters/jdbc/BaseWrapperManagedConnectionFactory.java#L1186.

But on match validation would always be the most foolproof way to ensure no bad connection ever slips through to your app for any errors. Also, if having a problem state revolving around a datasource pool, you could always try just flushing the datasource pool instead of having to fully restart the JVM.  For example, flushing via CLI:

 /subsystem=datasources/data-source=ExampleDS/:flush-idle-connection-in-pool
Reply all
Reply to author
Forward
0 new messages