0005637: Double Close on mysql pooled connection datasource

Viewing Issue Simple Details [ Jump to Notes ]

[ View Advanced ] [ Issue History ] [ Print ]

Category

Severity

Reproducibility

Date Submitted

Last Update

0005637

[Resin]

minor

always

01-23-14 17:03

09-11-14 14:26

Reporter

alex

View Status

public

Assigned To

ferg

Priority

normal

Resolution

fixed

Status

closed

Product Version

4.0.38

Summary

0005637: Double Close on mysql pooled connection datasource

Description

rep by: Srikanth Pulikonda

ManagedConnectionImpl closes poolConn followed by closing driverConn.

MySQL's poolConn closes the underlying driverConn.

driverConn in non-autocommit mode attempts a rollback and checks if the underlying Connection Impl was already closed throwing exception if it already was.

Since mysql's poolConn already had closed the underlying ConnectionImpl error is thrown.

Additional Information

[14-01-23 15:58:32.234] {Simple Daemon} opening JDBC connection
[14-01-23 15:58:32.375] {Simple Daemon} create: ManagedPoolItem[jdbc/LMDB,0,ManagedConnectionImpl](active:0, total:0)
[14-01-23 15:58:32.378] {Simple Daemon} allocate ManagedPoolItem[jdbc/LMDB,0,ManagedConnectionImpl]
[14-01-23 15:58:32.378] {Simple Daemon} current autocommit status: false
iterating: Thu Jan 23 15:58:32 PST 2014
[14-01-23 15:58:32.380] {Simple Daemon} commit
[14-01-23 15:58:32.380] {Simple Daemon} committed JDBC Connection
[14-01-23 15:58:32.380] {Simple Daemon} aggressively releasing JDBC connection
[14-01-23 15:58:32.380] {Simple Daemon} releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
[14-01-23 15:58:32.383] {Simple Daemon} idle ManagedPoolItem[jdbc/LMDB,0,ManagedConnectionImpl]
[14-01-23 15:58:43.384] {Simple Daemon} opened session at timestamp: 5695576159780864
[14-01-23 15:58:43.384] {Simple Daemon} begin
[14-01-23 15:58:43.384] {Simple Daemon} opening JDBC connection
[14-01-23 15:58:43.385] {Simple Daemon} connection pool destroy ManagedPoolItem[jdbc/LMDB,0,null]
[14-01-23 15:58:43.385] {Simple Daemon} destroy ManagedConnectionImpl[jdbc/LMDB.d0.0]
java.lang.Exception: Stack trace
    at java.lang.Thread.dumpStack(Thread.java:1266)
    at com.mysql.jdbc.ConnectionImpl.realClose(ConnectionImpl.java:4723)
    at com.mysql.jdbc.ConnectionImpl.close(ConnectionImpl.java:1625)
    at com.mysql.jdbc.jdbc2.optional.MysqlPooledConnection.close(MysqlPooledConnection.java:204)
    at com.mysql.jdbc.jdbc2.optional.JDBC4MysqlPooledConnection.close(JDBC4MysqlPooledConnection.java:57)
    at com.caucho.sql.ManagedConnectionImpl.destroy(ManagedConnectionImpl.java:916)
    at com.caucho.env.dbpool.ManagedPoolItem.destroy(ManagedPoolItem.java:1167)
    at com.caucho.env.dbpool.ConnectionPool.allocateIdleConnection(ConnectionPool.java:959)
    at com.caucho.env.dbpool.ConnectionPool.allocatePoolConnection(ConnectionPool.java:839)
    at com.caucho.env.dbpool.ConnectionPool.allocateConnection(ConnectionPool.java:740)
    at com.caucho.env.dbpool.ConnectionPool.allocateConnection(ConnectionPool.java:714)
    at com.caucho.sql.UserDataSource.getConnection(UserDataSource.java:75)
    at com.caucho.sql.DBPool.getConnection(DBPool.java:808)
    at org.hibernate.connection.DatasourceConnectionProvider.getConnection(DatasourceConnectionProvider.java:92)
    at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:446)
    at org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:167)
    at org.hibernate.jdbc.JDBCContext.connection(JDBCContext.java:160)
    at org.hibernate.transaction.JDBCTransaction.begin(JDBCTransaction.java:81)
    at org.hibernate.impl.SessionImpl.beginTransaction(SessionImpl.java:1473)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:616)
    at org.hibernate.context.ThreadLocalSessionContext$TransactionProtectionWrapper.invoke(ThreadLocalSessionContext.java:345)
    at $Proxy51.beginTransaction(Unknown Source)
    at com.lmsample.hibernate.HibernateSessionFactory.getSession(HibernateSessionFactory.java:57)
    at com.lmsample.hibernate.HibernateSessionFactory.getSession(HibernateSessionFactory.java:44)
    at com.lmsample.SimpleTest$SimpleDaemon.run(SimpleTest.java:36)
