Cómo monitorear Timeouts en SQL

¿Cuántas veces tus aplicaciones han dado error de Execution Timeout Expired?

En este video tutorial te muestro dos opciones que tenes con SQL para poder monitorear estos errores de Timeout para luego poder cartas en el asunto

Usando Query Store

-- query store moniroting Timeout
ALTER DATABASE [AdventureWorksDW2016_EXT]
SET QUERY_STORE = ON
    (
      OPERATION_MODE = READ_WRITE,
      CLEANUP_POLICY = ( STALE_QUERY_THRESHOLD_DAYS = 90 ),
      DATA_FLUSH_INTERVAL_SECONDS = 900,
      MAX_STORAGE_SIZE_MB = 1024,
      INTERVAL_LENGTH_MINUTES = 60,
      SIZE_BASED_CLEANUP_MODE = AUTO,
      MAX_PLANS_PER_QUERY = 200,
      QUERY_CAPTURE_MODE = ALL
    );
use AdventureWorksDW2016_EXT 
go

BEGIN TRAN
 DECLARE @OnlineSalesKey INT
 select * from FactResellerSalesXL WITH (UPDLOCK)

rollback tran 

-- ponemos en 5 segundos el timeput y en otra sesion corremos
use AdventureWorksDW2016_EXT 
go
select * from FactResellerSalesXL 

-- buscamos el timeput en la base
use AdventureWorksDW2016_EXT 
SELECT
 qst.query_sql_text,
 qrs.execution_type,
 qrs.execution_type_desc,
 qpx.query_plan_xml,
 qrs.count_executions,
 qrs.last_execution_time
FROM sys.query_store_query AS qsq
JOIN sys.query_store_plan AS qsp on qsq.query_id=qsp.query_id
JOIN sys.query_store_query_text AS qst on qsq.query_text_id=qst.query_text_id
OUTER APPLY (SELECT TRY_CONVERT(XML, qsp.query_plan) AS query_plan_xml) AS qpx
JOIN sys.query_store_runtime_stats qrs on qsp.plan_id = qrs.plan_id
WHERE qrs.execution_type =3
ORDER BY qrs.last_execution_time DESC;
GO

Usando eventos extendidos

-- QUERY STORE MONIROTING TIMEOUT
ALTER DATABASE [ADVENTUREWORKSDW2016_EXT]
SET QUERY_STORE = ON
    (
      OPERATION_MODE = READ_WRITE,
      CLEANUP_POLICY = ( STALE_QUERY_THRESHOLD_DAYS = 90 ),
      DATA_FLUSH_INTERVAL_SECONDS = 900,
      MAX_STORAGE_SIZE_MB = 1024,
      INTERVAL_LENGTH_MINUTES = 60,
      SIZE_BASED_CLEANUP_MODE = AUTO,
      MAX_PLANS_PER_QUERY = 200,
      QUERY_CAPTURE_MODE = ALL
    );
USE ADVENTUREWORKSDW2016_EXT 
GO

BEGIN TRAN
 DECLARE @ONLINESALESKEY INT
 SELECT * FROM FACTRESELLERSALESXL WITH (UPDLOCK)

ROLLBACK TRAN 

-- PONEMOS EN 5 SEGUNDOS EL TIMEPUT Y EN OTRA SESION CORREMOS
USE ADVENTUREWORKSDW2016_EXT 
GO
SELECT * FROM FACTRESELLERSALESXL 

-- BUSCAMOS EL TIMEPUT EN LA BASE
USE ADVENTUREWORKSDW2016_EXT 
SELECT
 QST.QUERY_SQL_TEXT,
 QRS.EXECUTION_TYPE,
 QRS.EXECUTION_TYPE_DESC,
 QPX.QUERY_PLAN_XML,
 QRS.COUNT_EXECUTIONS,
 QRS.LAST_EXECUTION_TIME
FROM SYS.QUERY_STORE_QUERY AS QSQ
JOIN SYS.QUERY_STORE_PLAN AS QSP ON QSQ.QUERY_ID=QSP.QUERY_ID
JOIN SYS.QUERY_STORE_QUERY_TEXT AS QST ON QSQ.QUERY_TEXT_ID=QST.QUERY_TEXT_ID
OUTER APPLY (SELECT TRY_CONVERT(XML, QSP.QUERY_PLAN) AS QUERY_PLAN_XML) AS QPX
JOIN SYS.QUERY_STORE_RUNTIME_STATS QRS ON QSP.PLAN_ID = QRS.PLAN_ID
WHERE QRS.EXECUTION_TYPE =3
ORDER BY QRS.LAST_EXECUTION_TIME DESC;
GO
----------------------------------------------------------
-------------------- CON EXTENDED EVENT
-----------------------------------------------------------

