January 23, 2019
CF11 database connection BLOCKED – JDBCPool.checkIn
Comments
(2)
January 23, 2019
CF11 database connection BLOCKED – JDBCPool.checkIn
Newbie 1 posts
Followers: 1 people
(2)

Dear All,

I have recently experienced an unexpected 503 server error and server crash quite often.

The application has been running for more than 5 years and never experienced this issue before.

I had thought it was due to bot attacks but after I blocked it, the server still not stable.

The thing is when one request stuck or had the slow response it impacted other requests and building up until it hits the max request number. It can’t solve by itself, sometimes I need to reject the requests to make the website running again.

It’s not happening every day but it started to be a big issue as the website is not stable anymore.

If someone can help out, it will be great.

During the crash, I got this error:

“ajp-bio-8012-exec-171” Id=59313 BLOCKED on coldfusion.server.j2ee.sql.pool.JDBCPool@11ffdd46 owned by “ajp-bio-8012-exec-236” Id=73475
java.lang.Thread.State: BLOCKED
at coldfusion.server.j2ee.pool.ObjectPool.checkIn(ObjectPool.java:263)
– waiting to lock coldfusion.server.j2ee.sql.pool.JDBCPool@11ffdd46 owned by “ajp-bio-8012-exec-236”
at coldfusion.server.j2ee.sql.pool.JDBCPool.returnConnection(JDBCPool.java:851)
at coldfusion.server.j2ee.sql.pool.JDBCPool.connectionClosed(JDBCPool.java:324)
at coldfusion.server.j2ee.sql.JRunConnection.sendCloseEvent(JRunConnection.java:345)
at coldfusion.server.j2ee.sql.JRunConnectionHandle.close(JRunConnectionHandle.java:74)
at coldfusion.sql.DataSrcImpl.clear(DataSrcImpl.java:182)
at coldfusion.sql.DataSrcImpl.clearSqlProxy(DataSrcImpl.java:25)
at coldfusion.filter.DatasourceFilter.invoke(DatasourceFilter.java:26)
at coldfusion.filter.CachingFilter.invoke(CachingFilter.java:62)
at coldfusion.CfmServlet.service(CfmServlet.java:219)
at coldfusion.bootstrap.BootstrapServlet.service(BootstrapServlet.java:89)
at sun.reflect.GeneratedMethodAccessor97.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:288)
at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:285)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAsPrivileged(Subject.java:549)
at org.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:320)
at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:175)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:297)
at org.apache.catalina.core.ApplicationFilterChain.access$000(ApplicationFilterChain.java:55)
at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:191)
at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:187)
at java.security.AccessController.doPrivileged(Native Method)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:186)
at coldfusion.monitor.event.MonitoringServletFilter.doFilter(MonitoringServletFilter.java:42)
at coldfusion.bootstrap.BootstrapFilter.doFilter(BootstrapFilter.java:46)
at sun.reflect.GeneratedMethodAccessor96.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:288)
at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:285)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAsPrivileged(Subject.java:549)
at org.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:320)
at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:260)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:237)
at org.apache.catalina.core.ApplicationFilterChain.access$000(ApplicationFilterChain.java:55)
at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:191)
at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:187)
at java.security.AccessController.doPrivileged(Native Method)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:186)
at sun.reflect.GeneratedMethodAccessor94.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.intergral.fusionreactor.j2ee.filterchain.WrappedFilterChain.doFilter(WrappedFilterChain.java:97)
at com.intergral.fusionreactor.j2ee.filter.FusionReactorRequestHandler.doNext(FusionReactorRequestHandler.java:472)
at com.intergral.fusionreactor.j2ee.filter.FusionReactorRequestHandler.doHttpServletRequest(FusionReactorRequestHandler.java:312)
at com.intergral.fusionreactor.j2ee.filter.FusionReactorRequestHandler.doFusionRequest(FusionReactorRequestHandler.java:192)
at com.intergral.fusionreactor.j2ee.filter.FusionReactorRequestHandler.handle(FusionReactorRequestHandler.java:507)
at com.intergral.fusionreactor.j2ee.filter.FusionReactorCoreFilter.doFilter(FusionReactorCoreFilter.java:36)
at sun.reflect.GeneratedMethodAccessor106.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.intergral.fusionreactor.j2ee.filterchain.WrappedFilterChain.doFilter(WrappedFilterChain.java:79)
at sun.reflect.GeneratedMethodAccessor66.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.intergral.fusionreactor.agent.filter.FusionReactorStaticFilter.doFilter(FusionReactorStaticFilter.java:53)
at com.intergral.fusionreactor.agent.pointcuts.NewFilterChainPointCut$1.invoke(NewFilterChainPointCut.java:41)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:110)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:494)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:169)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:104)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
at org.apache.catalina.ha.session.JvmRouteBinderValve.invoke(JvmRouteBinderValve.java:207)
at org.apache.catalina.ha.tcp.ReplicationValve.invoke(ReplicationValve.java:333)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:458)
at org.apache.coyote.ajp.AjpProcessor.process(AjpProcessor.java:196)
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:637)
at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316)
– locked org.apache.tomcat.util.net.SocketWrapper@5bd4245
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:748)

