ColdBox 4.3 Strange problem

[cubortea]

Hi Guys,


I really need help, currently I have an API which is using coldbox 4.3 and coldfusion 11. The APi is working fine, but sometime when I check in fusion reactor, there are API which has process which is like locked. Here is the error info:

coldfusion.runtime.Struct.get(Struct.java:72)
- waiting on <0x3591d57> (a coldfusion.runtime.Struct held by thread 94030, ajp-bio-8014-exec-3054)
coldfusion.runtime.ScopeSearchResult.searchForSubkeys(ScopeSearchResult.java:104)
coldfusion.runtime.LocalScope.search(LocalScope.java:438)
coldfusion.runtime.NeoPageContext.searchScopes(NeoPageContext.java:766)
coldfusion.runtime.NeoPageContext.searchScopes(NeoPageContext.java:684)
coldfusion.runtime.CfJspPage.resolveCanonicalName(CfJspPage.java:1767)
coldfusion.runtime.CfJspPage._resolve(CfJspPage.java:1726)
coldfusion.runtime.CfJspPage._resolveAndAutoscalarize(CfJspPage.java:1875)
coldfusion.runtime.CfJspPage._resolveAndAutoscalarize(CfJspPage.java:1854)
cfInterceptorService2ecfc458890167$funcPROCESSSTATE.runFunction(/opt/myapp/at2/coldbox/system/web/services/InterceptorService.cfc:161)
coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:487)
coldfusion.runtime.UDFMethod$ReturnTypeFilter.invoke(UDFMethod.java:420)
coldfusion.runtime.UDFMethod$ArgumentCollectionFilter.invoke(UDFMethod.java:383)
coldfusion.filter.FunctionAccessFilter.invoke(FunctionAccessFilter.java:95)
coldfusion.runtime.UDFMethod.runFilterChain(UDFMethod.java:334)
coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:231)
coldfusion.runtime.TemplateProxy.invoke(TemplateProxy.java:643)
coldfusion.runtime.TemplateProxy.invoke(TemplateProxy.java:432)
coldfusion.runtime.TemplateProxy.invoke(TemplateProxy.java:402)
coldfusion.runtime.CfJspPage._invoke(CfJspPage.java:2483)
cfInjector2ecfc312652358$funcBUILDINSTANCE.runFunction(/opt/myapp/at2/coldbox/system/ioc/Injector.cfc:285)
coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:487)
coldfusion.filter.SilentFilter.invoke(SilentFilter.java:47)
coldfusion.runtime.UDFMethod$ReturnTypeFilter.invoke(UDFMethod.java:420)
coldfusion.runtime.UDFMethod$ArgumentCollectionFilter.invoke(UDFMethod.java:383)
coldfusion.filter.FunctionAccessFilter.invoke(FunctionAccessFilter.java:95)
coldfusion.runtime.UDFMethod.runFilterChain(UDFMethod.java:334)
coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:231)
coldfusion.runtime.TemplateProxy.invoke(TemplateProxy.java:643)
coldfusion.runtime.TemplateProxy.invoke(TemplateProxy.java:432)
coldfusion.runtime.TemplateProxy.invoke(TemplateProxy.java:402)
coldfusion.runtime.CfJspPage._invoke(CfJspPage.java:2483)
cfNoScope2ecfc766392919$funcGETFROMSCOPE.runFunction(/opt/myapp/at2/coldbox/system/ioc/scopes/NoScope.cfc:31)
coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:487)
coldfusion.filter.SilentFilter.invoke(SilentFilter.java:47)
coldfusion.runtime.UDFMethod$ReturnTypeFilter.invoke(UDFMethod.java:420)
coldfusion.runtime.UDFMethod$ArgumentCollectionFilter.invoke(UDFMethod.java:383)
coldfusion.filter.FunctionAccessFilter.invoke(FunctionAccessFilter.java:95)
coldfusion.runtime.UDFMethod.runFilterChain(UDFMethod.java:334)
coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:231)
coldfusion.runtime.TemplateProxy.invoke(TemplateProxy.java:643)
coldfusion.runtime.TemplateProxy.invoke(TemplateProxy.java:432)
coldfusion.runtime.TemplateProxy.invoke(TemplateProxy.java:402)
coldfusion.runtime.CfJspPage._invoke(CfJspPage.java:2483)
cfInjector2ecfc312652358$funcGETINSTANCE.runFunction(/opt/myapp/at2/coldbox/system/ioc/Injector.cfc:263)
coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:487)
coldfusion.filter.SilentFilter.invoke(SilentFilter.java:47)
coldfusion.runtime.UDFMethod$ReturnTypeFilter.invoke(UDFMethod.java:420)
coldfusion.runtime.UDFMethod$ArgumentCollectionFilter.invoke(UDFMethod.java:383)
coldfusion.filter.FunctionAccessFilter.invoke(FunctionAccessFilter.java:95)
coldfusion.runtime.UDFMethod.runFilterChain(UDFMethod.java:334)
coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:231)
coldfusion.runtime.TemplateProxy.invoke(TemplateProxy.java:643)
coldfusion.runtime.TemplateProxy.invoke(TemplateProxy.java:432)
coldfusion.runtime.TemplateProxy.invoke(TemplateProxy.java:402)
coldfusion.runtime.CfJspPage._invoke(CfJspPage.java:2483)
cfController2ecfc1343300006$funcGETDATAMARSHALLER.runFunction(/opt/myapp/at2/coldbox/system/web/Controller.cfc:131)
coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:487)
coldfusion.runtime.UDFMethod$ArgumentCollectionFilter.invoke(UDFMethod.java:383)
coldfusion.filter.FunctionAccessFilter.invoke(FunctionAccessFilter.java:95)
coldfusion.runtime.UDFMethod.runFilterChain(UDFMethod.java:334)
coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:231)
coldfusion.runtime.TemplateProxy.invoke(TemplateProxy.java:643)
coldfusion.runtime.TemplateProxy.invoke(TemplateProxy.java:432)
coldfusion.runtime.TemplateProxy.invoke(TemplateProxy.java:402)
coldfusion.runtime.CfJspPage._invoke(CfJspPage.java:2483)
cfBootstrap2ecfc1530537328$funcRENDERDATASETUP.runFunction(/opt/myapp/at2/coldbox/system/Bootstrap.cfc:577)
coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:487)
coldfusion.runtime.UDFMethod$ReturnTypeFilter.invoke(UDFMethod.java:420)
coldfusion.runtime.UDFMethod$ArgumentCollectionFilter.invoke(UDFMethod.java:383)
coldfusion.filter.FunctionAccessFilter.invoke(FunctionAccessFilter.java:95)
coldfusion.runtime.UDFMethod.runFilterChain(UDFMethod.java:334)
coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:533)
coldfusion.runtime.CfJspPage._invokeUDF(CfJspPage.java:2819)
cfBootstrap2ecfc1530537328$funcPROCESSCOLDBOXREQUEST.runFunction(/opt/myapp/at2/coldbox/system/Bootstrap.cfc:267)
coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:487)
coldfusion.runtime.UDFMethod$ArgumentCollectionFilter.invoke(UDFMethod.java:383)
coldfusion.filter.FunctionAccessFilter.invoke(FunctionAccessFilter.java:95)
coldfusion.runtime.UDFMethod.runFilterChain(UDFMethod.java:334)
coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:231)
coldfusion.runtime.CfJspPage._invokeUDF(CfJspPage.java:2854)
cfBootstrap2ecfc1530537328$funcONREQUESTSTART.runFunction(/opt/myapp/at2/coldbox/system/Bootstrap.cfc:360)
coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:487)
coldfusion.runtime.UDFMethod$ReturnTypeFilter.invoke(UDFMethod.java:420)
coldfusion.runtime.UDFMethod$ArgumentCollectionFilter.invoke(UDFMethod.java:383)
coldfusion.filter.FunctionAccessFilter.invoke(FunctionAccessFilter.java:95)
coldfusion.runtime.UDFMethod.runFilterChain(UDFMethod.java:334)
coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:231)
coldfusion.runtime.TemplateProxy.invoke(TemplateProxy.java:643)
coldfusion.runtime.TemplateProxy.invoke(TemplateProxy.java:432)
coldfusion.runtime.TemplateProxy.invoke(TemplateProxy.java:402)
coldfusion.runtime.CfJspPage._invoke(CfJspPage.java:2483)
cfApplication2ecfc1936685633$funcONREQUESTSTART.runFunction(/opt/myapp/at2/web/go/Application.cfc:104)
coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:487)
coldfusion.runtime.UDFMethod$ReturnTypeFilter.invoke(UDFMethod.java:420)
coldfusion.runtime.UDFMethod$ArgumentCollectionFilter.invoke(UDFMethod.java:383)
coldfusion.filter.FunctionAccessFilter.invoke(FunctionAccessFilter.java:95)
coldfusion.runtime.UDFMethod.runFilterChain(UDFMethod.java:334)
coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:231)
coldfusion.runtime.TemplateProxy.invoke(TemplateProxy.java:643)
coldfusion.runtime.TemplateProxy.invoke(TemplateProxy.java:432)
coldfusion.runtime.TemplateProxy.invoke(TemplateProxy.java:402)
coldfusion.runtime.AppEventInvoker.invoke(AppEventInvoker.java:108)
coldfusion.runtime.AppEventInvoker.onRequestStart(AppEventInvoker.java:279)
coldfusion.filter.ApplicationFilter.invoke(ApplicationFilter.java:463)
coldfusion.filter.RequestMonitorFilter.invoke(RequestMonitorFilter.java:42)
coldfusion.filter.MonitoringFilter.invoke(MonitoringFilter.java:40)
coldfusion.filter.PathFilter.invoke(PathFilter.java:153)
coldfusion.filter.ExceptionFilter.invoke(ExceptionFilter.java:94)
coldfusion.filter.ClientScopePersistenceFilter.invoke(ClientScopePersistenceFilter.java:28)
coldfusion.filter.BrowserFilter.invoke(BrowserFilter.java:38)
coldfusion.filter.NoCacheFilter.invoke(NoCacheFilter.java:58)
coldfusion.filter.GlobalsFilter.invoke(GlobalsFilter.java:38)
coldfusion.filter.DatasourceFilter.invoke(DatasourceFilter.java:22)
coldfusion.filter.CachingFilter.invoke(CachingFilter.java:62)
coldfusion.CfmServlet.service(CfmServlet.java:219)
coldfusion.bootstrap.BootstrapServlet.service(BootstrapServlet.java:89)
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303)
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
coldfusion.monitor.event.MonitoringServletFilter.doFilter(MonitoringServletFilter.java:42)
coldfusion.bootstrap.BootstrapFilter.doFilter(BootstrapFilter.java:46)
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
sun.reflect.GeneratedMethodAccessor79.invoke(Unknown Source)
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
java.lang.reflect.Method.invoke(Method.java:483)
com.intergral.fusionreactor.j2ee.filterchain.WrappedFilterChain.doFilter(WrappedFilterChain.java:134)
com.intergral.fusionreactor.j2ee.filter.FusionReactorRequestHandler.doNext(FusionReactorRequestHandler.java:802)
com.intergral.fusionreactor.j2ee.filter.FusionReactorRequestHandler.doHttpServletRequest(FusionReactorRequestHandler.java:339)
com.intergral.fusionreactor.j2ee.filter.FusionReactorRequestHandler.doFusionRequest(FusionReactorRequestHandler.java:215)
com.intergral.fusionreactor.j2ee.filter.FusionReactorRequestHandler.handle(FusionReactorRequestHandler.java:839)
com.intergral.fusionreactor.j2ee.filter.FusionReactorCoreFilter.doFilter(FusionReactorCoreFilter.java:36)
sun.reflect.GeneratedMethodAccessor82.invoke(Unknown Source)
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
java.lang.reflect.Method.invoke(Method.java:483)
com.intergral.fusionreactor.j2ee.filterchain.WrappedFilterChain.doFilter(WrappedFilterChain.java:71)
sun.reflect.GeneratedMethodAccessor78.invoke(Unknown Source)
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
java.lang.reflect.Method.invoke(Method.java:483)
com.intergral.fusionreactor.agent.filter.FusionReactorStaticFilter.doFilter(FusionReactorStaticFilter.java:53)
com.intergral.fusionreactor.agent.pointcuts.NewFilterChainPointCut$1.invoke(NewFilterChainPointCut.java:41)
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java)
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220)
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122)
org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:505)
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:169)
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:450)
org.apache.coyote.ajp.AjpProcessor.process(AjpProcessor.java:197)
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:625)
org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316)
 - locked <0x44308842> (a org.apache.tomcat.util.net.SocketWrapper)
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
java.lang.Thread.run(Thread.java:745)

