[ https://issues.apache.org/jira/browse/DBCP-381?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Phil Steitz closed DBCP-381. ---------------------------- > Threads BLOCKED on stress tests > ------------------------------- > > Key: DBCP-381 > URL: https://issues.apache.org/jira/browse/DBCP-381 > Project: Commons Dbcp > Issue Type: Bug > Reporter: Carlos Martinez > Labels: BLOCKED, PERFORMANCE, ROLLBACK > > Hi, > We are performing stress tests of OpenCMS. The database used is Oracle one. > The pool of connections that OpenCMS is using is the DBCP pool. > While performing performance tests we see that with minimal load already > generated, almost all of the threads in java get "BLOCKED" trying to release > back connections to the pool, and the performance of the application is > really poor. We also see that the CPU consumption on the application server > machine goes up to 100%. We are not generating enough load to cause this > consumption. I believe that the CPU is all spent trying to handle those BLOCK > threads. > We did perform a thread dump of the Java on many occasions and the pattern is > always similar. Plenty of connections blocked releasing the connection: > ------------------- > "TP-Processor8" daemon prio=10 tid=0x00007fa2848b4000 nid=0x4713 waiting for > monitor entry [0x00007fa2833f8000] > java.lang.Thread.State: BLOCKED (on object monitor) > at > org.apache.commons.pool.impl.GenericObjectPool.returnObject(GenericObjectPool.java:916) > - waiting to lock <0x0000000780ba7cc8> (a > org.apache.commons.pool.impl.GenericObjectPool) > at > org.apache.commons.dbcp.PoolableConnection.close(PoolableConnection.java:87) > - locked <0x00000007811a6f78> (a > org.apache.commons.dbcp.PoolableConnection) > at > org.apache.commons.dbcp.PoolingDriver$PoolGuardConnectionWrapper.close(PoolingDriver.java:269) > at > org.opencms.ocee.db.transaction.CmsTransactionConnection.close(CmsTransactionConnection.java:79) > at > org.opencms.ocee.db.transaction.CmsTransaction.close(CmsTransaction.java:121) > at > org.opencms.ocee.db.transaction.CmsTransactionDbContext.clear(CmsTransactionDbContext.java:99) > at > org.opencms.db.CmsSecurityManager.readFile(CmsSecurityManager.java:3351) > at org.opencms.file.CmsObject.readFile(CmsObject.java:2725) > at org.opencms.file.CmsObject.readFile(CmsObject.java:2777) > at org.opencms.file.CmsObject.readFile(CmsObject.java:2747) > at > org.apache.jsp.WEB_002dINF.jsp.online.system.modules.org_opentrends_upf_template.templates.mainUPF_jsp._jspService(mainUPF_jsp.java:654) > at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:98) > ------------- > And one thread active releasing the connection: > ------------- > "TP-Processor10" daemon prio=10 tid=0x00007fa284b34800 nid=0x4715 runnable > [0x00007fa2831f4000] > java.lang.Thread.State: RUNNABLE > at java.net.SocketInputStream.socketRead0(Native Method) > at java.net.SocketInputStream.read(SocketInputStream.java:129) > at oracle.net.ns.Packet.receive(Unknown Source) > at oracle.net.ns.DataPacket.receive(Unknown Source) > at oracle.net.ns.NetInputStream.getNextPacket(Unknown Source) > at oracle.net.ns.NetInputStream.read(Unknown Source) > at oracle.net.ns.NetInputStream.read(Unknown Source) > at oracle.net.ns.NetInputStream.read(Unknown Source) > at > oracle.jdbc.driver.T4CMAREngine.unmarshalUB1(T4CMAREngine.java:1104) > at > oracle.jdbc.driver.T4CMAREngine.unmarshalSB1(T4CMAREngine.java:1075) > at > oracle.jdbc.driver.T4C7Ocommoncall.receive(T4C7Ocommoncall.java:106) > at oracle.jdbc.driver.T4CConnection.doRollback(T4CConnection.java:568) > - locked <0x00000007810e2ac0> (a oracle.jdbc.driver.T4CConnection) > at > oracle.jdbc.driver.PhysicalConnection.rollback(PhysicalConnection.java:1164) > - locked <0x00000007810e2ac0> (a oracle.jdbc.driver.T4CConnection) > at > org.apache.commons.dbcp.DelegatingConnection.rollback(DelegatingConnection.java:328) > at > org.apache.commons.dbcp.DelegatingConnection.rollback(DelegatingConnection.java:328) > at > org.apache.commons.dbcp.PoolableConnectionFactory.passivateObject(PoolableConnectionFactory.java:359) > at > org.apache.commons.pool.impl.GenericObjectPool.addObjectToPool(GenericObjectPool.java:926) > at > org.apache.commons.pool.impl.GenericObjectPool.returnObject(GenericObjectPool.java:917) > - locked <0x0000000780ba7cc8> (a > org.apache.commons.pool.impl.GenericObjectPool) > at > org.apache.commons.dbcp.PoolableConnection.close(PoolableConnection.java:87) > - locked <0x00000007810e29b0> (a > org.apache.commons.dbcp.PoolableConnection) > at > org.apache.commons.dbcp.PoolingDriver$PoolGuardConnectionWrapper.close(PoolingDriver.java:269) > at > org.opencms.ocee.db.transaction.CmsTransactionConnection.close(CmsTransactionConnection.java:79) > at > org.opencms.ocee.db.transaction.CmsTransaction.close(CmsTransaction.java:121) > at > org.opencms.ocee.db.transaction.CmsTransactionDbContext.clear(CmsTransactionDbContext.java:99) > at > org.opencms.db.CmsSecurityManager.readFile(CmsSecurityManager.java:3351) > at org.opencms.file.CmsObject.readFile(CmsObject.java:2725) > ------------ > As we can see the thread releasing the connection is performing a rollback, > probably so that the connection gets back clean to the pool. > In this case the application is not performing Updates/Deletes or Inserts. In > the future it will, but not in the stress tests. > This is a big issue, as a Rollback is not a light operation, even when it has > not to rollback many actions. > This is affecting the pool, as while the connection is performing rollback > nobody can use the pool as it is locked. > This does not make any sense. > I believe that what is happening is: > 1) I lock the pool > 2) I perform a rollback of the connection > 3) I return the connection to the pool > 4) I unlock the pool > Why is the rollback holding the pool??? The rollback should be done before > locking the pool. It would be better if: > 1) I perform a rollback of the connection > 2) I lock the pool > 3) I return the connection to the pool > 4) I unlock the pool > I have seen many threads on internet of people having this kind of locking > under stress tests, and I believe this could be the cause. The lock should be > hold really the shortest time possible. > Thanks, > Carlos -- This message was sent by Atlassian JIRA (v6.2#6252)