Yesterday, I started to explore the Timeout attribute of the CFQuery tag, which is used to terminate long-running queries in ColdFusion. When looking at the MySQL General Log, I could see that ColdFusion was establishing a new connection to the databasing and issuing KILL QUERY commands in order to perform the termination. It made me curious as to what would happen if the connection pool was exhausted at the time when the timeout threshold was reached - could ColdFusion actually issue the KILL QUERY command? To find the answer to this question, I re-ran the previous test with a new datasource whose connection pool was limiting to a single connection.
First, I went into the ColdFusion Administrator and created a new MySQL 5 datasource - "testing_tiny_pool" - that was limited to a single connection:
Then, I wanted to create a control experiment in order to ensure that ColdFusion actually adheres to the single-connection limitation. To test this, I spawned two long-running queries in separate asynchronous CFThread bodies and checked to see if they ran in series, not in parallel:
<cfset startedAt = getTickCount() /> <!--- As a control to our experiment, we want to test that the pool-size of ONE is actually going to be blocking concurrent requests. To do this, we're going to try and spawn 2 long-running queries and then check to confirm that they actually ran in series and NOT in parallel. ---> <!--- Async query one: 5-seconds. ---> <cfthread name="a" action="run"> <cfquery name="thread.results" datasource="testing_tiny_pool"> SELECT SLEEP( 5 ), ( UTC_TIMESTAMP() ) AS ranAt ; </cfquery> </cfthread> <!--- Async query two: 5-seconds. ---> <cfthread name="b" action="run"> <cfquery name="thread.results" datasource="testing_tiny_pool"> SELECT SLEEP( 5 ), ( UTC_TIMESTAMP() ) AS ranAt ; </cfquery> </cfthread> <!--- Now, let's wait for all the threads, and therefore all the queries, to return. ---> <cfthread action="join" /> <cfoutput> <!--- What we expect to see is that this page took ( 5 + 5 ) seconds to execute since the connection pool will have forced the queries to run in series, not in parallel. ---> Page ran in #fix( ( getTickCount() - startedAt ) / 1000 )# seconds. <cfdump var="#cfthread.a#" label="Thread A" /> <cfdump var="#cfthread.b#" label="Thread B" /> </cfoutput>
As you can see, each query should run for 5-seconds thanks to the SLEEP() command. And, since both are using the "testing_tiny_pool" datasource, only one should be allowed to execute at a time; which means that one will block the other until it has returned. When we run this code, we can confirm that the connection pool works as expected:
As you can see, the page ran for 10-seconds in total, which means that one 5-second query did exhaust the connection pool and blocked the other 5-second query, causing both queries to run in serial.
Now that we know that ColdFusion adheres to the size-one connection pool, we can re-run the experiment from yesterday (with a few modifications) using the tiny connection pool. This time, we're going to run two INSERT statements that use the SLEEP() command. The first one will execute successfully while the second one should be interrupted by the timeout:
<!--- First, let's enable and clear the GENERAL LOG so that we can see what queries actually execute in the MySQL database server. ---> <cfquery name="setup" datasource="testing_tiny_pool"> SET GLOBAL general_log = 'ON'; SET GLOBAL log_output = 'TABLE'; TRUNCATE TABLE mysql.general_log ; TRUNCATE TABLE timeout_test ; </cfquery> <cftry> <!--- Now that we are using the tiny connection pool, let's run a query that we know will need to be interrupted and see if ColdFusion can successfully send the KILL QUERY command (while the connection pool is exhausted). ---> <cfquery timeout="3" datasource="testing_tiny_pool"> INSERT INTO timeout_test SET value = SLEEP( 1 ) ; <!--- This is the query we expect to be interrupted by the timeout. ---> INSERT INTO timeout_test SET value = SLEEP( 10 ) ; </cfquery> <cfcatch> <cfdump var="#cfcatch#" label="Query Error" show="type,message,detail" /> </cfcatch> </cftry> <!--- Let's see which test values were actually inserted. ---> <cfquery name="test" datasource="testing_tiny_pool"> SELECT id, value FROM timeout_test </cfquery> <!--- Let's see which query statements were actually executed. ---> <cfquery name="log" datasource="testing_tiny_pool"> SELECT CONVERT( l.argument USING utf8 ) AS argument FROM mysql.general_log l WHERE l.argument NOT LIKE '%general_log%' -- That's THIS query. AND l.argument NOT LIKE '%PROCESSLIST%' -- That's me looking at the processlist. ORDER BY l.event_time ASC </cfquery> <cfdump var="#test#" label="Test Values" /> <cfdump var="#log#" label="MySQL General Log" />
As you can see, the CFQuery timeout of 3-seconds should interrupt the second INSERT statement, which will take 10-seconds to complete. And, when we run this code, we get the following output:
As you can see, the page only ran for 3-seconds, which means that the KILL QUERY command was issued successfully. An interesting little side-quirk is that the second INSERT statement wasn't interrupted - only the SLEEP() function was interrupted - allowing the second INSERT to complete. But, that's not really the main take-away of this result - the real take-away is that, despite the exhausted connection pool, ColdFusion was able to establish a new connect to the MySQL database and issue the KILL QUERY command. From this, we can deduce that ColdFusion does not use the current [exhausted] connection pool in order to terminate queries. I guess it creates one-off connections in order to perform this function.
It's super interesting to understand the mechanics of the ColdFusion CFQuery Timeout attribute. Not only can we see that ColdFusion is implementing the Timeout with KILL QUERY commands (at least with the MySQL 5 driver), we can also see that it creates one-off connections in order to issue said command. This means that it won't be affected by the state of the current connection pool. However, the MySQL server itself will still need to be in a state in which it can accept new connection (presumably) in order for the query timeouts to work.