Locked ownable synchronizers:
    - java.util.concurrent.ThreadPoolExecutor$Worker@1bc7eb36

any idea for this problem?

[br...@bradwood.com]

Can't say I've seen that one before.  Is your CF11 box fully patched?

 

The next time this happens, pull a _FULL_ thread dump of the entire JVM.  I need to see the other thread that's blocking this one to see what its doing.  In the case below, it was a thread named  thread 94030, ajp-bio-8014-exec-3054

 

Thanks!

~Brad

ColdBox/CommandBox Developer Advocate
Ortus Solutions, Corp

E-mail: br...@coldbox.org
ColdBox Platform: http://www.coldbox.org
Blog: http://www.codersrevolution.com 

 

 

--------- Original Message ---------

--
--
You received this message because you are subscribed to the Google Groups "ColdBox Platform" group.
For News, visit http://blog.coldbox.org
For Documentation, visit http://wiki.coldbox.org
For Bug Reports, visit https://ortussolutions.atlassian.net/browse/COLDBOX
---
You received this message because you are subscribed to the Google Groups "ColdBox Platform" group.
To unsubscribe from this group and stop receiving emails from it, send an email to coldbox+u...@googlegroups.com.
To post to this group, send email to col...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/coldbox/45715b89-2c44-417d-a7c7-4db0aa7af40f%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[cubortea]

