I'm very new to the blog carry-on, and was quite pleased to get some good feedback from my first post, and that it was sufficiently interesting for me to create a follow-up post to take a look at the question.
David McGuigan made a comment, and had this to say (extract):
[If] you call onApplicationStart programmatically, [...] say with a check in onRequestStart for a URL scope flag that triggers it from within Application.cfc itself, it still *is* single-threaded.I gotta say my initial thought was "um... I'm pretty sure it's not single-threaded", but I wasn't completely sure, so decided to look into it.
I knocked-together some slightly different code from last time, thus:
<!--- Application.cfc --->
<cfcomponent>
<cfset this.name = "singleThreadedAppStart3">
<cfset this.applicationTimeout = createTimeSpan(0,0,0,30)>
<cffunction name="onApplicationStart">
<cfset application.startTick = getTickCount()>
<cflog file="#this.name#" text="[#getTickCount()-application.startTick#] Top of onApplicationStart() called via #CGI.script_name#">
<cfset application.startedBy = CGI.script_name>
<cfset sleep(10000)>
<cflog file="#this.name#" text="[#getTickCount()-application.startTick#] Bottom of onApplicationStart() called via #CGI.script_name#">
</cffunction>
<cffunction name="onRequestStart">
<cflog file="#this.name#" text="[#getTickCount()-application.startTick#] Top of onRequestStart() called via #CGI.script_name#">
<cfif structKeyExists(URL, "restart")>
<cfset onApplicationStart()>
</cfif>
<cflog file="#this.name#" text="[#getTickCount()-application.startTick#] Bottom of onRequestStart() called via #CGI.script_name#">
</cffunction>
</cfcomponent>
I've added a coupla bits in here that stand quick clarification:
- I'm setting a small application timeout, so between tests I get a new application starting. I only mention this because I've been a bit of a drongo (look it up) in the past, and when I want to scrub my test application I change the name in the this.name setting (as you can see I've still actually done this three times in my code as it is, eg: "singleThreadedAppStart3"). There's no need to do that... a 30sec time out is enough for me to run the test and then whilst analysing it, the app times out of its own accord, ready for the next test. This is not earthshattering, but I was marginally pleased with myself for this finally occurring to me to do. I now feel I'm slightly less stupid than I was yesterday.
- I've added to the log entries how long it's been since the app was started (well: in this case, "since onApplicationStart() was called"). This info is already in the log entries, but this just makes it a bit more clear in the extract I'm going to include below.
- I've added in one of these "restart the app" conditions into onRequestStart(), so I can specify on the URL to restart the app. I'll repeat that this is not something I would usually do nor do I recommend it as a practice, but it's relevant to this discussion.
The calling code for this is much the same as before:
<!--- requestOne.cfm --->
<cfdump var="#application#" label="#CGI.script_name#">
<!--- requestTwo.cfm --->
<cfdump var="#application#" label="#CGI.script_name#">
The test I run is to do this:
- Hit requestOne.cfm (without the restart switch set). This is just to warm up the app.
- Count off my guess at 5sec (so halfway through the 10sec delay in onApplicationStart())
- Hit requestTwo.cfm (again, with no restart switch set). This is just to "prove" that app restart - if not calls to onApplicationStart() - are single-threaded.
- Wait for them both to finish, but being mindful that my new 30sec app timeout is perhaps working against me here (I screwed it up the first time, forgetting about it, I have to admit. Back to being as dumb as I was y/day. Sigh ;-)
- Hit requestOne.cfm?restart=true
- Count to five again.
- Hit requestTwo.cfm?restart=true
- that my baseline is sensible... the actual application start-up process is single-threaded.
- However the actual test hypothesis is that the second two calls to onApplicationStart() actually are not single threaded.
[0] Top of onApplicationStart() called via /shared/CF/other/appcfc/singlethreaded/requestOne.cfm
[10002] Bottom of onApplicationStart() called via /shared/CF/other/appcfc/singlethreaded/requestOne.cfm
[10005] Top of onRequestStart() called via /shared/CF/other/appcfc/singlethreaded/requestOne.cfm
[10005] Top of onRequestStart() called via /shared/CF/other/appcfc/singlethreaded/requestTwo.cfm
[10017] Bottom of onRequestStart() called via /shared/CF/other/appcfc/singlethreaded/requestOne.cfm
[10022] Bottom of onRequestStart() called via /shared/CF/other/appcfc/singlethreaded/requestTwo.cfm
[12291] Top of onRequestStart() called via /shared/CF/other/appcfc/singlethreaded/requestOne.cfm
[4] Top of onApplicationStart() called via /shared/CF/other/appcfc/singlethreaded/requestOne.cfm
[4097] Top of onRequestStart() called via /shared/CF/other/appcfc/singlethreaded/requestTwo.cfm
[0] Top of onApplicationStart() called via /shared/CF/other/appcfc/singlethreaded/requestTwo.cfm
[5908] Bottom of onApplicationStart() called via /shared/CF/other/appcfc/singlethreaded/requestOne.cfm
[5909] Bottom of onRequestStart() called via /shared/CF/other/appcfc/singlethreaded/requestOne.cfm
[10001] Bottom of onApplicationStart() called via /shared/CF/other/appcfc/singlethreaded/requestTwo.cfm
[10002] Bottom of onRequestStart() called via /shared/CF/other/appcfc/singlethreaded/requestTwo.cfm
And what does this tell us?
I've put a break between the two sets of requests (steps 1-3, then steps 5-7).
The first block shows us that requestOne.cfm takes the mantle of starting the application up, and requestTwo.cfm patiently waits until requestOne.cfm is done, then it continues its request (and it doesn't call onApplicationStart() at all). Good. This is what we want.
The second block is our actual test. What we see here is that requestOne.cfm starts, and correctly calls onApplicationStart(). However requestTwo.cfm comes in right behind it (note the "4097ms": I can't actually count off 5sec very well... ;-), and it also merrily calls onApplicationStart() too. Bleah. We really didn't want that to happen.
This is especially true if we look at the dumps afterwards:
| /shared/CF/other/appcfc/singlethreaded/requestOne.cfm - struct | |
|---|---|
| applicationname | singleThreadedAppStart3 |
| startedby | /shared/CF/other/appcfc/singlethreaded/requestTwo.cfm |
| starttick | 1342293921379 |
(wow: am quite impressed I could just copy the CFDUMP output from my browser into here and it renders perfectly. Nice one blogger.com).
| /shared/CF/other/appcfc/singlethreaded/requestTwo.cfm - struct | |
|---|---|
| applicationname | singleThreadedAppStart3 |
| startedby | /shared/CF/other/appcfc/singlethreaded/requestTwo.cfm |
| starttick | 1342293921379 |
So unfortunately as requestTwo.cfm started to execute onApplicationStart()'s code before requestOne.cfm had finished, we get the wrong value for application.startedBy.
This is a foolishly contrived example, I know, but it shows the point: onApplicationStart() in and of itself is just not single-threaded no matter how you spin it. It's just a method in a CFC. The single-threadedness of application start-up is because app-start-up is single-threaded, not that onApplicationStart() itself is single-threaded.
One last thing I better check... Dave, is that what you were kinda talking about? It'd be... "funny" if I'd blathered on about all this, and you were actually meaning something else. Heh... :-/
Righto... cheers all and enjoy your Saturday. What's left of it, if any.
--
Adam
