IJ000152: Trying to return an unknown connection: org.jboss.jca.adapters.jdbc.jdk8.WrappedConnectionJDK8

M K

unread,

Feb 23, 2024, 4:20:38 AM2/23/24

to WildFly

Hi,

we have migrated our application from WildFly 10 to WildFly 30, Hibernate 5 to Hibernate 6.4 and Java 8 to Java 17 over the last year. We're seeing the following INFO message quite often in our server.logs:

INFO [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (default task-10) IJ000311: Throwable from unregister connection: java.lang.IllegalStateException: IJ000152: Trying to return an unknown connection: org.jboss.jca.adapters.jdbc.jdk8.WrappedConnectionJDK8@6ca4f174

I have attached the full stack trace.

Does anyone know what it is about, if it is a reason to worry, what our best course of action is?

Thank you very much in advance!

Greetings,

Manuel K.

stacktrace.txt

Ebuzer Taha Kanat

unread,

Feb 25, 2024, 12:28:10 PM2/25/24

to WildFly

My guess is that If your resource adapter is old and looking for a javax namespace transaction manager and there is no javax namespace at server side you can get this error look for resource adapter code.

23 Şubat 2024 Cuma tarihinde saat 12:20:38 UTC+3 itibarıyla M K şunları yazdı:

M K

unread,

Feb 26, 2024, 3:32:12 AM2/26/24

to WildFly

Hi,

thanks for your reply. I don't think it's applicable to our situation though:

We are not doing anything with resource adapters manually, it's all WildFly.
The exception is only logged sometimes, it's not a general problem.

Greetings

Manuel K.

Scott Marlow

unread,

Feb 26, 2024, 11:00:44 AM2/26/24

to M K, WildFly

I think your application is calling flush after the database connection has already been closed:

deployment.redacted.ear.redacted-ejb.jar//at.redacted.redacted.service.OneServiceBean.delete(OneServiceBean.java:369)

--
You received this message because you are subscribed to the Google Groups "WildFly" group.
To unsubscribe from this group and stop receiving emails from it, send an email to wildfly+u...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/wildfly/0f3d164f-c4e4-45b1-9637-250765cbac0dn%40googlegroups.com.

M K

unread,

Feb 26, 2024, 2:09:28 PM2/26/24

to WildFly

Hmm, I don't think so, at least we're not the ones closing the connection. All connections and transactions in this stack trace are container managed and the delete method just deletes an entity. It doesn't touch the connection.

What else could it be? Should I log or debug something?

Scott Marlow

unread,

Feb 26, 2024, 3:08:18 PM2/26/24

to M K, WildFly

On 2/26/24 14:09, M K wrote:

Hmm, I don't think so, at least we're not the ones closing the connection. All connections and transactions in this stack trace are container managed and the delete method just deletes an entity. It doesn't touch the connection.

Good point. Is this a problem that only occurs under (multiple requests on multiple threads) load? I think the error means that the database connection was already returned to the database connection pool which implies that the connection was already previously closed.

What else could it be? Should I log or debug something?

Sure, logging can help give context as to what might be going on. Take a look at https://docs.wildfly.org/30/Developer_Guide.html#troubleshooting for enabling TRACE logging for org.jboss.as.jpa (and setting TRACE for console-handler). Every Persistence/JPA call will be logged including some of the transaction interaction. Mostly, you will be interested in the org.jboss.as.jpa log output that precedes the unexpected "java.lang.IllegalStateException: IJ000152: Trying to return an unknown connection" and I think understanding why the database connection was already closed.

Scott

On Monday, February 26, 2024 at 5:00:44 PM UTC+1 Scott Marlow wrote:

I think your application is calling flush after the database connection has already been closed:

deployment.redacted.ear.redacted-ejb.jar//at.redacted.redacted.service.OneServiceBean.delete(OneServiceBean.java:369)

On Fri, Feb 23, 2024 at 4:20 AM M K <mko...@gmail.com> wrote:

Hi,

we have migrated our application from WildFly 10 to WildFly 30, Hibernate 5 to Hibernate 6.4 and Java 8 to Java 17 over the last year. We're seeing the following INFO message quite often in our server.logs:

INFO [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (default task-10) IJ000311: Throwable from unregister connection: java.lang.IllegalStateException: IJ000152: Trying to return an unknown connection: org.jboss.jca.adapters.jdbc.jdk8.WrappedConnectionJDK8@6ca4f174

I have attached the full stack trace.

Does anyone know what it is about, if it is a reason to worry, what our best course of action is?

Thank you very much in advance!

Greetings,

Manuel K.

--
You received this message because you are subscribed to the Google Groups "WildFly" group.
To unsubscribe from this group and stop receiving emails from it, send an email to wildfly+u...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/wildfly/0f3d164f-c4e4-45b1-9637-250765cbac0dn%40googlegroups.com.

--
You received this message because you are subscribed to the Google Groups "WildFly" group.
To unsubscribe from this group and stop receiving emails from it, send an email to wildfly+u...@googlegroups.com.

To view this discussion on the web visit https://groups.google.com/d/msgid/wildfly/27b0393d-7120-40ba-84dc-499f0e5cf445n%40googlegroups.com.

M K

unread,

Feb 26, 2024, 3:25:38 PM2/26/24

to WildFly

> Is this a problem that only occurs under (multiple requests on multiple threads) load?

No, load is not necessary for the problem to occur. But it definitely only occurs when a lot is happening in a single transaction and multiple EJBs are involved.

I'll try to get some meaningful logs and get back to you, thank you!

M K

unread,

Feb 27, 2024, 7:01:11 AM2/27/24

to WildFly

I enabled JPA and Hibernate logging, but I'm none the wiser:

2024-02-27 12:05:19,927 TRACE [org.hibernate.event.internal.AbstractFlushingEventListener] (default task-1) Executing flush
2024-02-27 12:05:19,927 TRACE [org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl] (default task-1) Starting after statement execution processing [AFTER_STATEMENT]
2024-02-27 12:05:19,927 TRACE [org.hibernate.resource.jdbc.internal.AbstractLogicalConnectionImplementor] (default task-1) LogicalConnection#afterStatement
2024-02-27 12:05:19,927 DEBUG [org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl] (default task-1) Initiating JDBC connection release from afterStatement
2024-02-27 12:05:19,927 TRACE [org.hibernate.resource.jdbc.internal.ResourceRegistryStandardImpl] (default task-1) Releasing JDBC resources
2024-02-27 12:05:19,927 DEBUG [org.hibernate.orm.jdbc.batch] (default task-1) PreparedStatementDetails did not contain PreparedStatement on #releaseStatements : update [...]
2024-02-27 12:05:19,927 TRACE [org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl] (default task-1) Starting after statement execution processing [AFTER_STATEMENT]
2024-02-27 12:05:19,927 TRACE [org.hibernate.resource.jdbc.internal.AbstractLogicalConnectionImplementor] (default task-1) LogicalConnection#afterStatement
2024-02-27 12:05:19,927 DEBUG [org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl] (default task-1) Initiating JDBC connection release from afterStatement
2024-02-27 12:05:19,927 INFO [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (default task-1) IJ000311: Throwable from unregister connection: java.lang.IllegalStateException: IJ000152: Trying to return an unknown connection: org.jboss.jca.adapters.jdbc.jdk8.WrappedConnectionJDK8@42bcc16b
2024-02-27 12:05:19,929 TRACE [org.hibernate.event.internal.AbstractFlushingEventListener] (default task-1) Post flush
2024-02-27 12:05:19,929 TRACE [org.jboss.as.jpa] (default task-1) flush took 74ms
2024-02-27 12:05:19,929 DEBUG [org.jboss.as.jpa] (default task-1) default task-1:transaction scoped EntityManager [redacted.ear/redacted-ejb.jar#redacted]: reuse entity manager session already in tx Local transaction (delegate=TransactionImple < ac, BasicAction: 0:ffffac1b7001:1f5a4bce:65ddc110:db1 status: ActionStatus.RUNNING >, owner=Local transaction context for provider JBoss JTA transaction provider)
2024-02-27 12:05:19,929 TRACE [org.hibernate.event.internal.AbstractFlushingEventListener] (default task-1) Flushing session
2024-02-27 12:05:19,929 DEBUG [org.hibernate.event.internal.AbstractFlushingEventListener] (default task-1) Processing flush-time cascades

Do you see anything? It's using the same EntityManager and Transaction before the exception and after the exception.

I also debugged the IronJacamar CachedConnectionManagerImpl class, and when the exception occurs a different connection is found in the map, so the connection to be unregistered is not removed and the exception is logged. I couldn't figure out how this happens, there are just too many calls.

Looking at the source I found a property that would suppress the exception and it seems to be this property:

https://docs.wildfly.org/30/wildscribe/subsystem/jca/cached-connection-manager/cached-connection-manager/index.html#attr-ignore-unknown-connections

Do you know anything about it?

Thanks in advance!

Greetings

Manuel

Scott Marlow

unread,

Feb 27, 2024, 9:30:59 AM2/27/24

to M K, WildFly

On 2/27/24 07:01, M K wrote:

I enabled JPA and Hibernate logging, but I'm none the wiser:

2024-02-27 12:05:19,927 TRACE [org.hibernate.event.internal.AbstractFlushingEventListener] (default task-1) Executing flush
2024-02-27 12:05:19,927 TRACE [org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl] (default task-1) Starting after statement execution processing [AFTER_STATEMENT]
2024-02-27 12:05:19,927 TRACE [org.hibernate.resource.jdbc.internal.AbstractLogicalConnectionImplementor] (default task-1) LogicalConnection#afterStatement
2024-02-27 12:05:19,927 DEBUG [org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl] (default task-1) Initiating JDBC connection release from afterStatement
2024-02-27 12:05:19,927 TRACE [org.hibernate.resource.jdbc.internal.ResourceRegistryStandardImpl] (default task-1) Releasing JDBC resources
2024-02-27 12:05:19,927 DEBUG [org.hibernate.orm.jdbc.batch] (default task-1) PreparedStatementDetails did not contain PreparedStatement on #releaseStatements : update [...]
2024-02-27 12:05:19,927 TRACE [org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl] (default task-1) Starting after statement execution processing [AFTER_STATEMENT]
2024-02-27 12:05:19,927 TRACE [org.hibernate.resource.jdbc.internal.AbstractLogicalConnectionImplementor] (default task-1) LogicalConnection#afterStatement
2024-02-27 12:05:19,927 DEBUG [org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl] (default task-1) Initiating JDBC connection release from afterStatement
2024-02-27 12:05:19,927 INFO [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (default task-1) IJ000311: Throwable from unregister connection: java.lang.IllegalStateException: IJ000152: Trying to return an unknown connection: org.jboss.jca.adapters.jdbc.jdk8.WrappedConnectionJDK8@42bcc16b
2024-02-27 12:05:19,929 TRACE [org.hibernate.event.internal.AbstractFlushingEventListener] (default task-1) Post flush
2024-02-27 12:05:19,929 TRACE [org.jboss.as.jpa] (default task-1) flush took 74ms
2024-02-27 12:05:19,929 DEBUG [org.jboss.as.jpa] (default task-1) default task-1:transaction scoped EntityManager [redacted.ear/redacted-ejb.jar#redacted]: reuse entity manager session already in tx Local transaction (delegate=TransactionImple < ac, BasicAction: 0:ffffac1b7001:1f5a4bce:65ddc110:db1 status: ActionStatus.RUNNING >, owner=Local transaction context for provider JBoss JTA transaction provider)
2024-02-27 12:05:19,929 TRACE [org.hibernate.event.internal.AbstractFlushingEventListener] (default task-1) Flushing session
2024-02-27 12:05:19,929 DEBUG [org.hibernate.event.internal.AbstractFlushingEventListener] (default task-1) Processing flush-time cascades

Do you see anything? It's using the same EntityManager and Transaction before the exception and after the exception.

I also debugged the IronJacamar CachedConnectionManagerImpl class, and when the exception occurs a different connection is found in the map, so the connection to be unregistered is not removed and the exception is logged. I couldn't figure out how this happens, there are just too many calls.

Does the "redacted" persistence unit definition (in persistence.xml) have any persistence unit hints specified that could impact connection release behavior?

You can also enable TRACE logging for org.jboss.jca which should show more information.

Scott

To view this discussion on the web visit https://groups.google.com/d/msgid/wildfly/7d2c0f19-a93f-420f-a22a-e0127dbb3affn%40googlegroups.com.

M K

unread,

Feb 27, 2024, 9:53:48 AM2/27/24

to WildFly

Thank you for your reply!

No, we don't have anything related to connections in our persistence.xml.

I already enabled the TRACE logging for org.jboss.jca after wring my reply, but did not gain any new insights. Here is the output:

The connection is registered here:

2024-02-27 12:22:57,638 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (default task-1) [TxConnectionListener@36c4cf49] registerConnection: org.jboss.jca.adapters.jdbc.jdk8.WrappedConnectionJDK8@54bf484 [size=1] ([org.jboss.jca.adapters.jdbc.jdk8.WrappedConnectionJDK8@54bf484])
2024-02-27 12:22:57,638 TRACE [org.jboss.jca.core.api.connectionmanager.ccm.CachedConnectionManager] (default task-1) registering connection from connection manager: org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl@1d77a1cc, connection : org.jboss.jca.adapters.jdbc.jdk8.WrappedConnectionJDK8@54bf484, key: org.jboss.as.connector.deployers.ra.processors.CachedConnectionManagerSetupProcessor$CachedConnectionManagerSetupAction@699b624e
2024-02-27 12:22:57,638 TRACE [org.jboss.jca.core.tracer.Tracer] (default task-1) IJTRACER-redactedDS-63bafac7-401-92-70126416719000-36c4cf49-54bf484-org.jboss.as.connector.deployers.ra.processors.CachedConnectionManagerSetupProcessor$CachedConnectionManagerSetupAction@699b624e

And unregistered here. There are no other connections registered in between!

2024-02-27 12:22:57,995 DEBUG [org.hibernate.id.enhanced.SequenceStructure] (default task-1) Sequence value obtained: 10558
2024-02-27 12:22:57,995 TRACE [org.hibernate.resource.jdbc.internal.ResourceRegistryStandardImpl] (default task-1) Releasing result set [SQLServerResultSet:1360]
2024-02-27 12:22:57,995 TRACE [org.hibernate.resource.jdbc.internal.ResourceRegistryStandardImpl] (default task-1) Closing result set [SQLServerResultSet:1360]
2024-02-27 12:22:57,995 TRACE [org.hibernate.resource.jdbc.internal.ResourceRegistryStandardImpl] (default task-1) Releasing statement [org.jboss.jca.adapters.jdbc.jdk8.WrappedPreparedStatementJDK8@1464acba]
2024-02-27 12:22:57,995 TRACE [org.hibernate.resource.jdbc.internal.ResourceRegistryStandardImpl] (default task-1) Closing prepared statement [org.jboss.jca.adapters.jdbc.jdk8.WrappedPreparedStatementJDK8@1464acba]
2024-02-27 12:22:57,995 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (default task-1) Lock: HeldByCurrentThread: No, Locked: No, HoldCount: 0, QueueLength: 0
2024-02-27 12:22:57,995 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (default task-1) Unlock: HeldByCurrentThread: Yes, Locked: Yes, HoldCount: 1, QueueLength: 0
2024-02-27 12:22:57,996 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (default task-1) Owner: Thread[default task-1,5,main]
2024-02-27 12:22:57,996 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (default task-1) Lock: HeldByCurrentThread: No, Locked: No, HoldCount: 0, QueueLength: 0
2024-02-27 12:22:57,996 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (default task-1) Unlock: HeldByCurrentThread: Yes, Locked: Yes, HoldCount: 1, QueueLength: 0
2024-02-27 12:22:57,996 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (default task-1) Owner: Thread[default task-1,5,main]
2024-02-27 12:22:57,996 TRACE [org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl] (default task-1) Starting after statement execution processing [AFTER_STATEMENT]
2024-02-27 12:22:57,996 TRACE [org.hibernate.resource.jdbc.internal.AbstractLogicalConnectionImplementor] (default task-1) LogicalConnection#afterStatement
2024-02-27 12:22:57,996 DEBUG [org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl] (default task-1) Initiating JDBC connection release from afterStatement
2024-02-27 12:22:57,996 TRACE [org.hibernate.resource.jdbc.internal.ResourceRegistryStandardImpl] (default task-1) Releasing JDBC resources
2024-02-27 12:22:57,996 DEBUG [org.hibernate.orm.jdbc.batch] (default task-1) PreparedStatementDetails did not contain PreparedStatement on #releaseStatements : insert into [...]
2024-02-27 12:22:57,996 TRACE [org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl] (default task-1) Starting after statement execution processing [AFTER_STATEMENT]
2024-02-27 12:22:57,996 TRACE [org.hibernate.resource.jdbc.internal.AbstractLogicalConnectionImplementor] (default task-1) LogicalConnection#afterStatement
2024-02-27 12:22:57,996 DEBUG [org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl] (default task-1) Initiating JDBC connection release from afterStatement
2024-02-27 12:22:57,996 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (default task-1) Lock: HeldByCurrentThread: No, Locked: No, HoldCount: 0, QueueLength: 0
2024-02-27 12:22:57,996 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (default task-1) Unlock: HeldByCurrentThread: Yes, Locked: Yes, HoldCount: 1, QueueLength: 0
2024-02-27 12:22:57,996 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (default task-1) Owner: Thread[default task-1,5,main]
2024-02-27 12:22:57,996 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (default task-1) Lock: HeldByCurrentThread: No, Locked: No, HoldCount: 0, QueueLength: 0
2024-02-27 12:22:57,996 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (default task-1) Unlock: HeldByCurrentThread: Yes, Locked: Yes, HoldCount: 1, QueueLength: 0
2024-02-27 12:22:57,996 TRACE [org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory] (default task-1) Owner: Thread[default task-1,5,main]
2024-02-27 12:22:57,996 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (default task-1) connectionClosed called mc=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@25ae62a6
2024-02-27 12:22:57,996 TRACE [org.jboss.jca.core.api.connectionmanager.ccm.CachedConnectionManager] (default task-1) unregistering connection from connection manager: org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl@1d77a1cc, connection: org.jboss.jca.adapters.jdbc.jdk8.WrappedConnectionJDK8@54bf484, key: org.jboss.as.connector.deployers.ra.processors.CachedConnectionManagerSetupProcessor$CachedConnectionManagerSetupAction@699b624e
2024-02-27 12:22:57,996 TRACE [org.jboss.jca.core.tracer.Tracer] (default task-1) IJTRACER-redactedDS-63bafac7-401-95-70126775236799-36c4cf49-54bf484-org.jboss.as.connector.deployers.ra.processors.CachedConnectionManagerSetupProcessor$CachedConnectionManagerSetupAction@699b624e
2024-02-27 12:22:57,996 INFO [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (default task-1) IJ000311: Throwable from unregister connection: java.lang.IllegalStateException: IJ000152: Trying to return an unknown connection: org.jboss.jca.adapters.jdbc.jdk8.WrappedConnectionJDK8@54bf484
[...]
2024-02-27 12:22:57,998 TRACE [org.jboss.jca.core.tracer.Tracer] (default task-1) IJTRACER-redactedDS-63bafac7-401-41-70126777019300-36c4cf49-54bf484-
2024-02-27 12:22:57,998 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (default task-1) [TxConnectionListener@36c4cf49] unregisterConnection: 0 handles left ([])
2024-02-27 12:22:57,998 TRACE [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (default task-1) isManagedConnectionFree=false mc=org.jboss.jca.adapters.jdbc.local.LocalManagedConnection@25ae62a6
2024-02-27 12:22:57,998 DEBUG [org.hibernate.event.internal.AbstractSaveEventListener] (default task-1) Generated identifier: 10539, using strategy: org.hibernate.id.enhanced.SequenceStyleGenerator
2024-02-27 12:22:57,998 TRACE [org.hibernate.event.internal.AbstractSaveEventListener] (default task-1) Saving [model.Entity#10539]
2024-02-27 12:22:57,998 TRACE [org.hibernate.engine.internal.Cascade] (default task-1) Processing cascade ACTION_PERSIST for: model.Entity

Greetings

Manuel

Scott Marlow

unread,

Feb 27, 2024, 1:06:18 PM2/27/24

to M K, WildFly

On 2/27/24 09:53, M K wrote:

Thank you for your reply!

No, we don't have anything related to connections in our persistence.xml.

I already enabled the TRACE logging for org.jboss.jca after wring my reply, but did not gain any new insights. Here is the output:

I wonder if Hibernate ORM is using the JTA transaction. Does the persistence.xml specify transaction-type="RESOURCE_LOCAL" or transaction-type="JTA"?

To view this discussion on the web visit https://groups.google.com/d/msgid/wildfly/f940801c-e536-43f0-aba8-1e0055c86da6n%40googlegroups.com.

M K

unread,

Feb 28, 2024, 1:00:56 AM2/28/24

to WildFly

It's not specified at all, that probably means JTA. I have attached our persistence.xml so you can check if there's anything suspect.

Greetings

Manuel

persistence.xml

Scott Marlow

unread,

Feb 28, 2024, 5:22:55 AM2/28/24

to M K, WildFly

On Wed, Feb 28, 2024, 1:01 AM M K <mko...@gmail.com> wrote:

It's not specified at all, that probably means JTA. I have attached our persistence.xml so you can check if there's anything suspect.

I will look at the attachment later.

The default is JTA as per the WildFly JPA/Persistence container code that parses the persistence.xml

https://github.com/wildfly/wildfly/blob/main/jpa/subsystem/src/main/java/org/jboss/as/jpa/puparser/PersistenceUnitXmlParser.java#L147

Scott

To view this discussion on the web visit https://groups.google.com/d/msgid/wildfly/58c84486-9da3-4544-83a4-752d894e67e7n%40googlegroups.com.

Scott Marlow

unread,

Feb 28, 2024, 10:07:31 AM2/28/24

to M K, WildFly

On 2/28/24 01:00, M K wrote:

It's not specified at all, that probably means JTA. I have attached our persistence.xml so you can check if there's anything suspect.

I don't see anything the in the persistence.xml that seems related.

I looked again at the first exception call stack that you attached which I'm pasting part of here because I think we should explore why flush was called:

"

INFO [org.jboss.jca.core.connectionmanager.listener.TxConnectionListener] (default task-10) IJ000311: Throwable from unregister connection: java.lang.IllegalStateException: IJ000152: Trying to return an unknown connection: org.jboss.jca.adapters.jdbc.jdk8.WrappedConnectionJDK8@6ca4f174

"

You mentioned that the OneServiceBean.delete() is deleting something. I'm not concerned about the delete as much as whether you can confirm that line 369 in OneServiceBean.java is indeed calling EntityManager.flush() as the exception call stack shows.

I think the flush call should work but I am concerned that there could be a bug that leads to the database connection being closed too early. Could you try again with the latest WildFly that includes Hibernate ORM 6.4.4.Final in case you are hitting a bug that has already been fixed. Download link would be https://github.com/wildfly/wildfly/releases/download/31.0.1.Final/wildfly-31.0.1.Final.zip

I tried recreating the failure locally with a modified WildFly unit test that calls persist + flush a few times but could not. https://github.com/scottmarlow/wildfly/tree/recreate_flush_connectionalreadyclosed contains my attempt to recreate with "mvn install -Dtest=org.jboss.as.test.integration.jpa.basic.entitymanagerfactorytest.EntityManagerFactoryTestCase".

Please let me know if the later WildFly release helps so I can delete my test branch and others know the issue was resolved.

If the problem recreates with WildFly 31.0.1.Final, we will need to create a tracking https://issues.redhat.com/browse/WFLY issue for this problem.

Scott

To view this discussion on the web visit https://groups.google.com/d/msgid/wildfly/58c84486-9da3-4544-83a4-752d894e67e7n%40googlegroups.com.

M K

unread,

Feb 28, 2024, 10:28:39 AM2/28/24

to WildFly

Thank you Scott!

> I'm not concerned about the delete as much as whether you can confirm that line 369 in OneServiceBean.java is indeed calling EntityManager.flush() as the exception call stack shows.

Yes, I can confirm that EntityManager.flush() is being called explicitly.

> Could you try again with the latest WildFly that includes Hibernate ORM 6.4.4.Final in case you are hitting a bug that has already been fixed.

We are already using Hibernate ORM 6.4.4.Final with our WildFly 30.0.1.Final. Do you still think it makes sense to test it with WildFly 31.0.1.Final? It would take some time to get our application running on it.

Did you see the configuration attribute I found: https://docs.wildfly.org/30/wildscribe/subsystem/jca/cached-connection-manager/cached-connection-manager/index.html#attr-ignore-unknown-connections

Do you know why it exists? It would suppress the log message, but of course getting to the root of the problem seems more sensible.

Thank you!

Greetings

Manuel

Scott Marlow

unread,

Feb 28, 2024, 11:03:05 AM2/28/24

to M K, WildFly

On 2/28/24 10:28, M K wrote:

Thank you Scott!

> I'm not concerned about the delete as much as whether you can confirm that line 369 in OneServiceBean.java is indeed calling EntityManager.flush() as the exception call stack shows.

Yes, I can confirm that EntityManager.flush() is being called explicitly.

Thank you.

> Could you try again with the latest WildFly that includes Hibernate ORM 6.4.4.Final in case you are hitting a bug that has already been fixed.

We are already using Hibernate ORM 6.4.4.Final with our WildFly 30.0.1.Final. Do you still think it makes sense to test it with WildFly 31.0.1.Final? It would take some time to get our application running on it.

No need to update at this point then.

Did you see the configuration attribute I found: https://docs.wildfly.org/30/wildscribe/subsystem/jca/cached-connection-manager/cached-connection-manager/index.html#attr-ignore-unknown-connections

Do you know why it exists?

This goes back several years but from I recall there were some applications that cached (pooled/managed) database connections and reused those database connections in different application threads. IronJacamar made changes to detect that usage and enforce causing an application failure when detecting that a pooled/managed database connection was returned to the pool more than once (e.g. the first time when the database transaction completes possibly and the second via some application library code or a WildFly system component like Hibernate ORM). That was kind of the original intent from what I recall.

It would suppress the log message, but of course getting to the root of the problem seems more sensible.

+100

Can you want to start a https://issues.redhat.com/browse/WFLY issue for this failure? There should be a forum link field that could be set to this forum discussion (https://groups.google.com/d/msgid/wildfly/f2e42c23-3444-4412-ba57-74803ed64446n%40googlegroups.com).

Please do respond with the WFLY issue link here.

Thank you,

Scott

Thank you!

Greetings

Manuel

If the problem recreates with WildFly 31.0.1.Final?, we will need to create a tracking https://issues.redhat.com/browse/WFLY issue for this problem.

Scott

To view this discussion on the web visit https://groups.google.com/d/msgid/wildfly/f2e42c23-3444-4412-ba57-74803ed64446n%40googlegroups.com.

M K

unread,

Feb 29, 2024, 3:34:27 AM2/29/24

to WildFly

Thank you very much for your help Scott! I have created the Jira issue https://issues.redhat.com/browse/WFLY-19082 accordingly.

Greetings

Manuel

Scott Marlow

unread,

Mar 8, 2024, 1:07:48 PM3/8/24

to WildFly

I seem to be having trouble commenting on the jira currently, not sure why. I'll add my comment below:

I think that the other application activity could be related but I am not sure of how.

I wonder if the problem would still occur with the org.jboss.jca.core.api.connectionmanager.ccm.CachedConnectionManager disabled via use-ccm="false". It may help to understand if the problem goes away with that set or not. If it doesn't help, we should definitely revert the datasource settings. If it does help, we can explain more of the impact of that setting.

I think the setting would like something like:

"

<datasource jndi-name="java:jboss/datasources/ExampleDS" pool-name="ExampleDS" enabled="true" use-java-context="true" use-ccm="false" statistics-enabled="${wildfly.datasources.statistics-enabled:${wildfly.statistics-enabled:false}}">
<connection-url>jdbc:h2:mem:test;DB_CLOSE_DELAY=-1;DB_CLOSE_ON_EXIT=FALSE;MODE=${wildfly.h2.compatibility.mode:REGULAR}</connection-url>
<driver>h2</driver>
<security user-name="sa" password="sa"/>
</datasource>
"

Scott

Fernando Pulupa Pasquel

unread,

Mar 22, 2024, 11:26:48 AM3/22/24

to WildFly

Hi!

I have had the same problem. I migrated from wildfly 26.1.3 to wildfly 30.0.1 Following the explanation in the thread, for my part I use a flush when creating

The lines where the error is marked are the following

The abstract

The service.

Indeed, when you put use-ccm="false" the error does not appear.

My question is: Does making this change affect transactions? Does it work as well as in version 26 wildfly?

Scott Marlow

unread,

Mar 22, 2024, 1:30:46 PM3/22/24

to Fernando Pulupa Pasquel, WildFly

Hi Fernando,

Please consider adding a text copy of what you stated as a comment on https://issues.redhat.com/browse/WFLY-19082 as your feedback does sound like you are hitting the same problem. Or you could create a separate https://issues.redhat.com/browse/WFLY issue and we could link the issues together.

From your callstack, it looks like your code was on the EntityManager#persist(entity) call at the time the problem was observed.

> Indeed, when you put use-ccm="false" the error does not appear.

> My question is: Does making this change affect transactions? Does it work as well as in version 26 wildfly?

Good to hear that clue. There are certain application cases that require the default of use-ccm="true". For now, let's figure out the cause of the problem and see if we can address it once we understand the cause.

Could you change back to use-ccm"true" (which is the default when you don't specify it) and also try the following additional settings:

1. Update your WildFly config (e.g. standalone.xml or whatever your config is that you use) to set debug in the "jca" subsystem config, so change from <cached-connection-manager/> to <cached-connection-manager debug="true"/> I think this will show exception call stack of any leaked database connection which might be interesting.

2. Also in your WildFly config, update your datasource to set spy="true".

3. Also in your WildFly config, update the console logging from INFO to TRACE:
<console-handler name="CONSOLE">
<level name="TRACE"/>
4. Also add to the logging section, the following logger category:
<logger category="jboss.jdbc.spy">
<level name="TRACE"/>

</logger>

As mentioned before, it would be helpful to show us the server.log section that precedes the failure.

If you create a WFLY issue, just add the results there.

Scott

To view this discussion on the web visit https://groups.google.com/d/msgid/wildfly/7ceff33f-f44a-41f8-97a6-c12d4c83c3a0n%40googlegroups.com.

Fernando Pulupa Pasquel

unread,

Mar 22, 2024, 2:12:49 PM3/22/24

to WildFly

Hi!

I have followed your instructions, I attached my log

I have also uploaded it at https://issues.redhat.com/browse/WFLY-19082

Greetings.

server.log

Reply all

Reply to author

Forward