onError does not load include on query timeout "java.nio.channels.ClosedByInterruptException"

nonfatmedia · October 18, 2024, 4:40pm

When a long running query times out the onError page will not include our generic error handler. cfinclude fails with error

We have had some issues with our DB timing out on certain bad query plans recently and have noticed that our error handler is not running when this occurs. “java.nio.channels.ClosedByInterruptException”

To test the issue:

We have the following in our application.cfc:
Request timeout is set to 2 minutes.

<cffunction name="onError"> 
    <cfargument name="Exception" required="true" /> 
    <cfargument type="String" name="EventName" required="true"/>
<cfdump var="#VARIABLES.error#"/>
	<cfset VARIABLES.error = ARGUMENTS.exception />
	<cftry>
	<cfinclude template="/_errortemplates/cf.exception.cfm">
	<cfcatch><cfdump var="#cfcatch#" label="error loading cf.exception.cfm"/></cfcatch>
</cftry>
</cffunction>

Normally our “/_errortemplates/cf.exception.cfm” would contain additional error handling and a generic error message for the user. For this test we replace the contents of “/_errortemplates/cf.exception.cfm” with just <cfdump var="#VARIABLES.error#"/> <cfabort>

At this point you would expect to have 2 dump outputs with the same contents when any type of exception is thrown.

if you create a page with a query that times out in 3 minutes (mssql)

<cfquery datasource="xxxxx" name="res">
    WAITFOR DELAY '00:03:00';  
    select getdate()
</cfquery>
<cfdump var=#res#/>

What you will see is 2 dumps: the first will be the Query timeout:

Request [/timeout.cfm (C:\Sites\www\breakdown-services-full\casting.breakdownexpress.com\timeout.cfm)] has run into a timeout (timeout: 120 seconds) and has been stopped. The thread started 180227ms ago.

The second is caught by the try in onError(): “java.nio.channels.ClosedByInterruptException” which is not what is expected.
We should be seeing the same cfdump `’ contained within the include.

It basically errors on the cfinclude in on error for query timeouts only.

I would expect the page to timeout after 2 minutes or if not possible because of JDBC then the onError would be called at 3 minutes (when the query finally times out) and handle the include properly

andreas · October 19, 2024, 1:54am

I’m not sure if I can follow you right. Are you expceting the engine to follow all your error nested error handlings, even after request timeout? A request timeout is a full engine timeout. Expecting the engine just to make further decision and continue to run further cfml code blocks, when would you want the timeout to take effect? Wouldn’t you need a timeout again after the first timout? I’d really want Lucee to behave exactly that way and stop any propagation of code. Otherwise we would have dozens of users here asking, why their code isn’t timing out and “ignoring” the timeout setting.

carehart · October 19, 2024, 3:31am

Or here’s another take: do you realize the dump on line 4 could potentially dump a different thing than that in the include, since the first dump PRECEDES your setting variables.error on line 5? That first dumped variable could have been set in code outside/before the function call (perhaps BEFORE that error you’re now focused on).

On the other hand, the dump in the include there would show whatever exception was passed INTO the onerror method, as then set on line 5. That’s at least one reason THEY could potentially “not match”. Or perhaps you’ll add more to clarify things.

BK_BK · October 19, 2024, 2:19pm

To me your question itself raises questions. I am confused and just want to understand. So, please bear with me.

Where does VARIABLES.error come from? As it is an instance variable (of Application.cfc), the code suggests that an error has been observed elsewhere prior to the onError event being triggered. In other words, the code suggests that VARIABLES.error is initialized elsewhere.

On the other hand, suppose that VARIABLES.error is not initialized elsewhere. Then, as long as the application doesn’t encounter an error, you probably wouldn’t notice anything amiss. That is because onError wouldn’t run.

But if the application encounters an error somewhere, thereby triggering onError, the line <cfdump var="#VARIABLES.error#"/>
will itself generate an error. Something like “Element ERROR is undefined in VARIABLES”.

Or, could the current code just be a typing error? Did you, for example, intend to write

<!--- Variables-scoped variable for use in /_errortemplates/cf.exception.cfm --->
<cfset VARIABLES.error = ARGUMENTS.exception />
<cfdump var="#VARIABLES.error#"/>

instead of the other way round?

If so, then the VAR scope is perhaps more appropriate than the VARIABLES scope. By that I mean:

<cffunction name="onError"> 
    <cfargument name="Exception" required="true" /> 
    <cfargument type="String" name="EventName" required="true"/>

	<!--- Var-scoped variable for use in /_errortemplates/cf.exception.cfm --->
	<cfset var localError = ARGUMENTS.exception />
	<cfdump var="#localError#"/>
	
	<cftry>
		<cfinclude template="/_errortemplates/cf.exception.cfm">
	<cfcatch>
		<cfdump var="#cfcatch#" label="error loading cf.exception.cfm"/>
	</cfcatch>
	</cftry>
</cffunction>

BK_BK · October 20, 2024, 11:55am

On taking another look I saw a reason why there may be just one dump. Namely, the first one.

The second dump is in a catch. Therefore, it will be executed only if the code <cfdump var="#VARIABLES.error#"/> <cfabort> has an error. After all, that is the only code in the try-section (contents of “/_errortemplates/cf.exception.cfm” ).

<cfdump var="#VARIABLES.error#"/>
<!--- some omitted code --->
<cftry>
	<cfinclude template="/_errortemplates/cf.exception.cfm">
	<cfcatch>
		<cfdump var="#cfcatch#" label="error loading cf.exception.cfm"/>
	</cfcatch>
</cftry>

<cfabort> is error-free. So that leaves <cfdump var="#VARIABLES.error#"/>. However, if the code <cfdump var="#VARIABLES.error#"/> had an error, then the execution thread could not have gone past it to reach the cftry in the first place.

nonfatmedia · October 21, 2024, 2:36pm

The onError code I entered above is a proof of concept. There are plenty of times when our pages timeout throwing the onError which will cfinclude our error handler. The only time the include fails to load is when a query times out. I do agree that the variables scope is not the best scope. Legacy code. It doesn’t have any impact though on the outcome.

I think it has to do with query timeouts exceeding the page timeout.

This is the dump message of the query error:

Request [/mail/index.cfm has run into a timeout (timeout: 120 seconds) and has been stopped. The thread started 188972ms ago.

Notice how the thread is over 3 minutes but the timeout is set to 2.

BK_BK you are correct the variables.error should come after the set. The actual onError is as follows.

<cffunction name="onError"> 
    <cfargument name="Exception" required="true" /> 
    <cfargument type="String" name="EventName" required="true"/>
	<cfset VARIABLES.error = ARGUMENTS.exception />
<cfdump var="#VARIABLES.error#"/>
	<cftry>
	<cfinclude template="/_errortemplates/cf.exception.cfm">
	<cfcatch><cfdump var="#cfcatch#" label="error loading cf.exception.cfm"/></cfcatch>
</cftry>
</cffunction>

The query (replace xxxxx with a valid datasource) to throw the timeout/error is

<cfquery datasource="xxxxx" name="res">
    WAITFOR DELAY '00:03:00';  
    select getdate()
</cfquery>
<cfdump var=#res#/>

Note: If I copy the contents of the include file (/_errortemplates/cf.exception.cfm) into onError every thing works as expected. /_errortemplates/cf.exception.cfm contains queries, cmail, GetHttpRequestData, cfheader and html.

It just doesn’t like “cfinclude”

nonfatmedia · October 21, 2024, 3:52pm

I expect for application onError() to run code contained within it and for the most part it does. it just doesn’t do includes when the error is a query timeout. it does do includes for other timeouts.