Hibernate version: 3.1.3 - C3P0-0.9.1pre6

Name and version of the database you are using: Oracle 8

config:


Hi,

I'm a little confused about what is actually happening here. Basically i need to know what can cause the following scenario which occurred on a production system:

Tomcat stopped responding to http requests, so I had to terminate it. First I took a thread dump.

It turns out that every http processing thread was either stuck in "com.mchange.v2.resourcepool.BasicResourcePool.awaitAvailable(BasicResourcePool.java:998)" or waiting on another thread that was.

I am told that the DBA has restricted max connections (on the the database) to 10.

Unfortunately I cannot reproduce the problem locally (I assume it is a result of high load over time which I cannot adequately reproduce) and did not have the hibernate/c3p0 logs on DEBUG.

As far as I can see, sessions are being closed (via a finally block in all servlets and threads).

Any help is appreciated.

oh, and is there a way to get a dump of the connection pooling status by request? I'd like to run a dump every 10 minutes via a thread instead of turning on DEBUG logging (for fear of log bloat).

thx

Wanton,

For better status information (and better-ness in general), please upgrade to c3p0-0.9.1-pre9. If you are running in a 1.5.x VM (or an environment with a JMX infrastructure around), you can now monitor Connection pools, and their underlying thread pools, in real time. (You can use jconsole in JDK 1.5.x, or whatever JMX agent you like.)

Or you can query every 10 minutes and dump to a log if you like. (See the javadocs to com.mchange.v2.c3p0.PooledDataSource information for the relevant methods.)

It does sound like what you are observing is pool exhaustion -- i.e. maxPoolSize Connections are checked out, but not promptly checked back in, causing clients to wait indefinitely for new Connections. If there is a Connection leak you may be missing, you can debug it in c3p0-0.9.1-pre9 as follows:

1) set the c3p0 property unreturnedConnectionTimeout, which will force c3p0 to kill leaked Connections that aren't checked in after a certain period of time (and then acquire replacements from the database);

2) set debugUnreturnedConnectionStackTraces to true. If this parameter is set, the stack trace associated with all Connection checkouts will be cached, and when a Connection has to be destroyed for outliving unreturnedConnectionTimeout, the stack trace that checked it out will be dumped -- at INFO level -- to logs. This lets you see exactly what check-out in your app potentially fails to check back in. (Only use this parameter while debugging, as it harms performance.)

If it is something else besides a Connection leak, information about active and pending thread pool tasks and their stack traces are likely to be useful. You can get this any time via c3p0's PooledDataSource.sampleThreadPoolStatus(), via direct method calls, or via JMX.

Please note that c3p0 configuration properties besides a very few handled by hibernate cannot, for the moment, be set in your hibernate configuration. You'll need to set up a c3p0.properties file (in the ordinary property file format) at the top of your CLASSPATH for c3p0.unreturnedConnectionTimeout and c3p0. debugUnreturnedConnectionStackTraces. (Always check the configuration dump, logged by new c3p0 DataSources at INFO level on pool initialization, to verify that the configuration takes as you expect.)

Good luck, and let me know how this works out for you!

smiles,
Steve

Oh, I just reread the original post...

If your DBA is restricting your app to a maximum of 10 Connections, maxPoolSize (hibernate.c3p0.max_size) should be set at no more than 10. This could be the source of your problem.

Given your settings, c3p0 expects to be able to acquire 150 Connections. If Connection acquisitions fail with an Exception beyond your database max of 10, that would cause c3p0 to spin its wheels trying uselessly to get Connections, but c3p0 should deal.

But if Connection acquisitions beyond your limit of 10 don't fail promptly, but freeze, then...

1) c3p0 tries to acquire new Connections;

2) Load causes c3p0 to try to expand the pool beyond 10 Connections;

3) Connection acquisition tasks are handed to the thread pool, and then freeze indefinitely, as the database refuses to supply new Connections, and old Connections aren't closed, they are pooled;

4) All thread pool threads are occupied by frozen tasks, preventing Connection check-in (which is handled asynchronously be the thread pool).

Anyway, the moral of this story is... don't set c3p0.maxPoolSize (hibernate.c3p0.max_size) to a value greater than the number of Connections the pool can actually acquire.

smiles,
Steve

done.


i can't find this in the docs
what is a recommended value?
is it in seconds or millis?
is this still useful without 'debugUnreturnedConnectionStackTraces'?


.. yeah but i can't reproduce it in development/testing servers :(


