Finding Timeout-Prone Code with max_elapsed_time

Consider a scenario where your application timeout setting is 30 seconds and you’ve been asked to proactively start tuning workloads that are at risk of timing out.  There are several different places you can start, and I want to demonstrate an additional option today.

To demonstrate timeout settings, I can configure it in SQL Server Management Studio via the “Execution time-out” setting:

Next – let’s create two procedures that have two different WAITFOR thresholds (one which doesn’t time out and another that will):

CREATE PROCEDURE [dbo].[TimeOutProne]
AS
WAITFOR DELAY '00:00:29';
GO

CREATE PROCEDURE [dbo].[TimeOutProneV2]
AS
WAITFOR DELAY '00:00:30';
GO

Execute both of these (starting with the one that succeeds and the one that times out next):

EXEC [dbo].[TimeOutProne];
GO

EXEC [dbo].[TimeOutProneV2];
GO

The first execute succeeds and the second times out with the following error message:

Msg -2, Level 11, State 0, Line 13
Timeout expired.  The timeout period elapsed prior to completion of the operation or the server is not responding.

Now execute the following query against dm_exec_procedure_stats:

SELECT  [database_id] ,
OBJECT_NAME([object_id]) AS [object_name] ,
[max_elapsed_time],
[plan_handle],
[sql_handle]
FROM [sys].[dm_exec_procedure_stats]
WHERE [max_elapsed_time] > 28000000;  -- microseconds, "but only accurate to milliseconds"

Interestingly enough – even though the second query timed out – we still have accumulated max_elapsed_time stats for it prior to timeout:

I included plan_handle and sql_handle for later hook-ins – just keeping things minimal for demonstration purposes.

So if you’re seeing timeouts and want to start narrowing down workloads that are getting near or exceeding the timeout, both sys.dm_exec_procedure_stats and sys.sys.dm_exec_query_stats max_elapsed_time can be a helpful piece of information to work with.