3

I have a large report. The SQL only takes about 60 seconds to run but the actual rendering of the PDF is what takes up all the time. It has hundreds of pages.

The global setting for request timeouts is set to 240 seconds.

I am overriding the Global setting for this report and setting the value arbitrarily high (3600 seconds). realistically this report can't take more than 15 min to complete.

Regardless of how high I set the timeout this page will generate the time limit error well before it hits my timeout.

The SQL can take anywhere from 24 seconds to 4 min to complete depending on how many areas are selected.

Even though I am overriding the timeout, the page generates the error about 170 seconds (only one data point for that) after completing the queries. So this is happening sometimes even a full minute before the global timeout is hit.

Is there a limit to how much time a cfdocument can take to render a PDF?

Is there a way to increase that timeout?

Could this be related to something else like the maximum output buffer size?

here is a custom function I'm using to test what the requesttimeout is:

<cffunction name="getCurrentRequestTimeout" output="false" access="private" returntype="numeric">
    <cfset var rcMonitor = createObject("java", "coldfusion.runtime.RequestMonitor") />
    <cfreturn rcMonitor.getRequestTimeout() />
</cffunction>

I placed that in a couple spots to determine if the timeout was being set properly. In all cases it returned 3600 seconds.

Edit, here's another clue:

This report cross references data from 8 other queries (which have already been run in the controller) it does the cross referencing in the view. About a year ago we sped this up considerably (taking the run time from 1 hour down to 10 min) by creating hashes for the queries we were cross referencing. A task came through to completely remove 4 of the queries we were hashing from the report. Once I pulled those BuildHashTable function calls out of the view and removed all references to those queries the page no longer crashes after 3 min, it now takes 7.5 min to fail. 

coldfusion.runtime.RequestTimedOutException: The request has exceeded the allowable time limit Tag: cfoutput
at coldfusion.tagext.io.OutputTag.doStartTag(OutputTag.java:72)
at cfdump2ecfm625244097._factor54(/WEB-INF/cftags/dump.cfm:118)
at cfdump2ecfm625244097.runPage(/WEB-INF/cftags/dump.cfm:1)
at coldfusion.runtime.CfJspPage.invoke(CfJspPage.java:246)
at coldfusion.filter.CFVariablesScopeFilter.invoke(CFVariablesScopeFilter.java:56)
at coldfusion.tagext.lang.ModuleTag.doStartTag(ModuleTag.java:332)
at coldfusion.runtime.CfJspPage._emptyTcfTag(CfJspPage.java:2991)
at cfonerror2ecfm289163184.runPage(D:\CF11\facilopstest\wwwroot\HFDS\events\onerror.cfm:8)
at coldfusion.runtime.CfJspPage.invoke(CfJspPage.java:246)
at coldfusion.tagext.lang.IncludeTag.handlePageInvoke(IncludeTag.java:736)
at coldfusion.tagext.lang.IncludeTag.doStartTag(IncludeTag.java:572)
at coldfusion.runtime.CfJspPage._emptyTcfTag(CfJspPage.java:2991)
at cfcfml2ecfm2118004321$func$INCLUDEANDRETURNOUTPUT.runFunction(D:\CF11\facilopstest\wwwroot\HFDS\wheels\global\cfml.cfm:138)
at coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:487)
at coldfusion.filter.SilentFilter.invoke(SilentFilter.java:47)
at coldfusion.runtime.UDFMethod$ReturnTypeFilter.invoke(UDFMethod.java:420)
at coldfusion.runtime.UDFMethod$ArgumentCollectionFilter.invoke(UDFMethod.java:383)
at coldfusion.filter.FunctionAccessFilter.invoke(FunctionAccessFilter.java:95)
at coldfusion.runtime.UDFMethod.runFilterChain(UDFMethod.java:334)
at coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:533)
at coldfusion.runtime.CfJspPage._invokeUDF(CfJspPage.java:2810)
at cfonerror2ecfm1534078820$func$RUNONERROR.runFunction(D:\CF11\facilopstest\wwwroot\HFDS\wheels\events\onerror.cfm:65)
at coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:487)
at coldfusion.filter.SilentFilter.invoke(SilentFilter.java:47)
at coldfusion.runtime.UDFMethod$ReturnTypeFilter.invoke(UDFMethod.java:420)
at coldfusion.runtime.UDFMethod$ArgumentCollectionFilter.invoke(UDFMethod.java:383)
at coldfusion.filter.FunctionAccessFilter.invoke(FunctionAccessFilter.java:95)
at coldfusion.runtime.UDFMethod.runFilterChain(UDFMethod.java:334)
at coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:533)
at coldfusion.runtime.CfJspPage._invokeUDF(CfJspPage.java:2810)
at coldfusion.tagext.lang.InvokeTag.doEndTag(InvokeTag.java:493)
at coldfusion.runtime.CfJspPage._emptyTcfTag(CfJspPage.java:2992)
at cfcfml2ecfm2118004321$func$SIMPLELOCK.runFunction(D:\CF11\facilopstest\wwwroot\HFDS\wheels\global\cfml.cfm:44)
at coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:487)
at coldfusion.filter.SilentFilter.invoke(SilentFilter.java:47)
at coldfusion.runtime.UDFMethod$ReturnTypeFilter.invoke(UDFMethod.java:420)
at coldfusion.runtime.UDFMethod$ArgumentCollectionFilter.invoke(UDFMethod.java:383)
at coldfusion.filter.FunctionAccessFilter.invoke(FunctionAccessFilter.java:95)
at coldfusion.runtime.UDFMethod.runFilterChain(UDFMethod.java:334)
at coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:533)
at coldfusion.runtime.CfJspPage._invokeUDF(CfJspPage.java:2810)
at cfonerror2ecfm1534078820$funcONERROR.runFunction(D:\CF11\facilopstest\wwwroot\HFDS\wheels\events\onerror.cfm:14)
at coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:487)
at coldfusion.runtime.UDFMethod$ReturnTypeFilter.invoke(UDFMethod.java:420)
at coldfusion.runtime.UDFMethod$ArgumentCollectionFilter.invoke(UDFMethod.java:383)
at coldfusion.filter.FunctionAccessFilter.invoke(FunctionAccessFilter.java:95)
at coldfusion.runtime.UDFMethod.runFilterChain(UDFMethod.java:334)
at coldfusion.runtime.UDFMethod.invoke(UDFMethod.java:231)
at coldfusion.runtime.TemplateProxy.invoke(TemplateProxy.java:643)
at coldfusion.runtime.TemplateProxy.invoke(TemplateProxy.java:432)
at coldfusion.runtime.TemplateProxy.invoke(TemplateProxy.java:402)
at coldfusion.runtime.AppEventInvoker.invoke(AppEventInvoker.java:108)
at coldfusion.runtime.AppEventInvoker.onError(AppEventInvoker.java:491)
at coldfusion.filter.ApplicationFilter.invoke(ApplicationFilter.java:532)
at coldfusion.filter.RequestMonitorFilter.invoke(RequestMonitorFilter.java:42)
at coldfusion.filter.MonitoringFilter.invoke(MonitoringFilter.java:40)
at coldfusion.filter.PathFilter.invoke(PathFilter.java:142)
at coldfusion.filter.ExceptionFilter.invoke(ExceptionFilter.java:94)
at coldfusion.filter.BrowserDebugFilter.invoke(BrowserDebugFilter.java:78)
at coldfusion.filter.ClientScopePersistenceFilter.invoke(ClientScopePersistenceFilter.java:28)
at coldfusion.filter.BrowserFilter.invoke(BrowserFilter.java:38)
at coldfusion.filter.NoCacheFilter.invoke(NoCacheFilter.java:58)
at coldfusion.filter.GlobalsFilter.invoke(GlobalsFilter.java:38)
at coldfusion.filter.DatasourceFilter.invoke(DatasourceFilter.java:22)
at coldfusion.filter.CachingFilter.invoke(CachingFilter.java:62)
at coldfusion.CfmServlet.service(CfmServlet.java:219)
at coldfusion.bootstrap.BootstrapServlet.service(BootstrapServlet.java:89)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at coldfusion.monitor.event.MonitoringServletFilter.doFilter(MonitoringServletFilter.java:42)
at coldfusion.bootstrap.BootstrapFilter.doFilter(BootstrapFilter.java:46)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:505)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:170)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:437)
at org.apache.coyote.ajp.AjpProcessor.process(AjpProcessor.java:197)
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:625)
at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:745)

