Wednesday 15 August 2012

CFML: More on Application.cfc... when things run

G'day
This one stemmed from me trying to come up with an accurate answer to someone's question on StackOverflow.  To summarise, the question was about what order things run in, what scopes come into play when, and all that sort of thing.  Stuff I imagine most of us pretty much know, but perhaps don't completely know the boundaries of the edgecases.  Certainly I sat down at the keyboard, drew myself up in an all-knowing sort of way ready to type the model answer, before thinking... "you know what?  I don't actually know for sure".  And when I answer stuff on forums, I like to be like 99% confident I'm right.  Not for my sake, but because I don't like wasting people's time by giving inaccurate answers.  And a bit for my own sake ;-)


Anyway, I voted-down the two answers that were there when I first read the question, because I thought they were - on balance - inaccurate.  Both had elements of correctness about them, but they both had blatant inaccuracies about them too (ie: they stated things that were outright wrong).  But I figured if I was voting stuff down, I had better come back with the goods.
Speaking of StackOverflow... here's an aside.  If you are reading this and you don't already help out on StackOverflow and - more importantly - the Adobe ColdFusion forums, please consider donating some of your time to helping the ColdFusion community.  There are a lot of people asking questions out there, and not enough people to answer them.  We could use your help.
But anyway... that's not the topic of my wittering for the day.
Application.cfc.

So, yeah, it occurred to me I didn't actually 100% know when various scopes became available, and what was available where, and that sort of thing.  I also saw it as low-hanging-fruit for a blog entry, so here I am now.

I knocked together a quick Application.cfc, which logged what it was up to and when:


The logic at play in this is repetitive: at each step of the Application.cfc I test various scopes that might exist, report if they do exist, and attempt to create a variable in them.  Then as processing continues through various event handlers, I keep track of what exists and where.

