A Very Wonky Request/CFTHREAD Bug

Found some really interesting behaviour with CFTHREAD over the past couple days of testing.  Put this code into three browser tabs and run them concurrently (so you get three simultaneous requests which you can view the output of).  And ensure you have the CF Server Monitor open in a different window with monitoring enabled and the Active ColdFusion Threads report showing.

<cfoutput>
<cfapplication name="#createUUID()#" />
<cfset request.threadName = createUUID() />

<h1>Request: #timeFormat(now(), "HH:mm:ss")#</h1>
<cfflush />
<cfdump var="#cfthread#" label="cfthread is empty" />

<cfthread action="run"
  name="#request.threadName#">
  <cfthread action="sleep" duration="10000" />
</cfthread>

<cfdump var="#cfthread#" label="one thread running" />
<h1>Thread: #timeFormat(cfthread[request.threadName].startTime, "HH:mm:ss")#</h1>
<cfflush />

<cfif structKeyExists(url, "join")>
  <cfthread action="join" name="#request.threadName#" />
</cfif>

<h1>Complete: #timeFormat(now(), "HH:mm:ss")#</h1>
<cfdump var="#cfthread#" label="thread shows completed" />
</cfoutput>

What happens?  As expected, all three requests return immediately, each having spawned a thread.  The server monitor shows that the threads all go away after ten seconds.  Most importantly, all three requests started, launched their thread, and completed at the same time (+/- a few tens of milliseconds).

Now go to the first tab and add "?join" to the URL, which will trigger the joining of the thread back to the request thread.  Refresh all three tabs again.  This time, the tabs without the join command behave exactly the same, but the tab with the join waits for the thread to complete before returning, as evidenced by the "Completed" timestamp.  This is all correct behaviour, so lets get down to it.

Add "?join" to the second tab (so now two tabs will join), and refresh all three tabs a third time.  Notice that the second tab that joins doesn't even start until the first joining request completes.  The non-joining request completes immediately, as always, initiating at the same time as the first joining request.

I don't even know how to characterize this issue.  It's certainly a bug, but I'm not sure what.  Even more baffling, I can't even come up with a theoretical scenario that would cause these symptoms.  Anyone?

10 responses to “A Very Wonky Request/CFTHREAD Bug”

  1. Ben Nadel

    That is very strange. Do you know if the same issue crops up if tab 1 and 2 are different files (ex. Test1.cfm, Test2.cfm). It might be that the threads are somehow tied to the physical file even though they have different requests?

  2. Ben Nadel

    Insanity!

  3. Ken Auenson

    Barney,
    Are you running these tests on CF8 standard?
    I ask because CF8 standard does limit the number of threads that CFThread can use…
    actually, the quote I am finding online is "CFTHREAD is limited to two additional spawned threads in Standard Edition"
    That sounds like it could explain your observations, if some other process was already using one of the threads alotted to CFThread…

  4. Ken Auenson

    Oops…
    I guess I do need to get some sleep!
    Since you do mention the server monitor in your post, this means you are on developer or enterprise edition, so please ignore my previous comment!
    It sure does sound like there is a limiter on the simultaneous running threads, tho!

  5. Ken Auenson

    Barney,
    I spoke up way too soon after only reading your post without actually greping everything you were saying…
    I get exactly what you are describing now!

    I used your code and ran the tests on my dev edition, and I am not able to reproduce. If I run the first and second threads with the joins at the same time, they both run in seperate cfthread threads [different "Java Thread Name"s according to the server monitor]; and they do run in parallel [the second is not waiting for the first to complete].

    HTH!

  6. Ken Auenson

    Barney,
    I ran this test on the vanilla install with the built-in web server on Windows XP… At least… I don't remember installing any of the patches or anything… too many machines to remember! lol

    hope this helps, from CF Admin:
    CF Version 8,0,0,176276
    JVM 1.6.0_01