getHttpRequestData() Throws NullPointerException When Invoked After ColdFusion Request Has Ended
This odd ColdFusion behavior took me a little while to track down because, at first, it seemed like it was happening randomly. I started to notice that some of my error-logging was, itself, throwing errors that were showing up in the ColdFusion application logs. But, most of my error-logging was working. After much digging, I realized that the error was always being thrown inside a CFThread. And, after much more digging, I realized that it was tied directly to the getHttpRequestData() calls inside those threads.
Calling getHttpRequestData() inside of a CFThread tag inside a ColdFusion page request is not a problem; at least, not inherently. This is what made the issue hard to track down - it never broke for me when I was testing it. Calling getHttpRequestData() inside a CFThread tag only breaks - throws the NullPointerException - if, and only if, the parent request (that spawned the CFThread) has already finished processing at the time the getHttpRequestData() function is invoked.
NOTE: This is not the first time we've seen getHttpRequestData() have problematic behavior. getHttpRequestData() will break your SOAP requests.
To see this in action, I've put together a demo that spawns two CFThread tags, each of which invokes the getHttpRequestData() function. The first does so during the parent page request; the second does so after the parent request has finished executing.
<cfscript>
// I simply log the given value to a static output file.
public void function logOutput(
required string label,
required any data
) {
var logFile = ( getDirectoryFromPath( getCurrentTemplatePath() ) & "log.txt" );
writeDump(
label = label,
var = data,
output = logFile,
format = "text"
);
}
// ------------------------------------------------------ //
// ------------------------------------------------------ //
// This thread will be spawned, executed, and completed BEFORE
// the current request has finished processing (see JOIN).
thread
name = "duringRequest"
action = "run"
{
var requestData = getHttpRequestData();
logOutput( "Request Data [DURING REQUEST]", requestData );
} // END: Thread.
// Make sure the previous thread actually executes.
thread action = "join";
// ------------------------------------------------------ //
// ------------------------------------------------------ //
// This thread will be forced to "sleep" which will cause the
// body of the thread to execute after the current request has
// finished processing. As such, the getHttpRequestData() method
// will be invoked AFTER the request has finished.
thread
name = "afterRequest"
action = "run"
{
sleep( 500 );
try {
var requestData = getHttpRequestData();
logOutput( "Request Data [AFTER REQUEST]", requestData );
} catch ( any error ) {
logOutput( "Error [AFTER REQUEST]", error );
}
} // END: Thread.
// ------------------------------------------------------ //
// ------------------------------------------------------ //
writeOutput( "Done - #now()#" );
</cfscript>
When we run the above code, here is the log file output (cleaned up slightly):
Request Data [DURING REQUEST] - struct
content: [empty string]
headers:
-- [struct]
-- Accept-Encoding: gzip, deflate
-- Accept-Language: en-US,en;q=0.5
-- accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*
-- connection: keep-alive
-- content-length: 0
-- host: local.bennadel.com
-- user-agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.8; rv:26.0)
method: GET
protocol: HTTP/1.1****************************************************************
Error [AFTER REQUEST] - struct
Message: [empty string]
StackTrace: java.lang.NullPointerException
TagContext:
-- [array]
Type: java.lang.NullPointerException****************************************************************
As you can see, the first CFThread tag was able to invoke getHttpRequestData() without issue. The second CFThread tag, which executed after the parent page request (due to the sleep() call) raised the NullPointerException.
I want to say this is a bug. But, I am not sure it is. There is something that does, admittedly, feel unnatural about calling getHttpRequestData() inside of an asynchronous thread since the thread should, to some degree, not "know" about the parent request. The reason I needed it is because it wasn't being called by the thread directly; instead, the thread was calling something that was throwing an error, that was being logged by the error logging, which was attempting to pull "X-Forwarded-For" (the load-balanced IP address) from the request headers. So, the error was several times removed from the thread.
In any case, just be careful about the sometimes dubious interaction between CFThread and getHttpRequestData() inside ColdFusion.
Want to use code from this post? Check out the license.
Reader Comments
This is a bug, I have also seen other errors with threads similar to this, some with the cgi scope and logging using threads and ColdFusion ORM throwing null pointers when using threads.
There is a bug raised for this, just don't have the number of the top of my head. But it appears that when the request is finished and there are threads still running the scopes are being released before the request and threads are complete.
I say this is a bug, because a request is not considered finished until all threads have been completed.
Anyone using a framework with threads will notice this problem regularly.
@All,
Adam Cameron pointed out that this behavior is _somewhat_ documented in the Learn site (see last NOTE):
https://learn.adobe.com/wiki/display/coldfusionen/cfthread
Still sneaks up on you!
@Andrew,
The ORM stuff sounds like it's definitely a bug, for sure! Since ORM is a feature, not a data structure, there's nothing to pass into the thread (if you wanted to try to make it more thread-safe). Anyway, DB interaction is definitely something that I would consider doing Async, as long as the user didn't need to know about it right away; and, if that is compromised by the request ended, sounds like a real bug.
@Ben, the worst part is trying to track it down. It is intermittent and I am not sure what causes it. But I think it has something to do with
var settings = getApplicationMetadata();
as this is the line it fails on, yes this is sometimes being called from a thread.
Now when I (look away when I say this), look into that further, I found that there is a case where a null pointer is thrown and it seems to do when application scope is no longer there. Not sure about your error message, but in my case it seems to be finding a null key in the application metadata.
@Andrew,
Part of the problem is that these native ColdFusion calls is that they are black-boxed. When you call getApplicationMetaData() and I call getHttpRequestData(), I don't really know what it's doing under the cover. As such, it's much harder to debug.
@Ben - Yep.. Which is why Open Sourcing the Engine would be a great idea. When we find things like this we can fix and resubmit... Only wish Adobe understood that...
Then bugs like this would not be around for 5+ years.
@Andrew,
It would be pretty cool.
I would be VERY curious to know how this bug performs with and without this security fix
http://blogs.coldfusion.com/post.cfm/new-coldfusion-security-update-for-version-9-and-above
@Aaron, well personally I would expect the actual request scope to not be available. But others like cgi and application are available, but under certain conditions it appears that they don't.
@Aaron,
I am not sure. I actually just switched computers. But, I'm pretty sure that when I ran the tests (in the post) I was on a fully-updated ColdFusion 10 install.