Vague loop timeout

[Brian Pickens]

Hey gang,

We've discovered a vague loop timeout error, occurring within the mach-
ii code, in our cf error logs. Do you have any ideas on how I can
troubleshoot this problem? This is just a partial:

"Error","jrpp-3908","06/30/09","09:04:37","cms_v3","The request has
exceeded the allowable time limit Tag: CFLOOP The specific sequence of
files included or processed is: /home/cms/public_html/index.cfm, line:
161 "
coldfusion.runtime.RequestTimedOutException: The request has exceeded
the allowable time limit Tag: CFLOOP
at coldfusion.runtime.CfJspPage.checkRequestTimeout
(CfJspPage.java:2846)
at cfEvent2ecfc1025831723$funcSETARGS.runFunction(/home/cms/
public_html/MachII/framework/Event.cfc:161)
at coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:418)
at coldfusion.filter.SilentFilter.invoke(SilentFilter.java:47)
at coldfusion.runtime.UDFMethod$ReturnTypeFilter.invoke
(UDFMethod.java:360)
at coldfusion.runtime.UDFMethod$ArgumentCollectionFilter.invoke
(UDFMethod.java:324)
at coldfusion.filter.FunctionAccessFilter.invoke
(FunctionAccessFilter.java:59)
at coldfusion.runtime.UDFMethod.runFilterChain(UDFMethod.java:
277)
at coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:192)
at coldfusion.runtime.CfJspPage._invokeUDF(CfJspPage.java:2471)
at cfEvent2ecfc1025831723$funcINIT.runFunction(/home/cms/
public_html/MachII/framework/Event.cfc:57)
at coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:418)
at coldfusion.filter.SilentFilter.invoke(SilentFilter.java:47)
at coldfusion.runtime.UDFMethod$ReturnTypeFilter.invoke
(UDFMethod.java:360)
at coldfusion.runtime.UDFMethod$ArgumentCollectionFilter.invoke
(UDFMethod.java:324)
at coldfusion.filter.FunctionAccessFilter.invoke
(FunctionAccessFilter.java:59)
at coldfusion.runtime.UDFMethod.runFilterChain(UDFMethod.java:
277)
at coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:192)
at coldfusion.runtime.TemplateProxy.invoke(TemplateProxy.java:
448)
at coldfusion.runtime.TemplateProxy.invoke(TemplateProxy.java:
308)
at coldfusion.runtime.CfJspPage._invoke(CfJspPage.java:2272)
at cfEventManager2ecfc1832325542$funcCREATEEVENT.runFunction(/
home/cms/public_html/MachII/framework/EventManager.cfc:201)

[Matthew Woodward]

Brian Pickens wrote:
> Hey gang,
>
> We've discovered a vague loop timeout error, occurring within the mach-
> ii code, in our cf error logs. Do you have any ideas on how I can
> troubleshoot this problem? This is just a partial:

Well, remember that Mach-II is handling requests for your application
code, so there's something in your code that's exceeding your loop timeout.

Is this on app startup?

Have you tried adding a really long requesttimeout to the URL to see if
it ever finishes?

I'd say start by looking at the event in question and see what might be
timing out--big db query, call to an external resource like a web
service, large and/or nested loops ... all those could be the culprit.

Beyond that, just start putting breakpoints in the event to see how far
it gets before it starts timing out.

--
Matthew Woodward
ma...@mattwoodward.com
http://www.mattwoodward.com/blog

Please do not send me proprietary file formats such as Word, PowerPoint,
etc. as attachments.
http://www.gnu.org/philosophy/no-word-attachments.html

[Brian Pickens]

We weren't seeing this on the website at all but it only appeared in
the error log so there is no way I can see to find out which event the
timeout was occurring in.
But I just found out from our systems guys that this was occurring
while our systems requests were through the roof so now I suspect this
is a symptom of that.

On Jun 30, 10:17 am, Matthew Woodward <m...@mattwoodward.com> wrote:
> Brian Pickens wrote:
> > Hey gang,
>
> > We've discovered a vague loop timeout error, occurring within the mach-
> > ii code, in our cf error logs. Do you have any ideas on how I can
> > troubleshoot this problem? This is just a partial:
>
> Well, remember that Mach-II is handling requests for your application
> code, so there's something in your code that's exceeding your loop timeout.
>
> Is this on app startup?
>
> Have you tried adding a really long requesttimeout to the URL to see if
> it ever finishes?
>
> I'd say start by looking at the event in question and see what might be
> timing out--big db query, call to an external resource like a web
> service, large and/or nested loops ... all those could be the culprit.
>
> Beyond that, just start putting breakpoints in the event to see how far
> it gets before it starts timing out.
>
> --
> Matthew Woodward

> m...@mattwoodward.comhttp://www.mattwoodward.com/blog

>
> Please do not send me proprietary file formats such as Word, PowerPoint,
> etc. as attachments.http://www.gnu.org/philosophy/no-word-attachments.html
>

>  smime.p7s
> 4KViewDownload

[Peter J. Farrell]

Brian Pickens said the following on 06/30/2009 10:58 AM:

> We weren't seeing this on the website at all but it only appeared in
> the error log so there is no way I can see to find out which event the
> timeout was occurring in.
> But I just found out from our systems guys that this was occurring
> while our systems requests were through the roof so now I suspect this
> is a symptom of that.
>

Vague request timeouts are symptomatic of:

* too short default request timeouts when under high load
* Inefficient / slow queries and/or logic
* too short default request timeout when loading your application (see
the MACHII_ONLOAD_REQUEST_TIMEOUT in the bootstraper -- see the wiki)

You can add an onError() method to your Application.cfc to process some
more information. It's subject to your request timeout setting so you
only have only 40-50ms when it catches this type of exception. You can
increase the request time out to a longer setting using cfsetting in
your onError() to get around this problem and show a nice error to the
user (I like a static page because it's hard on the server stack).

.pjf

[Brian Pickens]

Very nice, thanks Peter and Matt. If we continue to have this issue
your guys' suggestions will be very useful.