Ben Nadel
On User Experience (UX) Design, JavaScript, ColdFusion, Node.js, Life, and Love.
I am the chief technical officer at InVision App, Inc - a prototyping and collaboration platform for designers, built by designers. I also rock out in JavaScript and ColdFusion 24x7.
Meanwhile on Twitter
Loading latest tweet...
Ben Nadel at the New York ColdFusion User Group (Feb. 2009) with: Clark Valberg

OnApplicationEnd() And OnSessionEnd() Errors Don't Get Logged In ColdFusion

Posted by Ben Nadel
Tags: ColdFusion

Over the last week or so, I've made some pretty large changes to the code behind my ColdFusion blogging software. As part of those changes, I've started using my Application.cfc's onSessionEnd() event handler. This event handler is used to tear down a given session, providing access to both the ending session as well as the sister application scope. The onSessionEnd() event handler accepts the session and application scopes as the first and second arguments respectively. Unfortunately, as I was making my updates, I accidentally switched the order of these two arguments. This error went unnoticed for two days because it turns out that neither onSessionEnd() nor onApplicationEnd() errors show up in the ColdFusion error logs.

Just to give you a taste of this error in action, here is a tiny Application.cfc ColdFusion framework component that I used to narrow down the problem:

  • <cfcomponent
  • output="false"
  • hint="I define the application settings and event handlers.">
  •  
  • <!--- Define application settings. --->
  • <cfset this.name = hash( getCurrentTemplatePath() ) />
  • <cfset this.applicationTimeout = createTimeSpan( 0, 0, 0, 15 ) />
  • <cfset this.sessionManagement = true />
  • <cfset this.sessionTimeout = createTimeSpan( 0, 0, 0, 5 ) />
  •  
  •  
  • <cffunction
  • name="onSessionEnd"
  • access="public"
  • returntype="void"
  • output="false"
  • hint="I tear down the session.">
  •  
  • <!--- Define arguments. --->
  • <cfargument
  • name="sessionScope"
  • type="any"
  • required="true"
  • hint="I am the session scope being torn down."
  • />
  •  
  • <cfargument
  • name="applicationScope"
  • type="any"
  • required="true"
  • hint="I am the application scope."
  • />
  •  
  • <!--- Log the session length. --->
  • <cfdump
  • var="#arguments.sessionScope.dateInitialized# : #now()#"
  • output="#expandPath( './log.htm' )#"
  • format="html"
  • />
  •  
  • <!--- Return out. --->
  • <cfreturn />
  • </cffunction>
  •  
  •  
  • <cffunction
  • name="onApplicationEnd"
  • access="public"
  • returntype="void"
  • output="false"
  • hint="I tear down the application.">
  •  
  • <!--- Define arguments. --->
  • <cfargument
  • name="applicationScope"
  • type="any"
  • required="true"
  • hint="I am the application scope."
  • />
  •  
  • <!--- Log the application length. --->
  • <cfdump
  • var="#arguments.applicationScope.dateInitialized# : #now()#"
  • output="#expandPath( './log.htm' )#"
  • format="html"
  • />
  •  
  • <!--- Return out. --->
  • <cfreturn />
  • </cffunction>
  •  
  • </cfcomponent>

As you can see, both the onSessionEnd() and onApplicationEnd() ColdFusion application event handlers make reference to a dateInitialized property that doesn't exist. If I run this application and wait for both the application and the session to time out, neither undefined variable reference error will show up in the ColdFusion application log file. I've tested this both locally on ColdFusion 8 and ColdFusion 9 as well as in production on ColdFusion 8 and this remains true across the board.

If I add an onError() event handler to my Application.cfc ColdFusion framework component, both of these errors will be caught internally (at which point I can respond to them however I need to); but, without out any explicit error handling within the application, it appears that onApplicationEnd() and onSessionEnd() errors will go unnoticed.

As I was writing this, I did a bit of Googling to see if anyone else had come across this problem. As it turns out, Mark Kruger discussed the onSessionEnd() aspect in a blog post 5 years ago. That's a long time ago. This problem feels like a bug; but, perhaps if it has been around for so long, it is the expected behavior of the asynchronous event handlers (seeing as they sort of happen outside of the application)?

NOTE: My blogging software does have an onError() event handler. I was actually not getting alerts for a different bug altogether - one in my code. But, the debugging of that bug lead me to this separate problem.




Reader Comments

Hey Ben,

Interesting read. I think that I've also seen similar behaviour with remote methods which are being called as a web service.

So if I'm publishing a method using access="remote" and an exception occurs when a client is calling it, the exception is not logged in the servers exception logs.

Makes debugging these kinds of things notoriously hard.

I can't be sure that the behaviour I saw was genuin and not provoked by something which I was doing but I remember it frustrating the hell out of me, getting consumers of the web service contact me with exceptions they were getting and me not being able to get the proper stack-trace in the logs.

