Hi Isomorphic,
it seems we do have a problem with current 12.0p (v12.0p_2019-03-23) and the shipped commons-dbcp-1.4.jar.
It is likely that this is related to this thread and the DBCP issue you mention in #6 there.
Release notes for unreleased Apache Commons DBCP 1.4.1 mention the bug that 1.2.2 claims to have fixed. It contains this fix which claims that the fix in 1.2.2 is incomplete. Now 1.4.1 is unreleased, so there is not much you can do here. I did ask for a release date, though. But I do assume that DBCP 2 (new namespace) fixes it as well, as this is in active development (3 releases in 2018, 1 in 2019).
We do have the configuration in place that is said to cause the issue (positive minIdle and timeBetweenEvictionRunsMillis):
Regarding the issue itself:
We run many instances of our application as own WAR files. These application run on the same Tomcat (9.0.17). Now if the issue happens, one application (server.xml <Host> entry) maxes out it connections. New requests will hang (stack trace follows). This in turn maxes out our Tomcat threads (maxThreads here) eventually, bringing all instances effectively down, as no more threads can be created.
We restarted our application to prevent the "whole Tomcat down" issue from happening.
At that time, we had many (~50) BLOCKED threads, most of them with a stack trace where the top line is like this (there are of course many different codepaths that use DB connections in the end, so the whole stack is always a bit different:
A few had a stack trace starting with this:
Does this (DataSourceManager.getDataSource:167 and ISCObjectPool.borrowObject:111) somehow relate to a potential problem with Apache Commons DBCP?
Thank you & Best regards
Blama
it seems we do have a problem with current 12.0p (v12.0p_2019-03-23) and the shipped commons-dbcp-1.4.jar.
It is likely that this is related to this thread and the DBCP issue you mention in #6 there.
Release notes for unreleased Apache Commons DBCP 1.4.1 mention the bug that 1.2.2 claims to have fixed. It contains this fix which claims that the fix in 1.2.2 is incomplete. Now 1.4.1 is unreleased, so there is not much you can do here. I did ask for a release date, though. But I do assume that DBCP 2 (new namespace) fixes it as well, as this is in active development (3 releases in 2018, 1 in 2019).
We do have the configuration in place that is said to cause the issue (positive minIdle and timeBetweenEvictionRunsMillis):
Code:
sql.defaultDatabase: Oracle sql.useAnsiJoins: true # Apache Commons DBCP Database connection pooling sql.pool.enabled: true [B]sql.pool.minIdle: 1[/B] sql.pool.maxActive: 10 sql.pool.whenExhaustedAction: block sql.pool.testWhileIdle: true [B]sql.pool.timeBetweenEvictionRunsMillis: 15000[/B] sql.pool.minEvictableIdleTimeMillis: 29000 sql.Oracle.database.type: oracle sql.Oracle.autoJoinTransactions: true sql.Oracle.database.supportsSQLLimit: false sql.Oracle.interface.credentialsInURL: true sql.Oracle.interface.type: dataSource sql.Oracle.pingTest: select 1 from dual sql.Oracle.driver: oracle.jdbc.pool.OracleDataSource sql.Oracle.driver.url: jdbc:oracle:thin:@xxxxxx:1521/DB11GXDB.localdomain sql.Oracle.driver.user: xxx sql.Oracle.driver.password: xxx sql.Oracle.driver.driverType: thin sql.Oracle.driver.networkProtocol: tcp sql.Oracle.driver.context:
We run many instances of our application as own WAR files. These application run on the same Tomcat (9.0.17). Now if the issue happens, one application (server.xml <Host> entry) maxes out it connections. New requests will hang (stack trace follows). This in turn maxes out our Tomcat threads (maxThreads here) eventually, bringing all instances effectively down, as no more threads can be created.
We restarted our application to prevent the "whole Tomcat down" issue from happening.
At that time, we had many (~50) BLOCKED threads, most of them with a stack trace where the top line is like this (there are of course many different codepaths that use DB connections in the end, so the whole stack is always a bit different:
Code:
[B]Example 1:[/B] Stack Trace http-nio-8080-exec-76 [133] (BLOCKED) com.isomorphic.datasource.DataSourceManager.getDataSource line: 167 com.isomorphic.datasource.DataSourceManager.getDataSource line: 121 com.isomorphic.datasource.DSRequest.getDataSource line: 2356 com.isomorphic.datasource.DSRequest.setDataSourceName line: 2330 com.isomorphic.datasource.DSRequest.<init> line: 436 org.apache.jsp.Lms_jsp._jspService line: 396 org.apache.jasper.runtime.HttpJspBase.service line: 70 javax.servlet.http.HttpServlet.service line: 741 org.apache.jasper.servlet.JspServletWrapper.service line: 476 org.apache.jasper.servlet.JspServlet.serviceJspFile line: 385 org.apache.jasper.servlet.JspServlet.service line: 329 javax.servlet.http.HttpServlet.service line: 741 org.apache.catalina.core.ApplicationFilterChain.internalDoFilter line: 231 org.apache.catalina.core.ApplicationFilterChain.doFilter line: 166 org.apache.tomcat.websocket.server.WsFilter.doFilter line: 53 org.apache.catalina.core.ApplicationFilterChain.internalDoFilter line: 193 org.apache.catalina.core.ApplicationFilterChain.doFilter line: 166 com.isomorphic.servlet.CompressionFilter._doFilter line: 260 com.isomorphic.servlet.BaseFilter.doFilter line: 93 org.apache.catalina.core.ApplicationFilterChain.internalDoFilter line: 193 org.apache.catalina.core.ApplicationFilterChain.doFilter line: 166 com.lmscompany.lms.server.ResponseHeaderFilter.doFilter line: 40 org.apache.catalina.core.ApplicationFilterChain.internalDoFilter line: 193 org.apache.catalina.core.ApplicationFilterChain.doFilter line: 166 org.apache.catalina.filters.HttpHeaderSecurityFilter.doFilter line: 126 org.apache.catalina.core.ApplicationFilterChain.internalDoFilter line: 193 org.apache.catalina.core.ApplicationFilterChain.doFilter line: 166 org.apache.catalina.core.StandardWrapperValve.invoke line: 200 org.apache.catalina.core.StandardContextValve.invoke line: 96 org.apache.catalina.authenticator.AuthenticatorBase.invoke line: 607 org.apache.catalina.core.StandardHostValve.invoke line: 139 org.apache.catalina.valves.ErrorReportValve.invoke line: 92 org.apache.catalina.valves.AbstractAccessLogValve.invoke line: 678 org.apache.catalina.valves.rewrite.RewriteValve.invoke line: 282 org.apache.catalina.core.StandardEngineValve.invoke line: 74 org.apache.catalina.valves.RemoteIpValve.invoke line: 679 org.apache.catalina.valves.rewrite.RewriteValve.invoke line: 539 org.apache.catalina.core.StandardEngineValve.invoke line: 74 org.apache.catalina.valves.RemoteIpValve.invoke line: 679 org.apache.catalina.connector.CoyoteAdapter.service line: 343 org.apache.coyote.http11.Http11Processor.service line: 408 org.apache.coyote.AbstractProcessorLight.process line: 66 org.apache.coyote.AbstractProtocol$ConnectionHandler.process line: 834 org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun line: 1415 org.apache.tomcat.util.net.SocketProcessorBase.run line: 49 java.util.concurrent.ThreadPoolExecutor.runWorker line: 1149 java.util.concurrent.ThreadPoolExecutor$Worker.run line: 624 org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run line: 61 java.lang.Thread.run line: 748 [B]Example 2:[/B] Stack Trace http-nio-8080-exec-73 [130] (BLOCKED) com.isomorphic.datasource.DataSourceManager.getDataSource line: 167 com.isomorphic.datasource.DataSourceManager.getDataSource line: 121 com.isomorphic.datasource.DSRequest.getDataSource line: 2356 com.isomorphic.datasource.DSRequest.setDataSourceName line: 2330 com.isomorphic.datasource.DSRequest.<init> line: 436 com.lmscompany.lms.server.SendMail.writeActionMails line: 166 com.lmscompany.lms.server.SendMail.doGet line: 50 javax.servlet.http.HttpServlet.service line: 634 javax.servlet.http.HttpServlet.service line: 741 org.apache.catalina.core.ApplicationFilterChain.internalDoFilter line: 231 org.apache.catalina.core.ApplicationFilterChain.doFilter line: 166 org.apache.tomcat.websocket.server.WsFilter.doFilter line: 53 org.apache.catalina.core.ApplicationFilterChain.internalDoFilter line: 193 org.apache.catalina.core.ApplicationFilterChain.doFilter line: 166 com.isomorphic.servlet.CompressionFilter._doFilter line: 247 com.isomorphic.servlet.BaseFilter.doFilter line: 93 org.apache.catalina.core.ApplicationFilterChain.internalDoFilter line: 193 org.apache.catalina.core.ApplicationFilterChain.doFilter line: 166 org.apache.catalina.filters.HttpHeaderSecurityFilter.doFilter line: 126 org.apache.catalina.core.ApplicationFilterChain.internalDoFilter line: 193 org.apache.catalina.core.ApplicationFilterChain.doFilter line: 166 org.apache.catalina.core.StandardWrapperValve.invoke line: 200 org.apache.catalina.core.StandardContextValve.invoke line: 96 org.apache.catalina.authenticator.AuthenticatorBase.invoke line: 490 org.apache.catalina.core.StandardHostValve.invoke line: 139 org.apache.catalina.valves.ErrorReportValve.invoke line: 92 org.apache.catalina.valves.AbstractAccessLogValve.invoke line: 678 org.apache.catalina.valves.rewrite.RewriteValve.invoke line: 282 org.apache.catalina.core.StandardEngineValve.invoke line: 74 org.apache.catalina.valves.RemoteIpValve.invoke line: 679 org.apache.catalina.valves.rewrite.RewriteValve.invoke line: 539 org.apache.catalina.core.StandardEngineValve.invoke line: 74 org.apache.catalina.valves.RemoteIpValve.invoke line: 679 org.apache.catalina.connector.CoyoteAdapter.service line: 343 org.apache.coyote.http11.Http11Processor.service line: 408 org.apache.coyote.AbstractProcessorLight.process line: 66 org.apache.coyote.AbstractProtocol$ConnectionHandler.process line: 834 org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun line: 1415 org.apache.tomcat.util.net.SocketProcessorBase.run line: 49 java.util.concurrent.ThreadPoolExecutor.runWorker line: 1149 java.util.concurrent.ThreadPoolExecutor$Worker.run line: 624 org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run line: 61 java.lang.Thread.run line: 748 [B]Example 3:[/B] Stack Trace http-nio-8080-exec-65 [122] (BLOCKED) com.isomorphic.datasource.DataSourceManager.getDataSource line: 167 com.isomorphic.datasource.DataSourceManager.getDataSource line: 121 com.isomorphic.datasource.DSRequest.getDataSource line: 2356 com.isomorphic.datasource.DSRequest.setDataSourceName line: 2330 com.isomorphic.datasource.DSRequest.<init> line: 436 com.lmscompany.lms.server.SendMail.writeActionMails line: 166 com.lmscompany.lms.server.SendMail.doGet line: 50 javax.servlet.http.HttpServlet.service line: 634 javax.servlet.http.HttpServlet.service line: 741 org.apache.catalina.core.ApplicationFilterChain.internalDoFilter line: 231 org.apache.catalina.core.ApplicationFilterChain.doFilter line: 166 org.apache.tomcat.websocket.server.WsFilter.doFilter line: 53 org.apache.catalina.core.ApplicationFilterChain.internalDoFilter line: 193 org.apache.catalina.core.ApplicationFilterChain.doFilter line: 166 com.isomorphic.servlet.CompressionFilter._doFilter line: 247 com.isomorphic.servlet.BaseFilter.doFilter line: 93 org.apache.catalina.core.ApplicationFilterChain.internalDoFilter line: 193 org.apache.catalina.core.ApplicationFilterChain.doFilter line: 166 org.apache.catalina.filters.HttpHeaderSecurityFilter.doFilter line: 126 org.apache.catalina.core.ApplicationFilterChain.internalDoFilter line: 193 org.apache.catalina.core.ApplicationFilterChain.doFilter line: 166 org.apache.catalina.core.StandardWrapperValve.invoke line: 200 org.apache.catalina.core.StandardContextValve.invoke line: 96 org.apache.catalina.authenticator.AuthenticatorBase.invoke line: 490 org.apache.catalina.core.StandardHostValve.invoke line: 139 org.apache.catalina.valves.ErrorReportValve.invoke line: 92 org.apache.catalina.valves.AbstractAccessLogValve.invoke line: 678 org.apache.catalina.valves.rewrite.RewriteValve.invoke line: 282 org.apache.catalina.core.StandardEngineValve.invoke line: 74 org.apache.catalina.valves.RemoteIpValve.invoke line: 679 org.apache.catalina.valves.rewrite.RewriteValve.invoke line: 539 org.apache.catalina.core.StandardEngineValve.invoke line: 74 org.apache.catalina.valves.RemoteIpValve.invoke line: 679 org.apache.catalina.connector.CoyoteAdapter.service line: 343 org.apache.coyote.http11.Http11Processor.service line: 408 org.apache.coyote.AbstractProcessorLight.process line: 66 org.apache.coyote.AbstractProtocol$ConnectionHandler.process line: 834 org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun line: 1415 org.apache.tomcat.util.net.SocketProcessorBase.run line: 49 java.util.concurrent.ThreadPoolExecutor.runWorker line: 1149 java.util.concurrent.ThreadPoolExecutor$Worker.run line: 624 org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run line: 61 java.lang.Thread.run line: 748
Code:
Stack Trace http-nio-8080-exec-29 [86] (BLOCKED) com.isomorphic.pool.ISCObjectPool.borrowObject line: 111 com.isomorphic.pool.PoolManager.borrowObject line: 102 com.isomorphic.pool.PoolManager.borrowObject line: 76 com.isomorphic.sql.SQLConnectionManager.getConnection line: 177 com.isomorphic.sql.SQLDriver.getTransformedResults line: 953 com.isomorphic.sql.SQLDriver.executeQuery line: 1394 com.isomorphic.sql.SQLDataSource.executeNativeQuery line: 585 com.isomorphic.sql.SQLDataSource.executeNativeQuery line: 579 com.isomorphic.sql.SQLDataSource.SQLExecute line: 1772 com.isomorphic.sql.SQLDataSource.processRequest line: 439 com.isomorphic.sql.SQLDataSource.executeFetch line: 384 com.lmscompany.lms.server.LMSSQLDataSource.executeFetch line: 149 com.isomorphic.datasource.DataSource.execute line: 2384 com.lmscompany.lms.server.LMSSQLDataSource.execute line: 191 com.isomorphic.application.AppBase.executeDefaultDSOperation line: 646 com.isomorphic.application.AppBase.executeAppOperation line: 547 com.isomorphic.application.AppBase.execute line: 490 com.isomorphic.datasource.DSRequest.execute line: 2835 com.lmscompany.lms.server.worker.T_FIELD_CONFIG.getData line: 94 com.lmscompany.lms.server.RefreshCycle.checkCacheAge line: 52 com.lmscompany.lms.server.worker.T_FIELD_CONFIG.getFieldConfigDataResponse line: 102 com.lmscompany.lms.server.RegisterDS.formatFieldMultiple line: 368 com.lmscompany.lms.server.RegisterDS.access$400 line: 52 com.lmscompany.lms.server.RegisterDS$3.getDataSource line: 251 com.isomorphic.datasource.DataSource.getDynamicDataSource line: 807 com.isomorphic.datasource.DataSource.forName line: 459 com.isomorphic.datasource.PoolableDataSourceFactory.makeUnpooledObject line: 134 com.isomorphic.pool.PoolManager.borrowUnpooledObject line: 143 com.isomorphic.datasource.DataSourceManager.getDataSource line: 169 com.isomorphic.datasource.DataSourceManager.getDataSource line: 121 com.isomorphic.datasource.BasicDataSource.getSuper line: 798 com.isomorphic.datasource.BasicDataSource.init line: 287 com.isomorphic.sql.SQLDataSource.init line: 257 com.isomorphic.datasource.DataSource.initialize line: 921 com.isomorphic.datasource.BasicDataSource.fromConfig line: 238 com.isomorphic.datasource.DataSource.fromConfig line: 906 com.isomorphic.datasource.DataSource.loadDS line: 534 com.isomorphic.datasource.DataSource.forName line: 462 com.isomorphic.datasource.PoolableDataSourceFactory.makeUnpooledObject line: 134 com.isomorphic.datasource.PoolableDataSourceFactory.makeObject line: 153 org.apache.commons.pool.impl.GenericKeyedObjectPool.borrowObject line: 1220 com.isomorphic.pool.ISCKeyedObjectPool.borrowObject line: 106 com.isomorphic.pool.PoolManager.borrowObject line: 92 com.isomorphic.datasource.DataSourceManager.getDataSource line: 171 com.isomorphic.datasource.DataSourceManager.getDataSource line: 121 com.isomorphic.datasource.DSRequest.getDataSource line: 2356 com.isomorphic.datasource.DSRequest.decodeUploadedStrings line: 826 com.isomorphic.datasource.DSRequest.<init> line: 707 com.isomorphic.rpc.RPCManager.parseRequest line: 2526 com.isomorphic.rpc.RPCManager.<init> line: 447 com.lmscompany.lms.server.LMSIDACall.processRequest line: 48 com.isomorphic.servlet.IDACall._processRequest line: 119 com.isomorphic.servlet.IDACall.doPost line: 79 javax.servlet.http.HttpServlet.service line: 660 com.isomorphic.servlet.BaseServlet.service line: 176 javax.servlet.http.HttpServlet.service line: 741 org.apache.catalina.core.ApplicationFilterChain.internalDoFilter line: 231 org.apache.catalina.core.ApplicationFilterChain.doFilter line: 166 org.apache.tomcat.websocket.server.WsFilter.doFilter line: 53 org.apache.catalina.core.ApplicationFilterChain.internalDoFilter line: 193 org.apache.catalina.core.ApplicationFilterChain.doFilter line: 166 com.isomorphic.servlet.CompressionFilter._doFilter line: 260 com.isomorphic.servlet.BaseFilter.doFilter line: 93 org.apache.catalina.core.ApplicationFilterChain.internalDoFilter line: 193 org.apache.catalina.core.ApplicationFilterChain.doFilter line: 166 org.apache.catalina.filters.HttpHeaderSecurityFilter.doFilter line: 126 org.apache.catalina.core.ApplicationFilterChain.internalDoFilter line: 193 org.apache.catalina.core.ApplicationFilterChain.doFilter line: 166 org.apache.catalina.core.StandardWrapperValve.invoke line: 200 org.apache.catalina.core.StandardContextValve.invoke line: 96 org.apache.catalina.authenticator.AuthenticatorBase.invoke line: 607 org.apache.catalina.core.StandardHostValve.invoke line: 139 org.apache.catalina.valves.ErrorReportValve.invoke line: 92 org.apache.catalina.valves.AbstractAccessLogValve.invoke line: 678 org.apache.catalina.valves.rewrite.RewriteValve.invoke line: 542 org.apache.catalina.core.StandardEngineValve.invoke line: 74 org.apache.catalina.valves.RemoteIpValve.invoke line: 679 org.apache.catalina.connector.CoyoteAdapter.service line: 343 org.apache.coyote.http11.Http11Processor.service line: 408 org.apache.coyote.AbstractProcessorLight.process line: 66 org.apache.coyote.AbstractProtocol$ConnectionHandler.process line: 834 org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun line: 1415 org.apache.tomcat.util.net.SocketProcessorBase.run line: 49 java.util.concurrent.ThreadPoolExecutor.runWorker line: 1149 java.util.concurrent.ThreadPoolExecutor$Worker.run line: 624 org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run line: 61 java.lang.Thread.run line: 748
Thank you & Best regards
Blama
Comment