This sounds like what i want to do (for now) but how do i aquire an instance of PooledDataSource?

Basically i want a report on open connections and connection age every 10 minutes so that i can identify when an orphan connection is being created. i'd love the stack trace (ala debugUnreturnedConnectionStackTraces) but can't afford the performance hit on a production system.

thx again.
paul.

... and why do all the 'count' methods of sessionFactory.getStatistics() return 0? surely i have had one open session/connection/transaction?

stats.getConnectCount()=0
stats.getSessionOpenCount()=0
stats.getSessionCloseCount()=0
stats.getTransactionCount()=0
stats.getSuccessfulTransactionCount()=0
stats.getPrepareStatementCount()=0
stats.getCloseStatementCount()=0
stats.getOptimisticFailureCount()=0
stats.getFlushCount()=0

Wanton,

Look at the docs that ship with c3p0-0.9.0-pre9. You'll find unreturnedConnectionTimeout and debugUnreturnedConnectionStackTraces documented there. (The docs on the web are still 0.9.0.4... but the 0.9.1 series is now quite mature. I think I'll replace the webdocs soon.)

You'll also find a trick, "Using C3P0Registry to get a reference to a DataSource". Basically, you can use a static methods of C3P0Registry to find any c3p0 PooledDataSource active in your VM. If you only have one DataSource around, just use C3P0Registry.getPooledDataSources(), and expect to find a Set with one element (that you can safely cast to a PooledDataSource).

All that said, did you try setting maxPoolSize (hibernate.c3p0.max_size) to your DBA-set limit of 10 or less? I know this might be smaller than what it ideally should be, but if the DBA has restricted you to 10 simultaneous connections, having the pool try to check out more than that is only gonna cause you grief.

Good luck!

Steve

I have set maxpoolsize to 10 and informed the DBA that he was being a nazi with his connection limit ;)

thanks for the tip on the docs .. that should have been obvious.

C3P0Registry is my saviour, i'll get to using it right away.

THANKS FOR THE PATIENCE AND INFORMED RESPONSES!!

ONE LAST QUESTION ;)

in my development c3p0.properties i have set

problem is, i cannot reproduce this outside of a production environment getting hammered for weeks on end. :(

you mentioned that 'debugUnreturnedConnectionStackTraces' was expensive, but is it not only expensive in the case that there is an unreturned connection? if this is the case, i would argue that it is safe for production as it will only affect performance if there is a major issue that i must know about (connection leak).

what do you think?

ps. i have learnt a lot about c3p0 in the last 48 hours :D

paul.

nvm.. i just re-read your first post. thx.

Wanton,

Well, "expensive" is a matter of degree, and I haven't benchmarked the cost of debugUnreturnedConnectionStackTraces precisely. As the developer of a Connection pool, I automatically cringe over any operation that will occur synchronously during Connection check-out or check-in. After all, the point of a Connection pool is to reduce the apparent cost to clients of these operations.

But... there's expensive and expensive. debugUnreturnedConnectionStackTraces is expensive compared to many in-memory Java operations, but likely to be inexpensive compared to most database operations. The cost of c3p0.debugUnreturnedConnectionStackTraces=true is the cost of constructing and storing an Exception (with its embeded stack trace) during Connection check-out. Again, I haven't benchmarked, and even if I had, your JVM, database, and network is different than mine. I don't think the performance degradation is likely to be huge, if you turn this on in a production system for a while. If your clients typically do significant databse work with your Connections, the cost of the database activity is likely to overwhelm the cost of caching the Exception, making the extra cost close to negligible.

But, the performance cost is with every Connection checkout, not just the bad, unreturned ones. The pool doesn't know which Connections will eventually be leaked, so it has to store a stack trace for every Connection checked out, just in case it won't be checked back in.

I wish it weren't so!

Steve

yeah, i had a dumb thought that it would only create the stack trace when the connection went bad ... but then realised from your original post that a stack trace was created on every check out.

an idea for c3p0:
stack trace creation (exception) is a relatively expensive java procedure and the goal here is to cache something that will allow us to track down the code which creates the unterminated session ..... maybe there are other things that you can cache .. possibly during the lifecycle of the connection that will also lead developers back to the cause .. like a couple of the executed statements in a string?

Wanton,

Re: caching less expensive hints -- it's a good idea. I'm trying to close out the c3p0-0.9.1 series now, so I'm not sure I'll get to it immediately. But I'll try to make that possible at some point.

smiles,
Steve

np, just a thought .. hopefully i have little-no need in the future ;)