error with timeouts in coldbox 3.1.0

[Jeremy_DeYoung]

below is the stack trace.

i have an automatic script that runs every 60 seconds via a standard cron job. it calls a coldfusion url and crunches data, then outputs the data in JSON.

I am able to run the url thru my browser without any problems. In fact, I am able to run it on the server without any problems via cron job however about every 10-15 minutes, I get the following stack trace.

Any ideas on how to fix or investigate?

I am running Railo 3.3.0.021 rc on Amazon/CentOS Linux

Stack Trace

Error including config file: there is a timeout occurred on a exclusive lock with name [ConcurrentStore.509537123.cbox_plugin-json] after 10 seconds at railo.runtime.tag.Throw._doStartTag(Throw.java:142):142 at railo.runtime.tag.Throw.doStartTag(Throw.java:131):131 at coldbox.system.frameworksupertype_cfc$cf.udfCall4(/var/lib/tomcat6/webapps/ROOT/coldbox/system/FrameworkSupertype.cfc:413):413 at coldbox.system.frameworksupertype_cfc$cf.udfCall(/var/lib/tomcat6/webapps/ROOT/coldbox/system/FrameworkSupertype.cfc):-1 at railo.runtime.type.UDFImpl.implementation(UDFImpl.java:214):214 at railo.runtime.type.UDFImpl._call(UDFImpl.java:418):418 at railo.runtime.type.UDFImpl.call(UDFImpl.java:383):383 at railo.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:738):738 at railo.runtime.PageContextImpl.getFunction(PageContextImpl.java:1438):1438 at coldbox.system.interceptors.ses_cfc$cf.udfCall4(/var/lib/tomcat6/webapps/ROOT/coldbox/system/interceptors/SES.cfc:1063):1063 at coldbox.system.interceptors.ses_cfc$cf.udfCall(/var/lib/tomcat6/webapps/ROOT/coldbox/system/interceptors/SES.cfc):-1 at railo.runtime.type.UDFImpl.implementation(UDFImpl.java:214):214 at railo.runtime.type.UDFImpl._call(UDFImpl.java:418):418 at railo.runtime.type.UDFImpl.call(UDFImpl.java:383):383 at railo.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:738):738 at railo.runtime.PageContextImpl.getFunction(PageContextImpl.java:1438):1438 at coldbox.system.interceptors.ses_cfc$cf.udfCall1(/var/lib/tomcat6/webapps/ROOT/coldbox/system/interceptors/SES.cfc:58):58 at coldbox.system.interceptors.ses_cfc$cf.udfCall(/var/lib/tomcat6/webapps/ROOT/coldbox/system/interceptors/SES.cfc):-1 at railo.runtime.type.UDFImpl.implementation(UDFImpl.java:214):214 at railo.runtime.type.UDFImpl._call(UDFImpl.java:418):418 at railo.runtime.type.UDFImpl.call(UDFImpl.java:383):383 at railo.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:738):738 at railo.runtime.PageContextImpl.getFunction(PageContextImpl.java:1438):1438 at coldbox.system.interceptors.ses_cfc$cf.udfCall1(/var/lib/tomcat6/webapps/ROOT/coldbox/system/interceptors/SES.cfc:87):87 at coldbox.system.interceptors.ses_cfc$cf.udfCall(/var/lib/tomcat6/webapps/ROOT/coldbox/system/interceptors/SES.cfc):-1 at railo.runtime.type.UDFImpl.implementation(UDFImpl.java:214):214 at railo.runtime.type.UDFImpl._call(UDFImpl.java:418):418 at railo.runtime.type.UDFImpl.callWithNamedValues(UDFImpl.java:376):376 at railo.runtime.ComponentImpl._call(ComponentImpl.java:574):574 at railo.runtime.ComponentImpl._call(ComponentImpl.java:502):502 at railo.runtime.ComponentImpl.callWithNamedValues(ComponentImpl.java:1772):1772 at railo.runtime.tag.Invoke.doComponent(Invoke.java:210):210 at railo.runtime.tag.Invoke.doEndTag(Invoke.java:183):183 at coldbox.system.web.context.interceptorstate_cfc$cf.udfCall(/var/lib/tomcat6/webapps/ROOT/coldbox/system/web/context/InterceptorState.cfc:139):139 at railo.runtime.type.UDFImpl.implementation(UDFImpl.java:214):214 at railo.runtime.type.UDFImpl._call(UDFImpl.java:418):418 at railo.runtime.type.UDFImpl.call(UDFImpl.java:383):383 at railo.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:738):738 at railo.runtime.PageContextImpl.getFunction(PageContextImpl.java:1438):1438 at coldbox.system.web.context.interceptorstate_cfc$cf.udfCall(/var/lib/tomcat6/webapps/ROOT/coldbox/system/web/context/InterceptorState.cfc:86):86 at railo.runtime.type.UDFImpl.implementation(UDFImpl.java:214):214 at railo.runtime.type.UDFImpl._call(UDFImpl.java:418):418 at railo.runtime.type.UDFImpl.call(UDFImpl.java:383):383 at railo.runtime.ComponentImpl._call(ComponentImpl.java:573):573 at railo.runtime.ComponentImpl._call(ComponentImpl.java:502):502 at railo.runtime.ComponentImpl.call(ComponentImpl.java:1757):1757 at railo.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:733):733 at railo.runtime.PageContextImpl.getFunction(PageContextImpl.java:1438):1438 at coldbox.system.web.services.interceptorservice_cfc$cf.udfCall1(/var/lib/tomcat6/webapps/ROOT/coldbox/system/web/services/InterceptorService.cfc:115):115 at coldbox.system.web.services.interceptorservice_cfc$cf.udfCall(/var/lib/tomcat6/webapps/ROOT/coldbox/system/web/services/InterceptorService.cfc):-1 at railo.runtime.type.UDFImpl.implementation(UDFImpl.java:214):214 at railo.runtime.type.UDFImpl._call(UDFImpl.java:418):418 at railo.runtime.type.UDFImpl.call(UDFImpl.java:383):383 at railo.runtime.ComponentImpl._call(ComponentImpl.java:573):573 at railo.runtime.ComponentImpl._call(ComponentImpl.java:502):502 at railo.runtime.ComponentImpl.call(ComponentImpl.java:1757):1757 at railo.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:733):733 at railo.runtime.PageContextImpl.getFunction(PageContextImpl.java:1438):1438 at coldbox.system.coldbox_cfc$cf.udfCall1(/var/lib/tomcat6/webapps/ROOT/coldbox/system/Coldbox.cfc:228):228 at coldbox.system.coldbox_cfc$cf.udfCall(/var/lib/tomcat6/webapps/ROOT/coldbox/system/Coldbox.cfc):-1 at railo.runtime.type.UDFImpl.implementation(UDFImpl.java:214):214 at railo.runtime.type.UDFImpl._call(UDFImpl.java:418):418 at railo.runtime.type.UDFImpl.call(UDFImpl.java:383):383 at railo.runtime.util.VariableUtilImpl.callFunctionWithoutNamedValues(VariableUtilImpl.java:738):738 at railo.runtime.PageContextImpl.getFunction(PageContextImpl.java:1438):1438 at application_cfc$cf.udfCall(/var/lib/tomcat6/webapps/ROOT/Application.cfc:84):84 at railo.runtime.type.UDFImpl.implementation(UDFImpl.java:214):214 at railo.runtime.type.UDFImpl._call(UDFImpl.java:418):418 at railo.runtime.type.UDFImpl.call(UDFImpl.java:383):383 at railo.runtime.ComponentImpl._call(ComponentImpl.java:573):573 at railo.runtime.ComponentImpl._call(ComponentImpl.java:502):502 at railo.runtime.ComponentImpl.call(ComponentImpl.java:1757):1757 at railo.runtime.listener.ModernAppListener.call(ModernAppListener.java:347):347 at railo.runtime.listener.ModernAppListener._onRequest(ModernAppListener.java:106):106 at railo.runtime.listener.MixedAppListener.onRequest(MixedAppListener.java:23):23 at railo.runtime.PageContextImpl.execute(PageContextImpl.java:1985):1985 at railo.runtime.PageContextImpl.execute(PageContextImpl.java:1952):1952 at railo.runtime.engine.CFMLEngineImpl.serviceCFML(CFMLEngineImpl.java:282):282 at railo.loader.servlet.CFMLServlet.service(CFMLServlet.java:32):32 at javax.servlet.http.HttpServlet.service(HttpServlet.java:717):717 at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290):290 at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206):206 at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233):233 at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191):191 at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127):127 at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102):102 at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109):109 at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298):298 at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:190):190 at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:291):291 at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:776):776 at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:705):705 at org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:898):898 at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:690):690 at java.lang.Thread.run(Thread.java:636):636

---

Jeremy R. DeYoung
Phone:615.261.8201

RantsFromAMadMan.com

[bdw429s]

I’m a little confused about the stack trace. It looks like the error is being thrown from line 1063 of SES.cfc. According to the 3.1.0 tag on github, that line is whitespace.
https://github.com/ColdBox/coldbox-platform/blob/3.1.0/system/interceptors/SES.cfc#L1063

Have you modified that file, or are the Railo stack traces a little funky with the line numbers?

Do you know how long the request runs before it times out. The name of the lock appears to be related to a cache box key (which is also confusing since there are no cachebox references in ses.cfc)
If it was me, I would try to catch it in the act with SeeFusion and capture a stack trace of what’s making the request take long enough to hang.

If it regularly happens every 10-15 minutes it could be another process running on the machine or perhaps really slow GC pauses.

Also, does your cron job/script have code in place to ensure it doesn’t run more than once if the previous run isn’t finished yet?

Thanks!

~Brad