How to detect query timeout errors with Extended Events

~ franklinyamamoto

A common error that pops up in application logs as a result of long executions is:

When these start showing up in an application log, it is a good indicator that a performance issue may be occurring in SQL Server.  So far as SQL Server is concerned, it thinks the application dropped or cancelled the request.

This is not a SQL Server query timeout

This is a query timeout occurring on the application server.  This indicates that the application server got tired of waiting for a query to respond so it cancels execution of the query.  By default, most drivers (JDBC, ADO.NET, ADO) will give up on waiting for a response from SQL Server after 30 seconds.  As a result, the DBA may not be aware there is a problem until after the application team reports a problem.

Let’s be proactive

By default there is no way (out of the box) to know this is occurring from a SQL Server perspective.  In SQL Server 2012 and later you can now create an extended event session to track this.  You can do this by watching for the attention event:

sqlserver.attention

By creating an event session, we can capture the occurrence of this happening, as well as some additional information useful in diagnosing the problem.

Below is a script that will create a file target for tracking occurrences of this.  This will capture some session information as well as the query that encountered the problem.  This script only includes user processes.

CREATE EVENT SESSION execution_timeout ON SERVER
ADD EVENT sqlserver.attention
(ACTION (sqlserver.session_id, sqlserver.database_id, sqlserver.database_name,
sqlserver.username, sqlserver.sql_text, sqlserver.client_hostname,
sqlserver.client_app_name)
WHERE ([package0].[equal_boolean]([sqlserver].[is_system],(0))))
ADD TARGET package0.event_file(SET filename=N'execution_timeout.xel',
max_file_size=(5),max_rollover_files=(2))
ALTER EVENT SESSION execution_timeout  ON SERVER STATE = start

Viewing the data

‘To view the data you can run the following query:

SELECT
object_name, convert(xml,event_data), file_name, file_offset
FROM sys.fn_xe_file_target_read_file(N'execution_timeout*.xel',
NULL,NULL,NULL)

Any rows returned are an indicator of cancelled executions.  You can click on the XML column to view the contents.  You can apply filtering in this on the client_app_name to avoid activity coming from things not related to applications of interest (i.e. filter out SSMS).

Conclusion

If you want to tie this into some sort of alerting mechanism it’ll take some additional work; however, this at least gets you to where you can see errors you otherwise would not have known about until someone complained.  Happy debugging!

SQLGrease and query timeout errors

How can SQLGrease help you get to the root cause of your query timeout errors?  Watch our demo video showing how SQLGrease can get to the root cause of very complex query timeouts.

6 thoughts on “How to detect query timeout errors with Extended Events”

  1. Good article, after reading that i finally figured out why some queries were not showing up in traces/extended events. They were stopped by the app server!

    Thanks for this 🙂

    Theo (nl)

    1. Thank you for your script and a brief explanation.
      I’m curious regarding how to read the output from this targeted event. What increment is ‘Duration’; milliseconds?

      1. There isn’t a duration returned from this. This only indicates that something (i.e. an application or user) cancelled a long running request.

  2. How heavy is this session performance wise? I just wanted to make sure that it won’t hurting the server when running on production.

    1. It’s really lightweight. That’s one of the reasons I didn’t bother to capture the execution plans in it. You can modify it to be more targeted by host, user, or application (I’d suggest filtering out SSMS calls).

Comments are closed.