-->
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: c3p0 threads waiting for connections
PostPosted: Mon Feb 23, 2009 8:24 am 
Newbie

Joined: Wed Oct 29, 2008 8:54 am
Posts: 13
hello, we just started our production setup with real beta user traffic, and i'm facing regular (1-2 times a day) lock-ups of c3p0, with stack traces like these:

Code:
INFO   | jvm 1    | 2009/02/22 20:40:49 | "pool-11-thread-1" prio=10 tid=0x094d2c00 nid=0x212 in Object.wait() [0xaeed1000..0xaeed1db0]
INFO   | jvm 1    | 2009/02/22 20:40:49 |    java.lang.Thread.State: WAITING (on object monitor)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at java.lang.Object.wait(Native Method)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   - waiting on <0xb90acc20> (a com.mchange.v2.resourcepool.BasicResourcePool)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at com.mchange.v2.resourcepool.BasicResourcePool.awaitAvailable(BasicResourcePool.java:1315)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at com.mchange.v2.resourcepool.BasicResourcePool.prelimCheckoutResource(BasicResourcePool.java:557)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   - locked <0xb90acc20> (a com.mchange.v2.resourcepool.BasicResourcePool)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at com.mchange.v2.resourcepool.BasicResourcePool.checkoutResource(BasicResourcePool.java:477)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutPooledConnection(C3P0PooledConnectionPool.java:525)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource.getConnection(AbstractPoolBackedDataSource.java:128)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.connection.C3P0ConnectionProvider.getConnection(C3P0ConnectionProvider.java:35)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:417)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:144)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.jdbc.JDBCContext.connection(JDBCContext.java:119)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.transaction.JDBCTransaction.begin(JDBCTransaction.java:57)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.impl.SessionImpl.beginTransaction(SessionImpl.java:1326)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at my.SessionUtil.updateSessionLifetime(SessionUtil.java:117)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at my.SessionLifetimeTaskHandler.doTask(SessionLifetimeTaskHandler.java:32)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at it.gotoandplay.smartfoxserver.util.scheduling.Scheduler.executeTasks(Scheduler.java:305)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   - locked <0xb92c3fc8> (a java.util.LinkedList)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at it.gotoandplay.smartfoxserver.util.scheduling.Scheduler.run(Scheduler.java:223)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at java.lang.Thread.run(Unknown Source)

INFO   | jvm 1    | 2009/02/22 20:40:49 | "btpool0-8" prio=10 tid=0x08d95400 nid=0x1bc in Object.wait() [0xafcaa000..0xafcaaf30]
INFO   | jvm 1    | 2009/02/22 20:40:49 |    java.lang.Thread.State: WAITING (on object monitor)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at java.lang.Object.wait(Native Method)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       - waiting on <0xb90acc20> (a com.mchange.v2.resourcepool.BasicResourcePool)   
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at com.mchange.v2.resourcepool.BasicResourcePool.awaitAvailable(BasicResourcePool.java:1315)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at com.mchange.v2.resourcepool.BasicResourcePool.prelimCheckoutResource(BasicResourcePool.java:557)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   - locked <0xb90acc20> (a com.mchange.v2.resourcepool.BasicResourcePool)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at com.mchange.v2.resourcepool.BasicResourcePool.checkoutResource(BasicResourcePool.java:477)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutPooledConnection(C3P0PooledConnectionPool.java:525)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource.getConnection(AbstractPoolBackedDataSource.java:128)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at org.hibernate.connection.C3P0ConnectionProvider.getConnection(C3P0ConnectionProvider.java:35)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:417)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:144)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.jdbc.AbstractBatcher.prepareQueryStatement(AbstractBatcher.java:139)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1560)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at org.hibernate.loader.Loader.doQuery(Loader.java:661)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:224)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.loader.Loader.doList(Loader.java:2144)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2028)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.loader.Loader.list(Loader.java:2023)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:393)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.hql.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:338)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:172)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1121)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.impl.QueryImpl.list(QueryImpl.java:79)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.impl.AbstractQueryImpl.uniqueResult(AbstractQueryImpl.java:780)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at my.BuddyHelper.isAnyBuddyOnline(BuddyHelper.java:87)

INFO   | jvm 1    | 2009/02/22 20:40:49 | "btpool0-5" prio=10 tid=0x08d9b800 nid=0x1b9 in Object.wait() [0xafd9d000..0xafd9ddb0]
INFO   | jvm 1    | 2009/02/22 20:40:49 |    java.lang.Thread.State: WAITING (on object monitor)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at java.lang.Object.wait(Native Method)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       - waiting on <0xb90acc20> (a com.mchange.v2.resourcepool.BasicResourcePool)   
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at com.mchange.v2.resourcepool.BasicResourcePool.awaitAvailable(BasicResourcePool.java:1315)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at com.mchange.v2.resourcepool.BasicResourcePool.prelimCheckoutResource(BasicResourcePool.java:557)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   - locked <0xb90acc20> (a com.mchange.v2.resourcepool.BasicResourcePool)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at com.mchange.v2.resourcepool.BasicResourcePool.checkoutResource(BasicResourcePool.java:477)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutPooledConnection(C3P0PooledConnectionPool.java:525)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource.getConnection(AbstractPoolBackedDataSource.java:128)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at org.hibernate.connection.C3P0ConnectionProvider.getConnection(C3P0ConnectionProvider.java:35)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:417)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:144)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.jdbc.AbstractBatcher.prepareQueryStatement(AbstractBatcher.java:139)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1560)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at org.hibernate.loader.Loader.doQuery(Loader.java:661)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:224)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.loader.Loader.doList(Loader.java:2144)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2028)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.loader.Loader.list(Loader.java:2023)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:393)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.hql.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:338)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:172)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1121)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.impl.QueryImpl.list(QueryImpl.java:79)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.impl.AbstractQueryImpl.uniqueResult(AbstractQueryImpl.java:780)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at my.BuddyHelper.isAnyBuddyOnline(BuddyHelper.java:87)