[14-01-23 15:58:43.389] {Simple Daemon} com.mysql.jdbc.exceptions.jdbc4.MySQLNonTransientConnectionException: No operations allowed after connection closed.
                           at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
                           at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:57)
                           at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
                           at java.lang.reflect.Constructor.newInstance(Constructor.java:532)
                           at com.mysql.jdbc.Util.handleNewInstance(Util.java:411)
                           at com.mysql.jdbc.Util.getInstance(Util.java:386)
                           at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1015)
                           at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:989)
                           at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:975)
                           at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:920)
                           at com.mysql.jdbc.ConnectionImpl.throwConnectionClosedException(ConnectionImpl.java:1299)
                           at com.mysql.jdbc.ConnectionImpl.checkClosed(ConnectionImpl.java:1291)
                           at com.mysql.jdbc.ConnectionImpl.rollback(ConnectionImpl.java:5017)
                           at com.mysql.jdbc.jdbc2.optional.ConnectionWrapper.rollback(ConnectionWrapper.java:794)
                           at com.mysql.jdbc.jdbc2.optional.ConnectionWrapper.close(ConnectionWrapper.java:836)
                           at com.mysql.jdbc.jdbc2.optional.ConnectionWrapper.close(ConnectionWrapper.java:466)
                           at com.mysql.jdbc.jdbc2.optional.JDBC4ConnectionWrapper.close(JDBC4ConnectionWrapper.java:75)
                           at com.caucho.sql.ManagedConnectionImpl.destroy(ManagedConnectionImpl.java:926)
                           at com.caucho.env.dbpool.ManagedPoolItem.destroy(ManagedPoolItem.java:1167)
                           at com.caucho.env.dbpool.ConnectionPool.allocateIdleConnection(ConnectionPool.java:959)
                           at com.caucho.env.dbpool.ConnectionPool.allocatePoolConnection(ConnectionPool.java:839)
                           at com.caucho.env.dbpool.ConnectionPool.allocateConnection(ConnectionPool.java:740)
                           at com.caucho.env.dbpool.ConnectionPool.allocateConnection(ConnectionPool.java:714)
                           at com.caucho.sql.UserDataSource.getConnection(UserDataSource.java:75)
                           at com.caucho.sql.DBPool.getConnection(DBPool.java:808)
                           at org.hibernate.connection.DatasourceConnectionProvider.getConnection(DatasourceConnectionProvider.java:92)
                           at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:446)
                           at org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:167)
                           at org.hibernate.jdbc.JDBCContext.connection(JDBCContext.java:160)
                           at org.hibernate.transaction.JDBCTransaction.begin(JDBCTransaction.java:81)
                           at org.hibernate.impl.SessionImpl.beginTransaction(SessionImpl.java:1473)
                           at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
                           at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
                           at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
                           at java.lang.reflect.Method.invoke(Method.java:616)
                           at org.hibernate.context.ThreadLocalSessionContext$TransactionProtectionWrapper.invoke(ThreadLocalSessionContext.java:345)
                           at $Proxy51.beginTransaction(Unknown Source)
                           at com.lmsample.hibernate.HibernateSessionFactory.getSession(HibernateSessionFactory.java:57)
                           at com.lmsample.hibernate.HibernateSessionFactory.getSession(HibernateSessionFactory.java:44)
                           at com.lmsample.SimpleTest$SimpleDaemon.run(SimpleTest.java:36)

[14-01-23 15:58:43.398] {Simple Daemon} create: ManagedPoolItem[jdbc/LMDB,2,ManagedConnectionImpl](active:0, total:0)
[14-01-23 15:58:43.398] {Simple Daemon} allocate ManagedPoolItem[jdbc/LMDB,2,ManagedConnectionImpl]
[14-01-23 15:58:43.398] {Simple Daemon} current autocommit status: false
iterating: Thu Jan 23 15:58:43 PST 2014

Attached Files

Relationships

There are no notes attached to this issue.

Issue History
Date Modified	Username	Field	Change
01-23-14 17:03	alex	New Issue
09-11-14 14:26	ferg	Assigned To	=> ferg
09-11-14 14:26	ferg	Status	new => closed
09-11-14 14:26	ferg	Resolution	open => fixed
09-11-14 14:26	ferg	Fixed in Version	=> 4.0.41

Mantis 1.0.0rc3[^]

27 total queries executed.
25 unique queries executed.