One transaction and 2 connections enlisted for the same data source

classic Classic list List threaded Threaded
2 messages Options
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

One transaction and 2 connections enlisted for the same data source

mihalcea_vlad
This post was updated on .
Hi,

In one use case we identified two connections being enlisted for the same XS transaction.

Shouldn't always be one connection/datasource/transaction?

In the attached log file we can see the following transaction running 696E74577342746D00000000036D01640000001A

Since connections are released after each statement (the default Hibernate JTA setting) we manage to recycle the first enlisted connection:

 trying to recycle a NOT_ACCESSIBLE connection of an XAPool of resource core-datasource with 2 connection(s) (1 still available)
2014-05-14 09:24:50,455 DEBUG [http-bio-8085-exec-10]: b.t.r.c.XAPool             - current transaction GTRID is [696E74577342746D00000000036D01640000001A]
2014-05-14 09:24:50,455 DEBUG [http-bio-8085-exec-10]: b.t.r.c.XAPool             - found a connection in NOT_ACCESSIBLE state: a JdbcPooledConnection from datasource core-datasource in state NOT_ACCESSIBLE with usage count 0 wrapping org.postgresql.xa.PGXAConnection@6e5ef727

Up to line 144 it works as described when we get the following scanrio:

2014-05-14 09:24:50,465 DEBUG [http-bio-8085-exec-10]: b.t.r.c.XAPool             - no NOT_ACCESSIBLE connection enlisted in this transaction
2014-05-14 09:24:50,465 DEBUG [http-bio-8085-exec-10]: b.t.r.c.XAPool             - getting a IN_POOL connection from an XAPool of resource core-datasource with 2 connection(s) (1 still available)
2014-05-14 09:24:50,465 DEBUG [http-bio-8085-exec-10]: b.t.r.c.XAPool             - waiting for IN_POOL connections count to be > 0, currently is 1
2014-05-14 09:24:50,465 DEBUG [http-bio-8085-exec-10]: b.t.r.c.XAPool             - found IN_POOL connection a JdbcPooledConnection from datasource core-datasource in state IN_POOL with usage count 0 wrapping org.postgresql.xa.PGXAConnection@c1fb3d5 from an XAPool of resource core-datasource with 2 connection(s) (1 still available)
2014-05-14 09:24:50,465 DEBUG [http-bio-8085-exec-10]: b.t.r.j.PoolingDataSource  - acquired connection from a PoolingDataSource containing an XAPool of resource core-datasource with 2 connection(s) (0 still available)
2014-05-14 09:24:50,465 DEBUG [http-bio-8085-exec-10]: b.t.r.ResourceRegistrar    - XAResource org.postgresql.xa.PGXAConnection@c1fb3d5 belongs to a JdbcPooledConnection from datasource core-datasource in state ACCESSIBLE with usage count 1 wrapping org.postgresql.xa.PGXAConnection@c1fb3d5 that itself belongs to a PoolingDataSource containing an XAPool of resource core-datasource with 2 connection(s) (0 still available)
2014-05-14 09:24:50,465 DEBUG [http-bio-8085-exec-10]: b.t.i.XAResourceManager    - creating new branch with a Bitronix XID [696E74577342746D00000000036D01640000001A : 696E74577342746D00000000036D05020000001C]
2014-05-14 09:24:50,487 DEBUG [http-bio-8085-exec-10]: b.t.r.j.PoolingDataSource  - acquiring connection from a PoolingDataSource containing an XAPool of resource core-datasource with 2 connection(s) (0 still available)
2014-05-14 09:24:50,487 DEBUG [http-bio-8085-exec-10]: b.t.r.c.XAPool             - trying to recycle a NOT_ACCESSIBLE connection of an XAPool of resource core-datasource with 2 connection(s) (0 still available)
2014-05-14 09:24:50,488 DEBUG [http-bio-8085-exec-10]: b.t.r.c.XAPool             - current transaction GTRID is [696E74577342746D00000000036D01640000001A]
2014-05-14 09:24:50,488 DEBUG [http-bio-8085-exec-10]: b.t.r.c.XAPool             - found a connection in NOT_ACCESSIBLE state: a JdbcPooledConnection from datasource core-datasource in state NOT_ACCESSIBLE with usage count 0 wrapping org.postgresql.xa.PGXAConnection@c1fb3d5
2014-05-14 09:24:50,488 DEBUG [http-bio-8085-exec-10]: b.t.r.c.XAPool             - 1 xa resource(s) created by connection in NOT_ACCESSIBLE state: a JdbcPooledConnection from datasource core-datasource in state NOT_ACCESSIBLE with usage count 0 wrapping org.postgresql.xa.PGXAConnection@c1fb3d5
2014-05-14 09:24:50,488 DEBUG [http-bio-8085-exec-10]: b.t.r.c.XAPool             - NOT_ACCESSIBLE xa resource GTRID: 696E74577342746D00000000036D01640000001A
2014-05-14 09:24:50,488 DEBUG [http-bio-8085-exec-10]: b.t.r.c.XAPool             - NOT_ACCESSIBLE xa resource's GTRID matched this transaction's GTRID, recycling it
2014-05-14 09:24:50,488 DEBUG [http-bio-8085-exec-10]: b.t.r.c.XAPool             - found NOT_ACCESSIBLE connection a JdbcPooledConnection from datasource core-datasource in state NOT_ACCESSIBLE with usage count 0 wrapping org.postgresql.xa.PGXAConnection@c1fb3d5 from an XAPool of resource core-datasource with 2 connection(s) (0 still available)
2014-05-14 09:24:50,488 DEBUG [http-bio-8085-exec-10]: b.t.r.j.PoolingDataSource  - acquired connection from a PoolingDataSource containing an XAPool of resource core-datasource with 2 connection(s) (0 still available)

It didn't find a NOT_ACCESSIBLE connection to recycle so it enlisted a new connection: org.postgresql.xa.PGXAConnection@c1fb3d5

Now we have two connections enlisted for the same transaction:

org.postgresql.xa.PGXAConnection@6e5ef727
org.postgresql.xa.PGXAConnection@c1fb3d5

Has anyone encountered this behaviour?

This project dependencies are:

<btm.version>2.1.3</btm.version>
<spring.version>3.1.3.RELEASE</spring.version>
<hibernate.version>4.1.6.Final</hibernate.version>

Vlad

btm.txt
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: One transaction and 2 connections enlisted for the same data source

mihalcea_vlad
This project dependencies are:

<btm.version>2.1.3</btm.version>
<spring.version>3.1.3.RELEASE</spring.version>
<hibernate.version>4.1.6.Final</hibernate.version>

Thanks
Loading...