I have a few places in my code that does not properly close database connections. This gets periodically reported in catalina.out with messages like: org.apache.commons.dbcp.AbandonedTrace$AbandonedObjectException: DBCP object created 2013-08-29 02:55:00 by the following code was never closed. These messages are repeated for other unclosed connections for various times over the next few hours.
By looking at other info in catalina.out, I can see that these messages were printed to catalina.out around 7:40AM. I've seen other instances where these are reported in catalina.out the next day. My question is, what determines when these messages get printed to catalina.out? How does that work exactly?
DBCP is open source so you can look at the code yourself and find out. The way DBCP checks for abandoned connections is a form of cooperative garbage collection. When a connection is checked out from the connection pool, it first checks for abandoned connections and cleans them up.
So if no new connections have been requested for a few hours, abandoned connections will not be removed. And when (eg at start of a business day) a connection is requested from the pool it will first remove all abandoned connections.
If you look at the code of
borrowObject(), depending on the configuration it will callremoveAbandoned(), which in turn will revoke and log abandoned connections.