-->
These old forums are deprecated now and set to read-only. We are waiting for you on our new forums!
More modern, Discourse-based and with GitHub/Google/Twitter authentication built-in.

All times are UTC - 5 hours [ DST ]



Forum locked This topic is locked, you cannot edit posts or make further replies.  [ 2 posts ] 
Author Message
 Post subject: Database connections are not returning to connection pool
PostPosted: Tue Sep 07, 2004 4:32 am 
Newbie

Joined: Mon Mar 01, 2004 12:27 am
Posts: 3
Location: KL, Malaysia
Problem : Dear All,

We are using JBoss3.2.3, Hibernate2.1.4 and mysql4.0.18.
Now our application was at Production.
I assume each hibernate session will get one datasource connection from pool and whenever session is closed the datasource connection will returned to pool. (Please Highlight if my assumption is wrong)
Normally our application is working fine. But some times after closing session, connections are not returning back to Connection Pool and non returned connections are keep growing in 2-3 hrs. So once non-returned connections size was grown to 20+ then the next request(session) is not getting connection from connection pool , it just using the
non-returned connection and we are getting SQL Exception i.e; SQL Error: 0 SQLState: 08S01 (since it is using the old (bad)connection).
I have gone through the forum to check for related queries, but I was unlucky ..

Your help is highly appreciable ..

Note: Connections InUse is growing when multiple requests(sessions) are issued at same time and only one connection(session was closing) was returning back. And once after this scenario normal request connections also not returning back (some times only).

Below I am providing configuration and Exception details .

Thanks in advance,
Kavuri.

Hibernate version: 2.1.4

Mapping documents:

<property name="dialect">net.sf.hibernate.dialect.MySQLDialect</property>
<property name="show_sql">false</property>
<property name="use_outer_join">true</property>
<property name="connection.isolation">4</property>
<property name="transaction.factory_class">net.sf.hibernate.transaction.JTATransactionFactory</property>
<property name="transaction.manager_lookup_class">net.sf.hibernate.transaction.JBossTransactionManagerLookup</property>
<property name="jta.UserTransaction">UserTransaction</property>

Data Source Configuration :

<!-- pooling enhancement -->
<blocking-timeout-millis>500</blocking-timeout-millis>
<idle-timeout-minutes>5</idle-timeout-minutes>
<min-pool-size>10</min-pool-size>
<max-pool-size>50</max-pool-size>
<check-valid-connection-sql>SELECT 1</check-valid-connection-sql>

<!-- MySQL specific enhancement -->
<connection-property name="autoReconnect">true</connection-property>
<connection-property name="autoReconnectForPools">true</connection-property>
<connection-property name="useNewIO">true</connection-property>


Code between sessionFactory.openSession() and session.close():

openSession :
Session s = (Session) session.get();
if (s == null) {
try {
s = sessionFactory.openSession();
session.set(s);
} catch (Exception e) {
throw new HibernateException(e.getMessage());
}
}
// check if session is not connected
if (!s.isConnected()) {
logger.warn("Reconnecting hibernate session...");
s.reconnect();
}
level++;
return s;
closeSession :
public static void closeSession() {
level--;
if (level <= 0) {
Session s = (Session) session.get();
if (s != null && s.isOpen()) {
session.set(null);
try {
s.flush();
s.close();

} catch (HibernateException e) {
logger.warn(e.getMessage());
}
}
}
}

Full stack trace of exception that occurs:

First Session :

2004-09-07 10:24:42,461 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] Getting connection from pool [InUse/Available/Max]: [1/10/500]
2004-09-07 10:24:52,290 INFO [com.mlifestyle.etud.ejb.session.facade.vim.VIMFacadeBean] Initializing worker....
2004-09-07 10:24:52,792 INFO [com.mlifestyle.etud.ejb.session.facade.vim.VIMWorker] Waiting for response...
2004-09-07 10:24:52,796 INFO
[com.mlifestyle.etud.ejb.session.facade.vim.VIMWorker] isLogonSuccessful()
2004-09-07 10:24:52,796 INFO [com.mlifestyle.etud.ejb.session.facade.vim.VIMWorker] Logon is successful...
2004-09-07 10:24:52,797 INFO [com.mlifestyle.vim.pdu.BalanceEnquiryRequest] pdu:
2004-09-07 10:24:52,797 INFO [com.mlifestyle.etud.ejb.session.facade.vim.VIMWorker] Waiting for response...
2004-09-07 10:25:20,260 INFO
Second Session: (First one was still in the process)
[com.mlifestyle.etud.ejb.session.facade.dealer.salesstaff.SalesStaffFacadeBean] Find all topup record for sales staff : 64751516
Second session was closed, but datasource connection was not returned back.
2004-09-07 10:25:20,261 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] supplying ManagedConnection from pool: org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@3c03e1
2004-09-07 10:25:20,261 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] Getting connection from pool [InUse/Available/Max]: [2/10/500]
2004-09-07 10:25:21,182 INFO
Third Session: (Still the first session was in process)
[com.mlifestyle.etud.ejb.session.facade.dealer.owner.OwnerFacadeBean] Find dealer branch data by Dealer Id where dealer id : 00643
2004-09-07 10:25:21,184 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] supplying ManagedConnection from pool: org.jboss.resource.adapter.jdbc.local.LocalManagedConnection@1f622fa
2004-09-07 10:25:21,184 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] Getting connection from pool [InUse/Available/Max]: [3/10/500]
2004-09-07 10:25:21,191 INFO [com.mlifestyle.etud.ejb.session.facade.dealer.owner.OwnerFacadeBean] Size of dealerBranchList is : 4
2004-09-07 10:25:21,193 INFO [com.mlifestyle.etud.ejb.session.facade.dealer.owner.OwnerFacadeBean] <NEW> Find dealer sales shifts for Dealer: 00643
2004-09-07 10:25:21,200 INFO [com.mlifestyle.etud.ejb.session.facade.dealer.owner.OwnerFacadeBean] <NEW> Find dealer sales staff for Dealer: 00643
2004-09-07 10:25:21,206 INFO [com.mlifestyle.etud.ejb.session.facade.dealer.owner.OwnerFacadeBean] <NEW> Find dealer staff for Dealer: 00643
The last i.e; Third session was closed, but connection was not returned back to pool.
2004-09-07 10:25:22,802 ERROR [com.mlifestyle.etud.ejb.session.facade.vim.VIMFacadeBean] Balance checking error: No response from VICG!
The First session was closed and the datasource connection was returned back. But mean time there is 2 non returned connections ...
2004-09-07 10:25:22,804 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] putting ManagedConnection back into pool
2004-09-07 10:25:22,804 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] Returning connection to pool [InUse/Available/Max]: [2/10/500]