FYI, my coldfusion version is 11,0,12,302575
after I restart my cfserver, I never get this problem now. I will check again later

[cubortea]

Hi Brad,

I've got again this problem in my server, after I trace the thread error. I found the problem is at coldbox logger

....coldbox/system/logging/Logger.cfc:344)

when I open the code in line 344:

thread action="run" name="#threadName#" logEvent="#logEvent#" thisAppender="#thisAppender#"{
     attributes.thisAppender.logMessage( attributes.logEvent );
}

The 2 process which were deadlock run almost at the same time. Maybe you know about this issue already ?

Thanks

Andri

On Thursday, May 18, 2017 at 5:08:37 AM UTC+7, Brad Wood wrote:

[br...@bradwood.com]

Please see my last reply.  I need a full thread dump of the JVM to help you.  I'm already aware of what line was getting help up-- that information was in your first E-mail, but that line number doesn't really mean anything.  We need to know what thread holds the lock and what that thread is doing.  And that is why I asked you to provide a full thread dump.  I can't help you until you do that.

--------- Original Message ---------

To view this discussion on the web visit https://groups.google.com/d/msgid/coldbox/4ad15e8d-bdc0-49a6-a517-cb6bb63aee10%40googlegroups.com.

[cubortea]

Hi Brad,

After I check on the thread info, the problem is at the logbox process. 
I have logbox appender with RollingFileAppender and with property async=true, and when there are 2 process log run in the same time it will lock each other.

the locked problem is at:

coldbox/system/logging/Logger.cfc:344)

After I change my logbox setting to async=false, everything are ok now.

Thanks

ANdri

[br...@bradwood.com]

The problem is unlikely to be with LogBox at all.  The thread in your original post was waiting on ColdFusion to search through scopes to find a variable.  There's nothing LogBox could do to affect that.  I have a feeling the issue is hitting scopes like cgi after the HTTP thread has completed.  This used to cause issues in older versions of ColdFusion but I thought they fixed those bugs.  I'd make sure you're on the latest update of Adobe CF 11 and please provide a full thread dump.  If this is still an issue in CF11, we'll want to report it.

--------- Original Message ---------

To view this discussion on the web visit https://groups.google.com/d/msgid/coldbox/afce872e-b991-4f18-9525-a1a31601ff08%40googlegroups.com.