Locked ownable synchronizers:
– java.util.concurrent.ThreadPoolExecutor$Worker@5170c41e

Please let me know if you have any questions. Thank you.

Raquel Septiane

2 Comments
2021-06-19 14:33:26
2021-06-19 14:33:26

Folks, this is indeed a very common problem, across all versions of cf. The jdbc checkin/checkout process (part of jdbc connection pool processing) happens constantly, perhaps a million times a day in even modest apps. So if it ever hangs up, you will indeed see it causing a backup of perhaps all processing very quickly.

The root cause of the problem can have many explanations. Bottom line, the problem is that a cf request wants to make a connection to the db and cannot. You will nearly always find in such a thread dump one or more requests doing a fetch connection, and all the others doing a checkin or checkout (to the same datasource) will show being be locked, waiting on that. Until that fetch happens, it will seem the app is hung.

And if eventually too many hangup (the number in the cf admin’s max simultaneous requests setting), then it will seem that all of cf is hung.

To solve it, you need to find and resolve whatever is blocking that fetchconnection from working. The problem could be in the db, or on the db server (in which case the diagnosis and resolution is there), or it could be a network problem between cf and the db, or it could be a problem in cf or the cf server (in which case diagnosis there may find another explanation).

Sadly, there’s no one explanation or solution. Of course, restarting cf may help…but it may not, if the problem is indeed elsewhere and would just happen to new requests. That said, restarting cf COULD solve it even if the problem IS in the db–if that problem was transient and no longer an issue.

I realize it’s all very frustrating. We just want things to work. Sadly, this is one of that class of problems where the answer may be simple (a problem in the db or cf or their servers which explains things and can be solved), but often it’s hard to spot the real cause.

And on top of all that, sometimes the real ROOT cause is indeed something else, like Michael originally notes, such as an unexpected burst of perhaps unusual requests such as from bots, spiders, hackers, scanners, and so on.

In most cases, it will just take digging into various diagnostics (in cf, the db, their servers, the network, perhaps the web server logs, etc.) to get to the bottom of the problem. There’s just no one simple suggestion to make.

I will say that I help people solve such problems about weekly in my cf server troubleshooting consulting, if anyone seeing this may like that help.

If instead Michael or anyone else may have what seems “the solution” for this, of course I and everyone would love to hear it, as again it’s a very common problem (and most people don’t have the skill you guys did to even see that the problem was reflected in a thread dump to be this jdbc connection pooling matter).

Like
yze
2021-06-19 09:25:16
yze
2021-06-19 09:25:16

Hi,

did you solve this?
I’m having kind of the same problem.

Like
Add Comment