This value(InUse) is keep growing and causing for a connection time out Exception.

2004-09-07 11:34:58,263 WARN [net.sf.hibernate.util.JDBCExceptionReporter] SQL Error: 0, SQLState: 08S01
2004-09-07 11:34:58,263 ERROR [net.sf.hibernate.util.JDBCExceptionReporter] Communication link failure: java.net.SocketException, underlying cause: Connection timed out

** BEGIN NESTED EXCEPTION **

java.net.SocketException
MESSAGE: Connection timed out

STACKTRACE:

java.net.SocketException: Connection timed out
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:183)
at java.io.BufferedInputStream.read1(BufferedInputStream.java:222)
at java.io.BufferedInputStream.read(BufferedInputStream.java:277)
at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:1385)
at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:1532)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:1923)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1163)
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:1272)
at com.mysql.jdbc.Connection.execSQL(Connection.java:2236)
at com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:1555)
at org.jboss.resource.adapter.jdbc.WrappedPreparedStatement.executeQuery(WrappedPreparedStatement.java:304)
at net.sf.hibernate.impl.BatcherImpl.getResultSet(BatcherImpl.java:87)
at net.sf.hibernate.loader.Loader.getResultSet(Loader.java:800)
at net.sf.hibernate.loader.Loader.doQuery(Loader.java:189)
at net.sf.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:133)
at net.sf.hibernate.loader.Loader.loadEntity(Loader.java:836)
at net.sf.hibernate.loader.Loader.loadEntity(Loader.java:856)
at net.sf.hibernate.loader.EntityLoader.load(EntityLoader.java:59)
at net.sf.hibernate.loader.EntityLoader.load(EntityLoader.java:51)
at net.sf.hibernate.persister.EntityPersister.load(EntityPersister.java:419)
at net.sf.hibernate.impl.SessionImpl.doLoad(SessionImpl.java:2113)
at net.sf.hibernate.impl.SessionImpl.doLoadByClass(SessionImpl.java:1987)
at net.sf.hibernate.impl.SessionImpl.get(SessionImpl.java:1923)
at com.mlifestyle.etud.util.ETUDHibernateLoginModule.getUsersPassword(ETUDHibernateLoginModule.java:127)
at org.jboss.security.auth.spi.UsernamePasswordLoginModule.login(UsernamePasswordLoginModule.java:150)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)
at org.apache.coyote.tomcat4.CoyoteAdapter.service(CoyoteAdapter.java:197)
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:781)
at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.processConnection(Http11Protocol.java:549)
at org.apache.tomcat.util.net.TcpWorkerThread.runIt(PoolTcpEndpoint.java:605)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:677)
at java.lang.Thread.run(Thread.java:534)


** END NESTED EXCEPTION **


2004-09-07 11:34:58,267 WARN [net.sf.hibernate.util.JDBCExceptionReporter] SQL Error: 0, SQLState: 08S01
2004-09-07 11:34:58,267 ERROR [net.sf.hibernate.util.JDBCExceptionReporter] Communication link failure: java.net.SocketException, underlying cause: Connection timed out

** BEGIN NESTED EXCEPTION **

java.net.SocketException
MESSAGE: Connection timed out

STACKTRACE:

java.net.SocketException: Connection timed out
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:129)
at java.io.BufferedInputStream.fill(BufferedInputStream.java:183)
at java.io.BufferedInputStream.read1(BufferedInputStream.java:222)
at java.io.BufferedInputStream.read(BufferedInputStream.java:277)
at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:1385)
at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:1532)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:1923)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1163)
at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:1272)
at com.mysql.jdbc.Connection.execSQL(Connection.java:2236)
at com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:1555)
at org.jboss.resource.adapter.jdbc.WrappedPreparedStatement.executeQuery(WrappedPreparedStatement.java:304)

Name and version of the database we are using: MySql 4.0.18 Max

Application Server : JBoss3.2.3

Debug level Hibernate log excerpt:


Top
 Profile  
 
 Post subject:
PostPosted: Wed Sep 08, 2004 10:30 pm 
Newbie

Joined: Mon Mar 01, 2004 12:27 am
Posts: 3
Location: KL, Malaysia
Is there any thing I confused you all ????


Top
 Profile  
 
Display posts from previous:  Sort by  
Forum locked This topic is locked, you cannot edit posts or make further replies.  [ 2 posts ] 

All times are UTC - 5 hours [ DST ]


You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum

Search for:
© Copyright 2014, Red Hat Inc. All rights reserved. JBoss and Hibernate are registered trademarks and servicemarks of Red Hat, Inc.