Robert

Reply to this Comment

@Robert,

Very interesting. I don't use remote methods all that often, but I can certainly try that out for myself. Remote methods are definitely a bit different in that ColdFusion packages up the invocation and the response implicitly. So, in a way, they are special events like onApplicationEnd() and onSession() (which are not tied to any particular request).

I'll have to play around with that a bit.

Reply to this Comment

@Ben,

Great stuff. One GOTCHA to be aware of, if you're building a client .cfm file using a <cfinvoke> to call the remote method then the exception will be logged, but by the calling .cfm and not the .cfc method.

So on first glance when testing it may appear that you're getting an exception logged, but this might not be an accurate depiction of a scenario when the client script is not sat on your server.

:-)

Robert

Reply to this Comment

Hi Ben
Have you checked the CF bug tracker to see if there's a bug raised for this, and if not, have you raised one?

--
Adam

Reply to this Comment

@Robert,

I'll see what I can come up with.

@Adam,

I did a quick search for onSessionEnd() and didn't seen anything in particular. I'll log a bug for it.

Reply to this Comment

@Robert: I too hate the non-logging of cffunctions with access="remote" invoked as Web Services.

If you invoke them using a REST call (filename.cfc?method=xxx&arg=yyy&etc) in a browser, you get both a screen dump and logged errors. But that's not too useful for us, because we often need to pass a lot of data.

Here's what works for us: In the cffunction, build some Variables-scope variables from the Arguments scope, then cfinclude a worker routine in a cftry/cfcatch block, then cfreturn success and/or failure data. We like to use a struct for the returned data, which allows success data to be returned along with error data, as appropriate.

Don't try to reference the Arguments scope or cfreturn from inside the worker routine. At the time you do the call, test whether or not you're on the same machine as the CFC. If so, build the same Variables-scope data and cfinclude the exact same worker routine (much less overhead). If not on the same machine, invoke as a Web Service. Either way, you get error information.

We like to employ a naming convention where the cffunction name appears as part of the filename of the worker routine. That way, if something messes up, we know which file to look in.

Hope this helps.

Reply to this Comment

@Steve,

Ah, so you've also experience the remote-access non-logging. I guess that confirms that it truly happens (I have not yet gotten around to testing it myself). Funky stuff.

Reply to this Comment

Hi,
Apparently, when the session ends, you will not be able to access what ever was stored in the session because the session will have expired, thus you cannot access the variables in SessionScope in onSessionEnd.
Is this true?
If it is not, how is it that one will be able to access the session variables which will have expired in OnSessionEnd?
Thanks,
Nich

Reply to this Comment

@Nich, onSessionEnd does not give you direct access to the Application and Session scopes. So that you should ARGUMENT them, like:

<!--- OnSessionEnd routine --->
<cffunction
name="OnSessionEnd"
access="public"
returntype="void"
output="false"
hint="running when session end and it is triger when we defined explicit sessionTimeout value into application settings">

<!--- Define arguments.-->
<cfargument
name="sessionScope"
type="struct"
required="true"
hint="I am the session scope used by the session."
/>
<cfargument name="appScope"
type="struct"
required="true"
hint="I am the application scope used by the session."
/>

<!--- executing an update for an defined session variable, session.username declared in onSessionStart... --->

<!---
suppose that:

application.adata = DNS DB defined in onApplicationStart
session.somevalue = value of table field from a db that you have tracked since session started... here i am updating an user status into db table :)
--->

<cflock name="myLock" type="Exclusive" timeout="5">
<cftransaction action="begin">
<cfquery name="upStatus" datasource="#ARGUMENTS.appScope.adata">
update mytable
set loggedin = false
where userid = <cfqueryparam value="#ARGUMENTS.sessionScope.somevalue" cfsqltype="cf_sql_bigint">;
</cfquery>
</cftransaction>
</cflock>

<cfreturn />
</cffunction>

Reply to this Comment

Hey Ben,

A really helpful page. One thing I don't see here is if it's possible to invoke a cfcomponent without a return value from inside onSessionEnd.

I want to do that but don't really see examples on the various sites. Something like

<cffunction name=onSessionEnd...

<cfinvoke component="endOfSessionData" method="writeData" />

... doesn't need to return a value, just run the function in the component.

All I want onSessionEnd to do is run a component in my CFC folder that writes a session array back to the DB. Cannot get it to work.

Great site!

Gerald

Reply to this Comment

Post A Comment

?
You — Get Out Of My Dreams, Get Into My Comments
Live in the Now
Oops!
Comment Etiquette: Please do not post spam. Please keep the comments on-topic. Please do not post unrelated questions or large chunks of code. And, above all, please be nice to each other - we're trying to have a good conversation here.