tracker issue : CF-4198342

select a category, or use search below
(searches all categories and all time range)
Title:

cfdocument timeout

| View in Tracker

Status/Resolution/Reason: To Fix/Withdrawn/BugVerified

Reporter/Name(from Bugbase): Cody W / Cody W ()

Created: 02/16/2017

Components: Document Management, PDF generation

Versions: 2016,2018

Failure Type: Usability Issue

Found In Build/Fixed In Build: 2016,0,03,300357 or any other /

Priority/Frequency: Normal / Few users will encounter

Locale/System: / Win 2012 Server x64

Vote Count: 7

Problem Description:
Intermittently, cfdocument will simply stop working completely. We're using the below code to generate a PDF, and it simply times out.

<cfdocument format="PDF">
<cfoutput>test</cfoutput>
</cfdocument>

You can set the timeout to be any length you want, and cfdocument will still fail to generate even a simple PDF. I've attached a stack trace from SeeFusion when the request was stuck as "cfdocument_while_running.txt". I've attached a stack trace provided by ColdFusion after the timeout as "cfdocument_after_timeout.txt". If any more information is needed, we're happy to provide it as this happens on a somewhat regular basis across several servers.

Steps to Reproduce:
Try to use cfdocument with any content.

Actual Result:
Error Occurred While Processing Request
The content of this document process takes more than 300000 milliseconds to process.

Expected Result:
PDF with the word "test" in it.

Attachments:

  1. February 16, 2017 00:00:00: cfdocument_after timeout.txt
  2. February 16, 2017 00:00:00: cfdocument_while_running.txt

Comments:

