G'day:
As the title suggests, I've done this before: Investigation into applicationStop(). However this time I've tested on Lucee as well. It's interesting to see how my code differs from 2012 and now.
This investigation came up cos someone asked on the CFML Slack channel how applicationStop behaves vis-a-vis other already-running requests. The suspicion being that the request calling applicationStop will break other already running requests that still need to rely on the application state as it was when their requests start. I was pretty sure ColdFusion had thought of that, and it made sure running requests continued with the "correct" application state, even if it's been reset during their run. I have to admit when I started looking into it, it did not occur to me that I might have already checked for this. Ah well. Anyway: I'm just writing this article so I can link to something in Slack.
The code is simple:
// Application.cfc
component {
this.name = "testApp"
this.applicationTimeout = createTimespan(0, 0, 0, 30)
function onApplicationStart() {
application.uuid = createUuid()
logMessage(getFunctionCalledName())
}
function onApplicationEnd(applicationScope) {
logMessage(getFunctionCalledName())
}
function logMessage(handlerName) {
writeLog(
file = "appStopDebug",
text = handlerName
& " (#getFileFromPath(getBaseTemplatePath())#)"
& " (query_string: #CGI.query_string#)"
& " (application?.uuid: [#application?.uuid#])")
}
}
This sets a UUID into the application scope when the application starts, and logs a line when the application starts and ends.
// beforeStop.cfm
writeLog(file="appStopDebug", text="START beforeStop.cfm (query_string: #CGI.query_string#) (application?.uuid: [#application?.uuid#])")
sleep(5000)
writeLog(file="appStopDebug", text="END beforeStop.cfm (query_string: #CGI.query_string#) (application?.uuid: [#application?.uuid#])")
My test requests this file three times, just to get some slow (note the sleep call there) requests running before I stop the app.
// applicationStop.cfm
writeLog(file="appStopDebug", text="START applicationStop.cfm (application?.uuid: [#application?.uuid#])")
applicationStop()
writeLog(file="appStopDebug", text="END applicationStop.cfm (application?.uuid: [#application?.uuid#])")
After kicking off the first three requests, the test calls this one to stop the application. Note that the first three requests will still be running when this is called. So the application will end whilst they are still needing their application state.
// afterStop.cfm
writeLog(file="appStopDebug", text="START afterStop.cfm (application?.uuid: [#application?.uuid#])")
sleep(5000)
writeLog(file="appStopDebug", text="END afterStop.cfm (application?.uuid: [#application?.uuid#])")
This is called after the application is stopped, just to restart it again; and application.uuid will be re-created with a new value by the onApplicationStart handler.
And this next one is the thing that runs the test:
// test.cfm
writeLog(file="appStopDebug", text="==================== TEST STARTED ====================")
port = server.coldfusion.productname contains "ColdFusion" ? 8500 : 8888;
for (i=1; i <= 3; i++) {
testUrl = "http://localhost:#port#/cfml/applicationFramework/applicationStop/testApp/beforeStop.cfm?i=#i#"
writeOutput("Calling #testUrl#<br>")
thread name="t#i#" action="run" testUrl=testUrl {
cfhttp(url=attributes.testUrl, timeout=0);
}
}
sleep(500)
writeOutput("Running applicationStop.cfm<br>")
cfhttp(url="http://localhost:#port#/cfml/applicationFramework/applicationStop/testApp/applicationStop.cfm", timeout=0);
sleep(500)
writeOutput("Running afterStop.cfm<br>")
cfhttp(url="http://localhost:#port#/cfml/applicationFramework/applicationStop/testApp/afterStop.cfm", timeout=0);
Note that the test.cfm file is in a separate directory and runs in a different application to the files it calls.
I've summarised what test.cfm does, above. Note how it calls beforeStop.cfm in their own threads so that I can get those underway, but not have to wait until they finish before calling applicationStop.cfm. The thing with the port variable is just cos I run the exact same code in my CF and Lucee containers, and they're both listening on different ports.
Here's the log from CF2021:
14:01:08 TESTERAPP ==================== TEST STARTED ==================== 14:01:08 TESTAPP onApplicationStart (beforeStop.cfm) (query_string: i=1) (application?.uuid: [BC105138-F6A3-62EC-146CC1456BB982D8]) 14:01:08 TESTAPP START beforeStop.cfm (query_string: i=3) (application?.uuid: [BC105138-F6A3-62EC-146CC1456BB982D8]) 14:01:08 TESTAPP START beforeStop.cfm (query_string: i=1) (application?.uuid: [BC105138-F6A3-62EC-146CC1456BB982D8]) 14:01:08 TESTAPP START beforeStop.cfm (query_string: i=2) (application?.uuid: [BC105138-F6A3-62EC-146CC1456BB982D8]) 14:01:09 TESTAPP START applicationStop.cfm (application?.uuid: [BC105138-F6A3-62EC-146CC1456BB982D8]) 14:01:09 TESTAPP onApplicationEnd (applicationStop.cfm) (query_string: ) (application?.uuid: []) 14:01:09 testApp END applicationStop.cfm (application?.uuid: [BC105138-F6A3-62EC-146CC1456BB982D8]) 14:01:09 TESTAPP onApplicationStart (afterStop.cfm) (query_string: ) (application?.uuid: [BC107AA8-BCA5-9CD9-3F2E0D20E47D0F60]) 14:01:09 TESTAPP START afterStop.cfm (application?.uuid: [BC107AA8-BCA5-9CD9-3F2E0D20E47D0F60]) 14:01:13 TESTAPP END beforeStop.cfm (query_string: i=3) (application?.uuid: [BC105138-F6A3-62EC-146CC1456BB982D8]) 14:01:13 TESTAPP END beforeStop.cfm (query_string: i=1) (application?.uuid: [BC105138-F6A3-62EC-146CC1456BB982D8]) 14:01:13 TESTAPP END beforeStop.cfm (query_string: i=2) (application?.uuid: [BC105138-F6A3-62EC-146CC1456BB982D8]) 14:01:14 TESTAPP END afterStop.cfm (application?.uuid: [BC107AA8-BCA5-9CD9-3F2E0D20E47D0F60]) 14:02:21 TESTAPP onApplicationEnd (Application.cfc) (query_string: ) (application?.uuid: [])
Here you can see that the app starts and sets application.uuid to be BC105138-F6A3-62EC-146CC1456BB982D8, and that value sticks through until the end of the beforeStop.cfm runs, even though in the middle the application has been stopped and restarted again (and in the new application, application.uuid is BC107AA8-BCA5-9CD9-3F2E0D20E47D0F60. This is what one would want. Well done ColdFusion.
Not so much for Lucee:
13:57:08 testerApp ==================== TEST STARTED ==================== 13:57:08 testApp onApplicationStart (beforeStop.cfm) (query_string: i=1) (application?.uuid: [FDC7FFBB-538B-4630-9894DA7F8E82726F]) 13:57:08 testApp START beforeStop.cfm (query_string: i=1) (application?.uuid: [FDC7FFBB-538B-4630-9894DA7F8E82726F]) 13:57:08 testApp START beforeStop.cfm (query_string: i=2) (application?.uuid: [FDC7FFBB-538B-4630-9894DA7F8E82726F]) 13:57:08 testApp START beforeStop.cfm (query_string: i=3) (application?.uuid: [FDC7FFBB-538B-4630-9894DA7F8E82726F]) 13:57:08 testApp START applicationStop.cfm (application?.uuid: [FDC7FFBB-538B-4630-9894DA7F8E82726F]) 13:57:08 testApp onApplicationEnd (applicationStop.cfm) (query_string: ) (application?.uuid: [FDC7FFBB-538B-4630-9894DA7F8E82726F]) 13:57:08 testApp END applicationStop.cfm (application?.uuid: []) 13:57:09 testApp onApplicationStart (afterStop.cfm) (query_string: ) (application?.uuid: [74D5E31E-46D2-4884-A3D14A6D5A31EAB8]) 13:57:09 testApp START afterStop.cfm (application?.uuid: [74D5E31E-46D2-4884-A3D14A6D5A31EAB8]) 13:57:13 testApp END beforeStop.cfm (query_string: i=1) (application?.uuid: []) 13:57:13 testApp END beforeStop.cfm (query_string: i=2) (application?.uuid: []) 13:57:13 testApp END beforeStop.cfm (query_string: i=3) (application?.uuid: []) 13:57:14 testApp END afterStop.cfm (application?.uuid: [74D5E31E-46D2-4884-A3D14A6D5A31EAB8]) 13:57:58 testApp onApplicationEnd (Application.cfc) (query_string: ) (application?.uuid: [74D5E31E-46D2-4884-A3D14A6D5A31EAB8])
In Lucee's case, as soon as applicationStop is called, the application state of running requests is banjanxed: note that in the END beforeStop.cfm entries, application.uuid is just gone. This is not very well-reasoned on Lucee's part, I think.
Oh, why did applicationStop come up in the first place? Once again someone was suggesting to another person that to restart an application, one just needs to call onApplicationStart. This is not correct. onApplicationStart is called as a result of the application starting; it doesn't in itself cause the application to (re)start. I cover this in another earlier article: CFML: The difference between events and event handlers. If you want the application to restart in a controlled fashion, you must call applicationStop(), and let the CFML server restart the app in an orderly fashion. Simply running the event handler that's called after the application has been started is not the same thing, and can be dangerous, and lead to an application being unstable.
Righto.
--
Adam
