DBCP connection not closed?

[Jacobjob Koster]

Hi all,

Is this a possible bug in MMBase code, that forgets to close the database connection?
Got it from a production environment of one of our customers, running MMBase 1.9.5 with Java 1.6.0_21. Don't know exactly which Tomcat version.

DBCP object created 2011-07-23 23:06:38 by the following code was never closed:
java.lang.Exception
at org.apache.tomcat.dbcp.dbcp.AbandonedTrace.setStackTrace(AbandonedTrace.java:157)
at org.apache.tomcat.dbcp.dbcp.AbandonedObjectPool.borrowObject(AbandonedObjectPool.java:76)
at org.apache.tomcat.dbcp.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:95)
at org.apache.tomcat.dbcp.dbcp.BasicDataSource.getConnection(BasicDataSource.java:540)
at org.mmbase.storage.implementation.database.DatabaseStorageManager.getActiveConnection(DatabaseStorageManager.java:219)
at org.mmbase.storage.implementation.database.DatabaseStorageManager.createKey(DatabaseStorageManager.java:360)
at org.mmbase.storage.implementation.database.DatabaseStorageManager.createWithoutEvent(DatabaseStorageManager.java:995)
at org.mmbase.storage.implementation.database.DatabaseStorageManager.create(DatabaseStorageManager.java:1017)
at org.mmbase.module.core.MMObjectBuilder.insert(MMObjectBuilder.java:636)
at org.mmbase.module.core.MMObjectNode.insert(MMObjectNode.java:371)
at org.mmbase.module.core.MMObjectBuilder.safeInsert(MMObjectBuilder.java:1081)
at org.mmbase.module.core.MMObjectNode.insert(MMObjectNode.java:383)
at org.mmbase.bridge.implementation.BasicCloud.afterCommit(BasicCloud.java:1231)
at org.mmbase.bridge.implementation.BasicNode.commit(BasicNode.java:534)
at com.finalist.portlets.responseform.ResponseFormPortlet.saveResponseForm(ResponseFormPortlet.java:218)
at com.finalist.portlets.responseform.ResponseFormPortlet.processView(ResponseFormPortlet.java:146)
at com.finalist.cmsc.portlets.CmscPortlet.processAction(CmscPortlet.java:139)

and
DBCP object created 2011-07-23 23:01:00 by the following code was never closed:
java.lang.Exception
at org.apache.tomcat.dbcp.dbcp.AbandonedTrace.setStackTrace(AbandonedTrace.java:157)
at org.apache.tomcat.dbcp.dbcp.AbandonedObjectPool.borrowObject(AbandonedObjectPool.java:76)
at org.apache.tomcat.dbcp.dbcp.PoolingDataSource.getConnection(PoolingDataSource.java:95)
at org.apache.tomcat.dbcp.dbcp.BasicDataSource.getConnection(BasicDataSource.java:540)
at org.mmbase.storage.implementation.database.DatabaseStorageManager.getActiveConnection(DatabaseStorageManager.java:219)
at org.mmbase.storage.implementation.database.DatabaseStorageManager.executeQuery(DatabaseStorageManager.java:3543)
at org.mmbase.storage.search.implementation.database.BasicQueryHandler.getNodes(BasicQueryHandler.java:88)
at org.mmbase.core.util.StorageConnector.getRawNodes(StorageConnector.java:488)
at org.mmbase.core.util.StorageConnector.getNodes(StorageConnector.java:525)
at org.mmbase.bridge.implementation.BasicNodeManager.getList(BasicNodeManager.java:413)
at org.mmbase.bridge.implementation.BasicNode.getRelatedNodes(BasicNode.java:900)
at org.mmbase.bridge.implementation.BasicNode.getRelatedNodes(BasicNode.java:850)
at org.mmbase.bridge.implementation.BasicNode.getRelatedNodes(BasicNode.java:897)
at org.mmbase.bridge.util.AbstractNode.getRelatedNodes(AbstractNode.java:586)
at org.mmbase.bridge.util.AbstractNode.getRelatedNodes(AbstractNode.java:578)
at org.mmbase.applications.crontab.builders.NodeCronEntry.isActive(NodeCronEntry.java:71)
at org.mmbase.applications.crontab.CronEntry.mustRun(CronEntry.java:352)
at org.mmbase.applications.crontab.CronDaemon.run(CronDaemon.java:356)
at org.mmbase.applications.crontab.CronDaemon$1.run(CronDaemon.java:266)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)

Thanks,
Jacobjob

[Nico Klasens]

Hello Jacobjob,

I have not touched mmbase code for a while, but it probably did not change that much in this part of the code. These stacktraces show a real common path. You would run out of connections really quickly if it was a bug.

Most of the times I have seen this error when the server had an OutOfMemory earlier. The DBCP pool does not like that and gets confused. The pool usually recovers when the java process recovers from the OOM.

Just depending how busy your system is, I would recommend to turn off  logAbandoned="true". Generating a stacktrace for each query (borrowing a connection) is expensive.

Regards
Nico

2011/7/25 Jacobjob Koster <jaco...@finalist.nl>

--
You received this message because you are subscribed to the Google Groups "mmbase-discuss" group.
To post to this group, send email to mmbase-...@googlegroups.com.
To unsubscribe from this group, send email to mmbase-discus...@googlegroups.com.
For more options, visit this group at http://groups.google.com/group/mmbase-discuss?hl=en.

[Jacobjob Koster]

Hi Nico,

Nice to hear from you! Your statement makes sense. It wouldn't be very
common that these code has such mistakes in it.
I'll check even better for Out of Memory-s in the production logs.

Cheers,
Jacobjob