I released a UDF
defer() to CFLib and Code Review yesterday. And Adam Tuttle quickly spotted a shortfall in my implementation. And whilst addressing that spotted two more bugs, which I have now fixed.Adam's observation was thus:
you're not doing a thread join in this code anywhere, which means that if the deferred job takes longer than the rest of the request to run, it will not be able to affect the response.
[...]
For your function to be useful, either the result of the job function can't be something that's needed to create the response, or you'll need to add a way to expose a join reference for the created thread.
All very true. So I mulled this over in my head this morning on the train, and came up with a fix. I also realised I had another significant bug in the original implementation at the same time. And when implementing the fix, spotted another bug. All now dealt with.
Here's the revised code:
public struct function defer(required function job, function onSuccess, function onFailure, function onError, function onTerminate){
var threadId = "deferredThread_#createUuid()#";
local[threadId] = "";
try {
cfthread.status = "Running";
thread name=threadId action="run" attributecollection=arguments {
try {
successData.result = job();
cfthread.status = "Completed";
if (structKeyExists(attributes, "onSuccess")){
onSuccess(successData);
}
} catch (any e){
cfthread.status = "Failed";
if (structKeyExists(attributes, "onFailure")){
onFailure(e);
}else{
rethrow;
}
}
}
} catch (any e){
cfthread.status = "Errored";
if (structKeyExists(arguments, "onError")){
onError(e);
}else{
rethrow;
}
}
return {
getStatus = function(){
return cfthread.status;
},
getThreadId = function(){
return threadId;
},
terminate = function(){
if (cfthread.status == "Running"){
thread name=threadId action="terminate";
cfthread.status = "Terminated";
if (isDefined("onTerminate")){
onTerminate();
}
}
}
};
}
So there are three significant changes here.
Firstly I addressed Adam's issue by adding a getThreadId() function which returns the ID of the thread being created. This value can then be used in a join later on, if needs must.
This threw up the second problem... I was checking for the onError() callback's existence incorrectly. I had been checking with structKeyExists(attributes, "onError"), which was just wrong (and, ahem, copy and pasted from the check for onFailure()). It's the attributes scope I need to check when the code is within the thread block, but obviously in the main body of defer(), it's in the arguments scope. This shows up my lack of unit testing on this, actually. Which is very slack of me.
Thirdly... why was onError() being called? Because I had a static thread name, so when my test called defer() twice, the second call failed with a duplicate thread name (threads must have unique names). So I fixed that too, by generating unique thread IDs.
Here's my test code for this. It relies on some other UDFs being created in the background, but they're not so relevant to the demonstration, so I'll omit them. all the code is on github if you want to have a look:
writeLog(file=logName, text="Before firstDeferredJob @ #ts()#");
firstDeferredJob = defer(
job = function(){
writeLog(file=logName, text="firstDeferredJob.job() called @ #ts()#");
sleep(10000);
writeLog(file=logName, text="firstDeferredJob.job() finished @ #ts()#");
},
onError = onError
);
writeLog(file=logName, text="After firstDeferredJob @ #ts()#");
writeLog(file=logName, text="Before secondDeferredJob @ #ts()#");
secondDeferredJob = defer(
job = function(){
writeLog(file=logName, text="secondDeferredJob.job() called @ #ts()#");
sleep(10000);
writeLog(file=logName, text="secondDeferredJob.job() finished @ #ts()#");
},
onError = onError
);
writeLog(file=logName, text="After secondDeferredJob @ #ts()#");
threadIds = [
firstDeferredJob.getThreadId(),
secondDeferredJob.getThreadId()
];
writeOutput("firstDeferredJob thread ID: #threadIds[1]#<br>");
writeOutput("secondDeferredJob thread ID: #threadIds[2]#<br>");
writeLog(file=logName, text="Before join @ #ts()#");
thread action="join" name=arrayToList(threadIds);
writeLog(file=logName, text="After join @ #ts()#");
dumpLog();
And this outputs:
firstDeferredJob thread ID: deferredThread_850236CF-D067-E5E6-F12EB1D2882B690E
secondDeferredJob thread ID: deferredThread_85023718-D067-E5E6-F12EE0D5CD9BFBE8
"Severity","ThreadID","Date","Time","Application","Message"
"Information","catalina-exec-2","10/21/13","09:20:27",,"C:\Apps\Adobe\ColdFusion\10\cfusion\logs\deferTest126_testGetThreadId.log initialized"
"Information","catalina-exec-2","10/21/13","09:20:27",,"Before firstDeferredJob @ 9:20:27.526"
"Information","cfthread-4","10/21/13","09:20:27",,"firstDeferredJob.job() called @ 9:20:27.529"
"Information","catalina-exec-2","10/21/13","09:20:27",,"After firstDeferredJob @ 9:20:27.534"
"Information","catalina-exec-2","10/21/13","09:20:27",,"Before secondDeferredJob @ 9:20:27.535"
"Information","catalina-exec-2","10/21/13","09:20:27",,"After secondDeferredJob @ 9:20:27.536"
"Information","cfthread-5","10/21/13","09:20:27",,"secondDeferredJob.job() called @ 9:20:27.538"
"Information","catalina-exec-2","10/21/13","09:20:27",,"Before join @ 9:20:27.538"
"Information","cfthread-4","10/21/13","09:20:37",,"firstDeferredJob.job() finished @ 9:20:37.531"
"Information","cfthread-5","10/21/13","09:20:37",,"secondDeferredJob.job() finished @ 9:20:37.539"
"Information","catalina-exec-2","10/21/13","09:20:37",,"After join @ 9:20:37.539"
Notes:
- the threads now have unique IDs;
- the join does indeed wait until both threads have finished before progressing.
I think this sorts Adam's issue out adequately? I await advice either way ;-)
--
Adam
