Wednesday 19 September 2012

CFML:Curious behaviour with THIS-scoped variables in onSessionEnd and onApplicationEnd

G'day
This article stems from a question that came up on StackOverflow today. In summary the bod wanted to know if they could set this.datasource conditionally on a CGI variable, and I confirmed they could, eg:
  • if the cgi.server_name equals "www.firsturl.com" => this.datasource = "firstdsn"
  • if the cgi.server_name equals "www.secondurl.com" => this.datasource = "seconddsn"
My initial response (beyond "just try it and see") was to confirm it was possible.


Someone (called "nosilleg") followed my answer up with  a warning that there could be unexpected results if onSessionEnd (etc) was to use the this.datasource value, as the CGI scope wouldn't be there, so which DSN would be used?  Good question!

To clarify... normal requests all instantiate Application.cfc, and run the pseudo-constructor code to create all the this-scoped config variables, and the CGI variables will all be there so logic predicated on them will work: that's fine.  But things like onSessionEnd() and onApplicationEnd() do not run via a request, per-se, so they won't have any CGI variables.  So what will happen?

This was - of course - my cue to slap together some test code and log stuff and run requests and all that sort of malarky, and now you have to endure reading about my findings.  Well don't say you weren't warned.

So I knocked some code together to test this:


And had a test file to request, thus:


<cfdump var="#this#">

The idea here is that I have DSN1 and DSN2 set up pointing to two different DBs, both of which have identical T_TEST tables to write data to.  Conditional on whether I request test.cfm via localhost or testing.local (both point to the same CF instance) I set this.datasource to point to one or the other (via checking CGI.SERVER_NAME).  If CGI.SERVER_NAME is neither of those, they get nowt.

What I was expecting here was for the onSessionEnd() and onApplicationEnd() to error.  I was not correct.  Well I was a bit correct.  But there is definitely fishy behaviour here.

My log file says this:

Start of logIt(). onApplicationStart [localhost] [dsn1]
End of logIt(). onApplicationStart [localhost] [dsn1]
Start of logIt(). onSessionStart [localhost] [dsn1]
End of logIt(). onSessionStart [localhost] [dsn1]
Start of logIt(). onRequestStart [localhost] [dsn1]
End of logIt(). onRequestStart [localhost] [dsn1]
Start of logIt(). onSessionStart [testing.local] [dsn2]
End of logIt(). onSessionStart [testing.local] [dsn2]
Start of logIt(). onRequestStart [testing.local] [dsn2]
End of logIt(). onRequestStart [testing.local] [dsn2]
Start of logIt(). onRequestStart [localhost] [dsn1]
End of logIt(). onRequestStart [localhost] [dsn1]
Start of logIt(). onSessionEnd [none] [dsn1]
End of logIt(). onSessionEnd [none] [dsn1]
Start of logIt(). onSessionEnd [none] [dsn1]
End of logIt(). onSessionEnd [none] [dsn1]
Start of logIt(). onApplicationEnd [none] [dsn1]
CATCH in logIt(). onApplicationEnd [none] [dsn1] [Attribute validation error for tag CFQUERY.] [The value of the attribute datasource, which is currently '', is invalid.]


I've truncated it, but the "proper" request's log entries were made by "catalina-exec-nn" when nn was a number, whereas the onSessionEnd() and onApplicationEnd() entries were made by "scheduler-n" (where n was a number).  This demonstrates the difference between a normal request running and CF doing its own thing in the background to tidy-up sessions and applications.


Note that neither onSessionEnd() or onApplicationEnd() see a CGI.server_name value.  This is no surprise. However what appears to happen is - by magic, it seems - the onSessionEnd() and onApplicationEnd() calls both receive the last value that this.datasource was set to be via a legit "request".  I verified this through more testing I'll not bore you with, but it was always the DSN of the previous request that these handlers used.  However - rather weirdly - despite onApplicationEnd() definitely seeing this.datasource, the <cfquery> tag in Query.cfc did not think it had a default datasource set.  That's an interesting disconnect, isn't it?  Especially given it seems like onSessionEnd() is in the same boat, but its query worked fine.  Oh, I should have said: data when into the DB tables exactly as one would expect, given the DSN setting (other than the error in onApplicationEnd(), I mean).

If I can be bothered (currently: no) I will refactor the Application.cfc to be tag-based so I can use <cfquery> instead, and see what happens.

Anyway, the bottom line here is that nosilleg was right to be cautious here.  However in situations wherein one doesn't need to use the DSN in the tidy-up handlers, the technique works fine.  I'll feed this back to StackOverflow.

And that's it.

--
Adam