Hi, How often does this issue occur? Also, how much load is there in the system that the issue starts coming? Also, are you running some other requests too along with the one shared? Thanks, Kailash
Comment by Kailash B.
1169 | March 10, 2017 09:40:05 AM GMT
Hello, The issue occurs intermittently. There is very little load. The server is a shared hosting server, so it's very likely that other requests are running at the same time when the issue begins. However, once cfdocument breaks, it will continue to timeout regardless of server load or lack of other requests. To be clear, once cfdocument quits working, there could be no other ColdFusion requests running and it will still timeout. Thanks, Cody W
Comment by Cody W.
1170 | April 06, 2017 02:27:54 PM GMT
Any chance we could get an update on this? This issue is intermittent and keeps causing us to have to restart ColdFusion. Each time, the stack trace is almost identical and gets stuck in the following pattern. at coldfusion.util.Waiter.getResponse(Waiter.java:44) at coldfusion.document.DocumentProcessor.processContent(DocumentProcessor.java:274) at coldfusion.document.DocumentProcessor.processContent(DocumentProcessor.java:179) at coldfusion.tagext.lang.DocumentTag.processContent(DocumentTag.java:1868) at coldfusion.tagext.lang.DocumentTag.access$200(DocumentTag.java:136)
Comment by Cody W.
1171 | September 26, 2017 05:23:08 PM GMT
Hi Cody, As we don't have a specific test case, we will see how best we could check this in the code. It always helps if you could share isolated reproducible code so that we can fix the same quickly. Thanks, Kailash
Comment by Kailash B.
1172 | October 03, 2017 10:37:59 AM GMT
We have experienced this same issue. It seems the issue is triggered when more than one person hits the same cfdocument process at the same time. I would consider this a major issue as it impacts reporting under load.
Vote by Mark P.
1175 | January 24, 2018 08:17:16 PM GMT
We have experienced this same issue. It seems the issue is triggered when more than one person hits the same cfdocument process at the same time. Mark
Comment by Mark P.
1173 | January 24, 2018 08:18:03 PM GMT
We are implementing a pay-for-pdf system with CF, and have just hit this issue in a VPS environment. CFDOCUMENT causes the server to hang, then we get the Internal Server Error message after timing out. After this, any other CFDOCUMENT process encounters the same problem, even using this simple CFDOCUMENT code: <cfdocument format="pdf" mimetype="text/html"> This is a test pdf. </cfdocument>
Comment by Chris R.
1174 | March 02, 2018 04:55:46 PM GMT
Hi,   It has been 5 months since the last update. Just checking if this is working for you? If not, can we get on a call to see when the issue is happening? You can email me at [bihani@adobe.com|mailto:bihani@adobe.com]    Thanks, Kailash
Comment by Kailash B.
29577 | August 21, 2018 07:24:32 AM GMT
Closing it for now. We will reopen it again once user comes back.
Comment by Kailash B.
29649 | August 30, 2018 07:16:55 AM GMT
This same behavior has recently represented itself in one of our production environments. <cfdocument> tags will suddenly begin timing out with no explanation. ColdFusion is stuck waiting on "processContent" as reported in earlier incidents. at coldfusion.util.Waiter.getResponse(Waiter.java:44) - locked <0x000000072b969cb0> (a coldfusion.util.Waiter) at coldfusion.document.DocumentProcessor.processContent(DocumentProcessor.java:274) at coldfusion.document.DocumentProcessor.processContent(DocumentProcessor.java:179) at coldfusion.tagext.lang.DocumentTag.processContent(DocumentTag.java:1868) at coldfusion.tagext.lang.DocumentTag.access$200(DocumentTag.java:136) This issue is intermittent and isn't reproducible. Restarting ColdFusion fixes this issue when it presents itself.
Comment by dakota c.
29909 | November 08, 2018 06:58:11 PM GMT
This issue has once again presented itself in a separate production environment. Here is the AJP request starting at CfmServlet that shows this behavior occurring. This request will eventually timeout on processContent as mentioned in previous responses. java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) at coldfusion.util.Waiter.getResponse(Waiter.java:44) - locked <0x00000007b3bd1c90> (a coldfusion.util.Waiter) at coldfusion.document.DocumentProcessor.processContent(DocumentProcessor.java:274) at coldfusion.document.DocumentProcessor.processContent(DocumentProcessor.java:179) at coldfusion.tagext.lang.DocumentTag.processContent(DocumentTag.java:1868) at coldfusion.tagext.lang.DocumentTag.access$200(DocumentTag.java:136) at coldfusion.tagext.lang.DocumentTag$6.run(DocumentTag.java:1777) at java.security.AccessController.doPrivileged(Native Method) at coldfusion.tagext.lang.DocumentTag._processContent(DocumentTag.java:1773) at coldfusion.tagext.lang.DocumentTag.doAfterBody(DocumentTag.java:1701) at cftestPDF2ecfm71332642.runPage(D:\home\TestDomainHere.com\wwwroot\testPDF.cfm:15) 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.filter.CfincludeFilter.invoke(CfincludeFilter.java:65) at coldfusion.filter.IpFilter.invoke(IpFilter.java:45) at coldfusion.filter.ApplicationFilter.invoke(ApplicationFilter.java:495) at coldfusion.filter.RequestMonitorFilter.invoke(RequestMonitorFilter.java:42) at coldfusion.filter.MonitoringFilter.invoke(MonitoringFilter.java:40) at coldfusion.filter.PathFilter.invoke(PathFilter.java:153) at coldfusion.filter.ExceptionFilter.invoke(ExceptionFilter.java:94) 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) --- This issue is sudden and begins occurring with no explanation. It could be weeks before the issue presents itself. When the issue does arise a restart of ColdFusion is required.
Comment by dakota c.
30162 | January 31, 2019 03:42:45 PM GMT
Hi Kailash, Perhaps 2 simultaneous requests hitting <cfdocument> triggers a deadlock w/ infinite timeout? Could you check that scenario? Thanks!, -Aaron
Comment by Aaron N.
30168 | February 01, 2019 09:52:16 AM GMT
Reopening the bug as the user is still seeing the issue Can you please share the complete thread dump when you hit the issue? Do share 7-8 thread dumps taken with a time interval of 10 seconds gap between each Also, is there any case where you might have used a html img tag with empty source? It will look something like: {code:java} <img src="" />{code}  
Comment by Kailash B.
30193 | February 05, 2019 08:57:19 AM GMT
I'm seeing a very similar issue, but when PDFs start hanging on the server, there are two threads that get deadlocked which is what caused all other threads to timeout. Here is the top of the stack from the HTTP request that first hung and is deadlocked: "ajp-bio-8014-exec-1" Id=135 BLOCKED on com.icesoft.util.trackers.RenderDoneTracker@36c4a013 owned by "AWT-EventQueue-0" Id=1518 java.lang.Thread.State: BLOCKED at com.icesoft.util.trackers.RenderDoneTracker.propertyChange(RenderDoneTracker.java:111) - waiting to lock com.icesoft.util.trackers.RenderDoneTracker@36c4a013 owned by "AWT-EventQueue-0" at ice.storm.StormBase.firePropertyChangeEvent(StormBase.java:615) at ice.storm.StormBase.sendViewportMessage(StormBase.java:595) at ice.storm.StormBase.renderViewportContent(StormBase.java:938) at ice.storm.StormBase.renderContent(StormBase.java:914) at com.icesoft.util.PageDecorator.HeaderFooterDecoration.paint(HeaderFooterDecoration.java:117) - locked java.lang.Object@51cc3e14 at ice.pilots.html4.ThePrinter.printPage(ThePrinter.java:187) at coldfusion.document.DocumentSection.print(DocumentSection.java:144) at coldfusion.tagext.lang.DocumentTag.printSection(DocumentTag.java:1796) at coldfusion.tagext.lang.DocumentTag.doAfterBody(DocumentTag.java:1674) at cfehPDF2ecfc1151364043$funcPDF132.runFunction(D:\HTTP\site\handlers\ehPDF.cfc:160) And here is the other thread (not an HTTP request) that it is deadlocked with) com.icesoft.util.PageDecorator.HeaderFooterDecoration.renderingDone(HeaderFooterDecoration.java:333) - waiting on <0x51cc3e14> (a java.lang.Object held by thread 135, ajp-bio-8014-exec-1) com.icesoft.util.trackers.RenderDoneTracker.notifyListeners(RenderDoneTracker.java:282) - locked <0x36c4a013> (a com.icesoft.util.trackers.RenderDoneTracker) com.icesoft.util.trackers.RenderDoneTracker.forceReset(RenderDoneTracker.java:92) com.icesoft.util.trackers.RenderDoneTracker.propertyChange(RenderDoneTracker.java:229) - locked <0x36c4a013> (a com.icesoft.util.trackers.RenderDoneTracker) ice.storm.StormBase.firePropertyChangeEvent(StormBase.java:615) ice.storm.StormBase.sendViewportMessage(StormBase.java:595) ice.storm.Pilot.firePropertyChange(Pilot.java:247) ice.pilots.html4.ObjectPool.fireOutstandingImagesEvent(ObjectPool.java:80) ice.pilots.html4.ObjectPool.fireOutstandingImagesEvent(ObjectPool.java:85) ice.pilots.html4.ThePilot.onLoadingDone(ThePilot.java:986) ice.storm.Viewport$4.run(Viewport.java:996) java.awt.event.InvocationEvent.dispatch(InvocationEvent.java:311) java.awt.EventQueue.dispatchEventImpl(EventQueue.java:756) java.awt.EventQueue.access$500(EventQueue.java:97) java.awt.EventQueue$3.run(EventQueue.java:709) java.awt.EventQueue$3.run(EventQueue.java:703) java.security.AccessController.doPrivileged(Native Method) java.security.ProtectionDomain$JavaSecurityAccessImpl.doIntersectionPrivilege(ProtectionDomain.java:80) java.awt.EventQueue.dispatchEvent(EventQueue.java:726) java.awt.EventDispatchThread.pumpOneEventForFilters(EventDispatchThread.java:201) java.awt.EventDispatchThread.pumpEventsForFilter(EventDispatchThread.java:116) java.awt.EventDispatchThread.pumpEventsForHierarchy(EventDispatchThread.java:105) java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:101) java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:93) java.awt.EventDispatchThread.run(EventDispatchThread.java:82) This appears so be some sort of race condition in the underlying Java icesoft library. It's happened twice in the course of 2 weeks on a new site my client has deployed, but I don't know how to force it to happen on demand.
Comment by Bradley W.
30613 | April 09, 2019 05:52:27 PM GMT
@{color:#333333}Bradley W, Can you please share the test case?{color}
Comment by Amit S.
30620 | April 10, 2019 09:06:47 AM GMT
Amit, not sure what you mean by "test case", it's just a CFDocument tag with a header and footer that turns HTML into a PDF. The only thing interesting i the stack is it seems to imply that the "headerfootdecoration" is part of the issue. The header just had some text inside of <font> tags and the footer just said "Page X of Y". I can't share the exact code as it's part of a govt app and wouldn't run stand alone.
Comment by Bradley W.
30621 | April 10, 2019 05:56:35 PM GMT
I'll add that I also reviewed some of the source code of the open source version of IcePDF and the deadlock is centered around the synchronized blocks of code in there. I'm sure examining the Java source code of the IcePDF Java library that ColdFusion uses under the hood will help reveal the scenario in which a deadlock can happen. That said, i also acknowledge that IcePDF is a 3rd party library bundled in Adobe ColdFusion and CF11 is likely on an older version of it. Can Adobe comment on what version of IcePDF is in use? I was unable to determine based on how the jar files seem to be "shaded" into the cfusion.jar and not directly placed in the cfusion/lib folder. I'm unclear on whether Adobe has been updating the IcePDF library in ColdFusion 11, or just left it at whatever version was out when CF11 shipped years ago.
Comment by Bradley W.
30622 | April 10, 2019 06:02:17 PM GMT
Hi Brad,   Does it happen only in CF 11 for you or in all versions of CF? Please let us know the version of CF and the current hotfix number applied to it. Also, are you able to repro it consistently?   Thanks, Kailash
Comment by Kailash B.
30630 | April 15, 2019 10:37:28 AM GMT
Kailash, my client is using CF 11 update 18. They don't have any 2016 or 2018 licenses yet so this code has not been deployed in production on anything other than CF11. After we pushed our new site to production, the issue happened 2 times in about 3 weeks. I have already converted the site to use cfhtmltopdf as we couldn't keep this buggy stuff in production.
Comment by Bradley W.
30638 | April 19, 2019 04:08:37 AM GMT
We have been getting this cfdocument error on our production server. Only way we are able to resolve is by re-starting the server.
Vote by Praveen S.
30641 | April 19, 2019 09:21:28 PM GMT
Kailash, we have this issue in ColdFusion 10 and 2016 versions. We are currently migrating from ColdFusion 10 to ColdFusion 2016 so I can confirm that it is a problem in both versions.
Comment by Praveen S.
30640 | April 19, 2019 09:23:29 PM GMT
Hi Praveen,   Can you share a specific case (I mean the code you are using) after which you start facing this issue?   Thanks, Kailash
Comment by Kailash B.
30646 | April 22, 2019 07:06:38 AM GMT
Yes, this is a synchronization issue in IcePDF. Adobe can provide you with a hotfix jar to remove this lock. This is most likely a duplicate of my bug https://tracker.adobe.com/#/view/CF-4205442 . They have fix, they just need to add it to the mainstream release.
Comment by Aaron W.
31782 | November 07, 2019 03:38:07 PM GMT
Hi Aaron, How do we contact adobe to get hotfix jar file? Sorry if this is a silly question.
Comment by Praveen S.
31783 | November 07, 2019 07:06:53 PM GMT
This is still an issue in CF 2018 HF 7. Still get cfdocument hangs until the service is restarted. at coldfusion.document.DocumentProcessor.processContent(DocumentProcessor.java:274) at coldfusion.document.DocumentProcessor.processContent(DocumentProcessor.java:179) at coldfusion.tagext.lang.DocumentSectionTag.processContent(DocumentSectionTag.java:534) at coldfusion.tagext.lang.DocumentSectionTag._processContent(DocumentSectionTag.java:479) at coldfusion.tagext.lang.DocumentSectionTag.doAfterBody(DocumentSectionTag.java:452)
Comment by Toby W.
32080 | January 09, 2020 12:57:50 PM GMT
We've been seeing this same timeout problem for quite awhile now across CF2016 and CF2018 servers. Restarting the CF instance has been our only solution. I see suggestions above that there may be a hotfix that resolves this. What do we need to do to get that? Thanks, Ken Wilson Server Product ColdFusion 2018 Version 2018.0.06.316308 Tomcat Version 9.0.21.0 Edition Enterprise Operating System Windows Server 2016 OS Version 10.0 Update Level /lib/updates/hf201800-4206898.jar Adobe Driver Version 5.1.4 (Build 0001) Java Version 11.0.4
Comment by Ken W.
33282 | March 09, 2020 03:49:01 PM GMT