The log file created is as follows (this is a bit longwinded... scroll down rather than read it all. I've highlighted the important bits):

1 in pseudoconstructor before application name is set application scope not enabled
1 in pseudoconstructor before application name is set session scope not enabled
1 in pseudoconstructor before application name is set request.pseudoconstructor initialised
1 in pseudoconstructor before application name is set this.pseudoconstructor initialised
==================================================
1 in pseudoconstructor after application name is set application scope not enabled
1 in pseudoconstructor after application name is set session scope not enabled
1 in pseudoconstructor after application name is set request.pseudoconstructor existed
1 in pseudoconstructor after application name is set this.pseudoconstructor existed
==================================================
1 in onApplicationStart application.pseudoconstructor initialised
1 in onApplicationStart session scope not enabled
1 in onApplicationStart request.pseudoconstructor existed
1 in onApplicationStart this.pseudoconstructor existed
==================================================
1 in onApplicationStart application.onApplicationStart initialised
1 in onApplicationStart session scope not enabled
1 in onApplicationStart request.onApplicationStart initialised
1 in onApplicationStart this.onApplicationStart existed
==================================================
1 in onSessionStart application.pseudoconstructor existed
1 in onSessionStart session.pseudoconstructor initialised
1 in onSessionStart request.pseudoconstructor existed
1 in onSessionStart this.pseudoconstructor existed
==================================================
1 in onSessionStart application.onApplicationStart existed
1 in onSessionStart session.onApplicationStart initialised
1 in onSessionStart request.onApplicationStart existed
1 in onSessionStart this.onApplicationStart existed
==================================================
1 in onSessionStart application.onSessionStart initialised
1 in onSessionStart session.onSessionStart initialised
1 in onSessionStart request.onSessionStart initialised
1 in onSessionStart this.onSessionStart existed
==================================================
1 in onRequestStart application.pseudoconstructor existed
1 in onRequestStart session.pseudoconstructor existed
1 in onRequestStart request.pseudoconstructor existed
1 in onRequestStart this.pseudoconstructor existed
==================================================
1 in onRequestStart application.onApplicationStart existed
1 in onRequestStart session.onApplicationStart existed
1 in onRequestStart request.onApplicationStart existed
1 in onRequestStart this.onApplicationStart existed
==================================================
1 in onRequestStart application.onSessionStart existed
1 in onRequestStart session.onSessionStart existed
1 in onRequestStart request.onSessionStart existed
1 in onRequestStart this.onSessionStart existed
==================================================
1 in onRequestStart application.onRequestStart initialised
1 in onRequestStart session.onRequestStart initialised
1 in onRequestStart request.onRequestStart initialised
1 in onRequestStart this.onRequestStart existed
==================================================
1 in onRequest application.pseudoconstructor existed
1 in onRequest session.pseudoconstructor existed
1 in onRequest request.pseudoconstructor existed
1 in onRequest this.pseudoconstructor existed
==================================================
1 in onRequest application.onApplicationStart existed
1 in onRequest session.onApplicationStart existed
1 in onRequest request.onApplicationStart existed
1 in onRequest this.onApplicationStart existed
==================================================
1 in onRequest application.onSessionStart existed
1 in onRequest session.onSessionStart existed
1 in onRequest request.onSessionStart existed
1 in onRequest this.onSessionStart existed
==================================================
1 in onRequest application.onRequestStart existed
1 in onRequest session.onRequestStart existed
1 in onRequest request.onRequestStart existed
1 in onRequest this.onRequestStart existed
==================================================
1 in onRequest application.onRequest initialised
1 in onRequest session.onRequest initialised
1 in onRequest request.onRequest initialised
1 in onRequest this.onRequest existed
==================================================
1 in onRequestEnd application.pseudoconstructor existed
1 in onRequestEnd session.pseudoconstructor existed
1 in onRequestEnd request.pseudoconstructor existed
1 in onRequestEnd this.pseudoconstructor existed
==================================================
1 in onRequestEnd application.onApplicationStart existed
1 in onRequestEnd session.onApplicationStart existed
1 in onRequestEnd request.onApplicationStart existed
1 in onRequestEnd this.onApplicationStart existed
==================================================
1 in onRequestEnd application.onSessionStart existed
1 in onRequestEnd session.onSessionStart existed
1 in onRequestEnd request.onSessionStart existed
1 in onRequestEnd this.onSessionStart existed
==================================================
1 in onRequestEnd application.onRequestStart existed
1 in onRequestEnd session.onRequestStart existed
1 in onRequestEnd request.onRequestStart existed
1 in onRequestEnd this.onRequestStart existed
==================================================
1 in onRequestEnd application.onRequest existed
1 in onRequestEnd session.onRequest existed
1 in onRequestEnd request.onRequest existed
1 in onRequestEnd this.onRequest existed
==================================================
1 in onRequestEnd application.onRequestEnd initialised
1 in onRequestEnd session.onRequestEnd initialised
1 in onRequestEnd request.onRequestEnd initialised
1 in onRequestEnd this.onRequestEnd existed
==================================================
2 in pseudoconstructor before application name is set application scope not enabled
2 in pseudoconstructor before application name is set session scope not enabled
2 in pseudoconstructor before application name is set request.pseudoconstructor initialised
2 in pseudoconstructor before application name is set this.pseudoconstructor initialised
==================================================
2 in pseudoconstructor after application name is set application scope not enabled
2 in pseudoconstructor after application name is set session scope not enabled
2 in pseudoconstructor after application name is set request.pseudoconstructor existed
2 in pseudoconstructor after application name is set this.pseudoconstructor existed
==================================================
2 in onRequestStart application.pseudoconstructor existed
2 in onRequestStart session.pseudoconstructor existed
2 in onRequestStart request.pseudoconstructor existed
2 in onRequestStart this.pseudoconstructor existed
==================================================
2 in onRequestStart application.onApplicationStart existed
2 in onRequestStart session.onApplicationStart existed
2 in onRequestStart request.onApplicationStart initialised
2 in onRequestStart this.onApplicationStart existed
==================================================
2 in onRequestStart application.onSessionStart existed
2 in onRequestStart session.onSessionStart existed
2 in onRequestStart request.onSessionStart initialised
2 in onRequestStart this.onSessionStart existed
==================================================
2 in onRequestStart application.onRequestStart existed
2 in onRequestStart session.onRequestStart existed
2 in onRequestStart request.onRequestStart initialised
2 in onRequestStart this.onRequestStart existed
==================================================
2 in onRequest application.pseudoconstructor existed
2 in onRequest session.pseudoconstructor existed
2 in onRequest request.pseudoconstructor existed
2 in onRequest this.pseudoconstructor existed
==================================================
2 in onRequest application.onApplicationStart existed
2 in onRequest session.onApplicationStart existed
2 in onRequest request.onApplicationStart existed
2 in onRequest this.onApplicationStart existed
==================================================
2 in onRequest application.onSessionStart existed
2 in onRequest session.onSessionStart existed
2 in onRequest request.onSessionStart existed
2 in onRequest this.onSessionStart existed
==================================================
2 in onRequest application.onRequestStart existed
2 in onRequest session.onRequestStart existed
2 in onRequest request.onRequestStart existed
2 in onRequest this.onRequestStart existed
==================================================
2 in onRequest application.onRequest existed
2 in onRequest session.onRequest existed
2 in onRequest request.onRequest initialised
2 in onRequest this.onRequest existed
==================================================
2 in onRequestEnd application.pseudoconstructor existed
2 in onRequestEnd session.pseudoconstructor existed
2 in onRequestEnd request.pseudoconstructor existed
2 in onRequestEnd this.pseudoconstructor existed
==================================================
2 in onRequestEnd application.onApplicationStart existed
2 in onRequestEnd session.onApplicationStart existed
2 in onRequestEnd request.onApplicationStart existed
2 in onRequestEnd this.onApplicationStart existed
==================================================
2 in onRequestEnd application.onSessionStart existed
2 in onRequestEnd session.onSessionStart existed
2 in onRequestEnd request.onSessionStart existed
2 in onRequestEnd this.onSessionStart existed
==================================================
2 in onRequestEnd application.onRequestStart existed
2 in onRequestEnd session.onRequestStart existed
2 in onRequestEnd request.onRequestStart existed
2 in onRequestEnd this.onRequestStart existed
==================================================
2 in onRequestEnd application.onRequest existed
2 in onRequestEnd session.onRequest existed
2 in onRequestEnd request.onRequest existed
2 in onRequestEnd this.onRequest existed
==================================================
2 in onRequestEnd application.onRequestEnd existed
2 in onRequestEnd session.onRequestEnd existed
2 in onRequestEnd request.onRequestEnd initialised
2 in onRequestEnd this.onRequestEnd existed


The log here follows two consecutive requests (labelled "1" and "2" in the leftmost column).

There's a whole lot of bumpf there, but the stand-out things are highlighted.

First, let's look at what happens in the pseudo-constructor (the bit of code within the component tags, but outwith any method in the CFC).

This is not surprising:

1 in pseudoconstructor before application name is set application scope not enabled
1 in pseudoconstructor before application name is set session scope not enabled

There's no chance that there'd be any sense of application before the this.name line had been encountered.  CF doesn't know which application a given request is part of before it's been told.  Equally the session scope cannot exist prior to the application being identified, because sessions are bound to applications.

This is straight forward:
1 in pseudoconstructor before application name is set request.pseudoconstructor initialised
1 in pseudoconstructor before application name is set this.pseudoconstructor initialised

Obviously we know we can set this-scoped variables here... we'd not be able to set the application settings otherwise.  Being able to set request-scope variables is slightly surprising, given that this is before onRequestStart(), esp. given what I'm drawing your attention to next:

1 in pseudoconstructor after application name is set application scope not enabled
1 in pseudoconstructor after application name is set session scope not enabled

So this is after the application has been named.  But still the application and session scopes aren't available.  I expected they might have been as there's no reason for them not to.  I guess CF waits until the onApplicationStart() and onSessionStart() event handlers start before starting those two scopes.  Given my earlier diatribe on events vs event handlers, I half expected the scopes to be there, even if the event handlers had yet to be called.  So that is definitely something I have learned about all this.



Next, unsurprisingly, the variables we set previously in the this and request scopes are still there:

1 in pseudoconstructor after application name is set request.pseudoconstructor existed
1 in pseudoconstructor after application name is set this.pseudoconstructor existed

From there, as processing falls through each of the onApplicationStart(), onSessionStart() and onRequestStart() handlers (and the onRequest() interceptor), there are no surprises.  As each scope is started, it becomes available. And variables in each scope created in each handler exist in the next handler.  No surprises.

When it comes to the second request, we get the same behaviour in the pseudo-constructor as the first request:

No application name = no scope:
2 in pseudoconstructor before application name is set application scope not enabled
2 in pseudoconstructor before application name is set session scope not enabled

But - again - even after the application has a name, there's still no application or session scopes exposed:

2 in pseudoconstructor after application name is set application scope not enabled
2 in pseudoconstructor after application name is set session scope not enabled

For some reason I thought these guys might be accessible now, having been created in the previous request.  No.

However we note from all this lot sampled in onRequestStart():

2 in onRequestStart application.pseudoconstructor existed
2 in onRequestStart session.pseudoconstructor existed
2 in onRequestStart request.pseudoconstructor existed
2 in onRequestStart this.pseudoconstructor existed
==================================================
2 in onRequestStart application.onApplicationStart existed
2 in onRequestStart session.onApplicationStart existed
2 in onRequestStart request.onApplicationStart initialised
2 in onRequestStart this.onApplicationStart existed
==================================================
2 in onRequestStart application.onSessionStart existed
2 in onRequestStart session.onSessionStart existed
2 in onRequestStart request.onSessionStart initialised
2 in onRequestStart this.onSessionStart existed
==================================================
2 in onRequestStart application.onRequestStart existed
2 in onRequestStart session.onRequestStart existed
2 in onRequestStart request.onRequestStart initialised
2 in onRequestStart this.onRequestStart existed

That the application exists (no second call to onApplicationStart()), as does the session (ditto for onSessionStart()).  And all the variables set previously existed.

Don't be confused by my sloppy programming here (I only just noticed this):

2 in onRequestStart application.pseudoconstructor existed
2 in onRequestStart session.pseudoconstructor existed

This does not indicate that these variables were created in the pseudo-constructor after all, it's just that the testScopes() method tests for their existence, and then creates them if not.  These guys were created back in the call to testScopes() in onApplicationStart() (or onSessionStart()), in the previous request.  I should have made the log entries clearer as to which request and in what handler the variables were created.  But if you look at the whole log, you can see when it happens.

That's all I've really got to say on this.  The one thing I learned here is that I expected the application and session scopes to be available straight after the application got its name, but this is not the case.  They don't become available until the relevant start handler is called.

So having driven all you lot off to sleep with my incisive investigations... I'm off to bed meself.

Righto.

--
Adam