CREATE EVENT SESSION [TRIGGERDB_TIMEOUT] ON SERVER
ADD EVENT SQLSERVER.ATTENTION(
    ACTION(SQLSERVER.CLIENT_APP_NAME,
	      SQLSERVER.CLIENT_HOSTNAME,SQLSERVER.DATABASE_ID,
      SQLSERVER.DATABASE_NAME,SQLSERVER.IS_SYSTEM,SQLSERVER.NT_USERNAME,SQLSERVER.SERVER_PRINCIPAL_NAME,
      SQLSERVER.SQL_TEXT,SQLSERVER.USERNAME))
ADD TARGET PACKAGE0.ASYNCHRONOUS_FILE_TARGET
(SET FILENAME = N'TIMEOUT.XEL',
     METADATAFILE = N'TIMEOUT.XEM',
     MAX_FILE_SIZE=(65536),
     MAX_ROLLOVER_FILES=5)
WITH (MAX_MEMORY = 4096KB, 
      EVENT_RETENTION_MODE = ALLOW_SINGLE_EVENT_LOSS, 
	  MAX_DISPATCH_LATENCY = 30 SECONDS, 
	  MAX_EVENT_SIZE = 0KB, MEMORY_PARTITION_MODE = NONE, 
	  TRACK_CAUSALITY = OFF, STARTUP_STATE = ON) 
GO

ALTER EVENT SESSION [TRIGGERDB_TIMEOUT] ON SERVER STATE = START 

-- GENERAMOS TIMEOUT

USE ADVENTUREWORKSDW2016_EXT 
GO



-- VER TIMEOUT

WITH QRY AS (
SELECT
THENODES.EVENT_DATA.VALUE('(ACTION[@NAME="DATABASE_NAME"]/VALUE)[1]','VARCHAR(50)')
           AS DATABASE_NAME,
THENODES.EVENT_DATA.VALUE('(ACTION[@NAME="CLIENT_HOSTNAME"]/VALUE)[1]','VARCHAR(50)')
           AS CLIENT_HOSTNAME,
THENODES.EVENT_DATA.VALUE('(ACTION[@NAME="CLIENT_APP_NAME"]/VALUE)[1]','VARCHAR(50)')
           AS CLIENT_APP_NAME,
THENODES.EVENT_DATA.VALUE('(DATA[@NAME="DURATION"]/VALUE)[1]','BIGINT') AS DURATION,
THENODES.EVENT_DATA.VALUE('(ACTION[@NAME="SQL_TEXT"]/VALUE)[1]','VARCHAR(4000)') AS SQL_TEXT,
THENODES.EVENT_DATA.VALUE('(ACTION[@NAME="USER_NAME"]/VALUE)[1]','VARCHAR(50)') AS USER_NAME,
THENODES.EVENT_DATA.VALUE('(ACTION[@NAME="IS_SYSTEM"]/VALUE)[1]','VARCHAR(50)') AS IS_SYSTEM,
THENODES.EVENT_DATA.VALUE('(ACTION[@NAME="NT_USER_NAME"]/VALUE)[1]','VARCHAR(50)')
           AS NT_USER_NAME,
THENODES.EVENT_DATA.VALUE('(ACTION[@NAME="SERVER_PRINCIPAL_NAME"]/VALUE)[1]','VARCHAR(50)')
           AS SERVER_PRINCIPAL_NAME,
DATEADD(MI,
    DATEDIFF(MI, GETUTCDATE(), CURRENT_TIMESTAMP),
    THENODES.EVENT_DATA.VALUE('(@TIMESTAMP)[1]', 'DATETIME2')) AS [EVENT TIME] 
FROM
      (SELECT CONVERT(XML,EVENT_DATA) EVENT_DATA
            FROM
       SYS.FN_XE_FILE_TARGET_READ_FILE('TIMEOUT_*.XEL', 'TIMEOUT.XEM', NULL, NULL)) AS THEDATA
CROSS APPLY THEDATA.EVENT_DATA.NODES('//EVENT') THENODES(EVENT_DATA)
       )
SELECT  * FROM QRY      
ORDER BY [EVENT TIME] DESC