INFO   | jvm 1    | 2009/02/22 20:40:49 | "btpool0-4" prio=10 tid=0x08d9ac00 nid=0x1b8 in Object.wait() [0xafdee000..0xafdef130]
INFO   | jvm 1    | 2009/02/22 20:40:49 |    java.lang.Thread.State: WAITING (on object monitor)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at java.lang.Object.wait(Native Method)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       - waiting on <0xb90acc20> (a com.mchange.v2.resourcepool.BasicResourcePool)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at com.mchange.v2.resourcepool.BasicResourcePool.awaitAvailable(BasicResourcePool.java:1315)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at com.mchange.v2.resourcepool.BasicResourcePool.prelimCheckoutResource(BasicResourcePool.java:557)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       - locked <0xb90acc20> (a com.mchange.v2.resourcepool.BasicResourcePool)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at com.mchange.v2.resourcepool.BasicResourcePool.checkoutResource(BasicResourcePool.java:477)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutPooledConnection(C3P0PooledConnectionPool.java:525)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource.getConnection(AbstractPoolBackedDataSource.java:128)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at org.hibernate.connection.C3P0ConnectionProvider.getConnection(C3P0ConnectionProvider.java:35)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:417)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:144)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at org.hibernate.jdbc.AbstractBatcher.prepareQueryStatement(AbstractBatcher.java:139)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1560)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at org.hibernate.loader.Loader.doQuery(Loader.java:661)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:224)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at org.hibernate.loader.Loader.doList(Loader.java:2144)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2028)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at org.hibernate.loader.Loader.list(Loader.java:2023)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:393)

INFO   | jvm 1    | 2009/02/22 20:40:49 | "btpool0-0" prio=10 tid=0x08e4fc00 nid=0x1b4 in Object.wait() [0xb00c9000..0xb00c9f30]
INFO   | jvm 1    | 2009/02/22 20:40:49 |    java.lang.Thread.State: WAITING (on object monitor)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at java.lang.Object.wait(Native Method)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   - waiting on <0xb90acc20> (a com.mchange.v2.resourcepool.BasicResourcePool)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at com.mchange.v2.resourcepool.BasicResourcePool.awaitAvailable(BasicResourcePool.java:1315)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at com.mchange.v2.resourcepool.BasicResourcePool.prelimCheckoutResource(BasicResourcePool.java:557)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   - locked <0xb90acc20> (a com.mchange.v2.resourcepool.BasicResourcePool)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at com.mchange.v2.resourcepool.BasicResourcePool.checkoutResource(BasicResourcePool.java:477)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool.checkoutPooledConnection(C3P0PooledConnectionPool.java:525)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource.getConnection(AbstractPoolBackedDataSource.java:128)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.connection.C3P0ConnectionProvider.getConnection(C3P0ConnectionProvider.java:35)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:417)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:144)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.jdbc.AbstractBatcher.prepareQueryStatement(AbstractBatcher.java:139)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1560)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.loader.Loader.doQuery(Loader.java:661)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:224)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.loader.Loader.doList(Loader.java:2144)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2028)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at org.hibernate.loader.Loader.list(Loader.java:2023)
INFO   | jvm 1    | 2009/02/22 20:40:49 |       at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:393)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.hql.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:338)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:172)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1121)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.impl.QueryImpl.list(QueryImpl.java:79)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at org.hibernate.impl.AbstractQueryImpl.uniqueResult(AbstractQueryImpl.java:780)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at my.BuddyHelper.isAnyBuddyOnline(BuddyHelper.java:87)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at my.InfoServlet.doGet(InfoServlet.java:75)
INFO   | jvm 1    | 2009/02/22 20:40:49 |   at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)


the hibernate.cfg.xml snippet for c3p0

Code:
       <property name="hibernate.c3p0.min_size">5</property>
       <property name="hibernate.c3p0.max_size">20</property>
       <property name="hibernate.c3p0.acquire_increment">2</property>
        <property name="hibernate.c3p0.max_statements">0</property>
        <property name="hibernate.c3p0.timeout">25200</property>
        <property name="hibernate.c3p0.idle_test_period">14400</property>
        <property name="hibernate.c3p0.preferredTestQuery">select 1;</property>


(there is no c3p0.properties file)


Hibernate version:
3.3.1

c3p0 version:
0.9.1.2

Name and version of the database you are using:
mySQL 5.0.45


i'm trying to reproduce this on our dev-system, but so far no luck.

i'm not sure i understand whats going on - the max number of connections does not seem to be reached.

side note - because of an apparent class loader problem (that i'm working on), i'm having 2 HibernateUtil singleton instances in 2 parts of the system, instead of one. the problem always appears in the same one.

side question - i'm currently using openSession, (how) would getCurrentSession make a difference?

any hint is greatly appreciated!

best,
thomas


Top
 Profile  
 
 Post subject:
PostPosted: Mon Feb 23, 2009 10:51 am 
Newbie

Joined: Wed Oct 29, 2008 8:54 am
Posts: 13
solved - stupid ressource leak; i was watching the "wrong" singleton.

have to fix this ASAP.

thx anyway ;-)


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.