CF9: onRequestEnd Vs. CFDocument * David Boyer

CF9: onRequestEnd Vs. CFDocument

An odd thing happened to me on the way to the end of my request… I bumped into CFDocument, caught up on old times, but without realising I managed to end up back tracking a few steps, to a place I had already travelled through. Here is my story of a weird behaviour between CFDocument and onRequestEnd().

Premise

Our opening scene contains a simple Application.cfc file. It’s using onRequest to capture the output from the requested file and then onRequestEnd to embed it in a layout file. Everything goes to plan and requesting index.cfm throws it’s content into layout-html.cfm. The world’s a happy place and we all move on with our lifes… until CFDocument comes along. It’s decided that we need a PDF version of the page, so we simply switch to another layout file, pretty similar to the last apart from a CFDocument tag wrapping around the whole thing.

The Twist

Everything starts out normal, until you get to CFDocument being executed. That’s where the oddity begins by firing onRequestEnd a second time. Here’s a walk through of what happens:

Request received.
onRequest fired.
1. index.cfm included
2. Output captured
onRequestEnd fired.
1. Count execution
2. Log to file
3. Include layout.cfm file.
  1. CFDocument PDF.
  2. Rules of normality break down.
onRequestEnd fired (again?).
1. Count execution (now 2).
2. Log to file.
3. Include layout.cfm file.
  1. CFDocument PDF, doesn’t appear to do anything with this second invocation.
  2. Thankfully, CFDocument doesn’t flag onRequestEnd to execute again or we’d be stuck in a loop.
Request ends.

Strangely enough, you won’t get any errors. The 2nd CFDocument doesn’t appear to do anything and thankfully won’t attempt to run onRequestEnd again, avoiding a loop.

The code

Our Application.cfc file, as mentioned above has been written to capture the output from onRequest and use onRequestEnd to apply it onto a layout file. Some logging code has added to onRequestEnd to highlight what’s going on.

&lt;cfset this.name = &apos;AFunnyThingHappenOnTheWay...&apos; /&gt;

&lt;cffunction name=&quot;onRequest&quot; returntype=&quot;void&quot;&gt;
  &lt;cfargument name=&quot;thisPage&quot; required=&quot;true&quot; type=&quot;string&quot; /&gt;
  &lt;cfsavecontent variable=&quot;request.content&quot;&gt;
    &lt;cfinclude template=&quot;#arguments.thisPage#&quot; /&gt;
  &lt;/cfsavecontent&gt;
&lt;/cffunction&gt;

&lt;cffunction name=&quot;onRequestEnd&quot; returntype=&quot;void&quot;&gt;
  &lt;cfset var msg = &apos;&apos; /&gt;
  &lt;cfif Not StructKeyExists(request, &apos;onRequestEndCount&apos;)&gt;
    &lt;cfset msg = &apos;&lt;hr&gt;&apos; &amp; Chr(10) /&gt;
    &lt;cfset request.onRequestEndCount = 1 /&gt;
  &lt;cfelse&gt;
    &lt;cfset request.onRequestEndCount++ /&gt;
  &lt;/cfif&gt;
  &lt;cfset msg &amp;= &apos;onRequestEnd() Fired: &apos; &amp; Now() &amp; &apos;&lt;br&gt;&apos; &amp; Chr(10) /&gt;
  &lt;cfset msg &amp;= &apos;Count in single request = #request.onRequestEndCount#&lt;br&gt;&apos; /&gt;
  &lt;cffile action=&quot;append&quot; file=&quot;#ExpandPath(&apos;./log.html&apos;)#&quot; output=&quot;#msg#&quot; /&gt;
  &lt;cfcontent reset=&quot;true&quot; /&gt;&lt;cfinclude template=&quot;layout.cfm&quot; /&gt;
&lt;/cffunction&gt;

An awesome index.cfm file…

&lt;p&gt;This content is super fantastico!&lt;/p&gt;
&lt;p&gt;&lt;cfoutput&gt;#Now()#&lt;/cfoutput&gt;&lt;/p&gt;

And our layout file using CFDocument.

&lt;cfset msg = &apos;layout.cfm executed: &apos; &amp; Now() &amp; &apos;&lt;br&gt;&apos; &amp; Chr(10) /&gt;
&lt;cffile action=&quot;append&quot; file=&quot;#ExpandPath(&apos;./log.html&apos;)#&quot; output=&quot;#msg#&quot; /&gt;
&lt;cfdocument format=&quot;pdf&quot;&gt;
&lt;!doctype html&gt;
&lt;html&gt;
&lt;body&gt;
  &lt;h1&gt;Layout&lt;/h1&gt;
  &lt;h2&gt;Content&lt;/h2&gt;
  &lt;cfoutput&gt;#request.content#&lt;/cfoutput&gt;
&lt;/body&gt;
&lt;/html&gt;
&lt;/cfdocument&gt;

Put it all together and what do you get? onRequestEnd being fired twice. Here’s what you’ll probably see in log.html.

&lt;hr&gt;
onRequestEnd() Fired: {ts &apos;2013-05-22 12:37:09&apos;}&lt;br&gt;
Count in single request = 1&lt;br&gt;
layout.cfm executed: {ts &apos;2013-05-22 12:37:09&apos;}&lt;br&gt;

onRequestEnd() Fired: {ts &apos;2013-05-22 12:37:09&apos;}&lt;br&gt;
Count in single request = 2&lt;br&gt;
layout.cfm executed: {ts &apos;2013-05-22 12:37:09&apos;}&lt;br&gt;

So having CFDocument execute within onRequestEnd will fire onRequestEnd a second time. This doesn’t happen in CF8, haven’t tested CF10 as I haven’t a version handy at the moment. I believe this is probably related to the change in onRequestEnd behaviour in CF9. Where it’ll fire even after a CFLocation. Haven’t stumbled across any bug entries for this so far, but will log one for it if I’m certain no one has beaten me to it.

Premise

The Twist

The code

Comments

David Boyer