Windows server 2008 running ColdFusion 11,0,07,296330 Enterprise

gnarbarian
  • 2,622
  • 2
  • 19
  • 25
  • 1
    By what method are you overriding the global timeout? – Dan Bracuk Jan 12 '16 at 03:47
  • I'm using setting requesttimeout="3600"; in the controller and in the view. (this is a cfwheels app) Then I'm using a function I attached to the Controller's superclasss I found to test what the request timeout is. (added to question) – gnarbarian Jan 12 '16 at 03:51
  • Are you sure you mean rendering, as opposed to creating the pdf? – Dan Bracuk Jan 12 '16 at 03:56
  • You're right @Dan_Bracuk That is a clearer way to put it. – gnarbarian Jan 12 '16 at 03:58
  • Can you add the stack trace to your question? – Miguel-F Jan 12 '16 at 12:44
  • 1
    The timeout might be caused within cfdocument which make it look like a request timeout when it's not. What CF version are you using? Is it Developer, Standard or Enterprise? You might be running out of memory during creation. How large do you think, the PDF would end up? – Alex Jan 12 '16 at 19:52
  • @Miguel-F Added stacktrack and server version. – gnarbarian Jan 12 '16 at 20:22
  • @Alex Coldfusion 11,0,07296330 Enteprise PDF looks like the PDF ends up being about 16 megs for the largest ones. and 1.6 megs when run for a smaller area. I increased the output buffer size to 100 megs but it didn't help. – gnarbarian Jan 12 '16 at 20:22

2 Answers2

1

I would suggest moving your PDF logic off to a cfthread spawn. Requests really aren't suited to handle that long of a request so you're probably getting a browser timeout rather than a ColdFusion timeout. But I don't have enough information from your description to determine that.

Chris Tierney
  • 1,539
  • 1
  • 8
  • 16
  • Could it still be a browser timeout when many reports in other areas of the app successfully complete after much longer time periods ie 15 min? EDIT: Still getting the error after disabling timeouts in firefox. – gnarbarian Jan 12 '16 at 00:44
  • then it's probably not a browser timeout... but a thread is still a good idea in any case. A user won't wait around on their browser 15 minutes for a report to finish if that's your audience, so you'll want to notify them when it's available. – Chris Tierney Jan 12 '16 at 01:15
  • @Chris_Tierney I solved it. the problem was a cartesian product which may have been blowing up the memory. Still no idea why it would trigger a timeout way ahead of time but at least it's fixed in this instance. – gnarbarian Feb 10 '16 at 01:28
0

I solved it. the problem was a cartesian product which may have been blowing up the memory. It caused some loops in the output to run for much much longer than intended. I'm assuming this inflated the size to such a degree that it would crash. Still no idea why it would trigger a timeout way ahead of time but at least it's fixed.

gnarbarian
  • 2,622
  • 2
  • 19
  • 25