Erro de Timeout em Query SQL

Hoje o pessoal estava reclamando sobre erros de timeout no SQL Server. Qual seria uma forma eficiente de gerar um trace da aplicação/SQL e identificar quem está causando problemas? Uma forma é gerar um Trace com essas informações e abrir usando a query abaixo.

 SELECT 
    DatabaseName, TextData, 
    StartTime, EndTime, Duration/1000 as 'Duration (ms)', 
    Reads, Writes, CPU, Hostname, LoginName, ApplicationName, 
    SPID
FROM ::fn_trace_gettable('C:\QueryTimeout.trc',1)
    WHERE EventClass in (10,12)

Uma lista dos comandos cancelados fica registrado em um arquivo de Trace chamado “QueryTimeout.TRC”.

image

Observe que a coluna de Duration apresenta valores próximos aos 30 segundos de timeout (30000 milissegundos). Para gerar esse Trace, utilize os scripts de START e STOP que seguem abaixo.

 

Instruções:

  • Copie o script de START para capturar os comandos que foram cancelados por TIMEOUT, substituindo os parâmetros de MAXFILESIZE e FILENAME por valores adequados ao seu ambiente. Rode o script no servidor.
  • Para finalizar a captura de dados, rode o script de STOP, substituindo o parâmetro FILENAME pelo nome do arquivo de Trace correspondente.

 

START: Script para capturar o QueryTimeout

 -------------------------------------------------------- SQL Server 2005/2008                             --------------------------------------------------------declare @rc intdeclare @TraceID intdeclare @maxfilesize bigintdeclare @filename nvarchar(512)declare @intfilter intdeclare @bigintfilter bigint-------------------------------------------------------- PARAMETROS--   @maxfilesize = Tamanho do arquivo (MB)--   @filename = Nome do arquivo (omitir extensão .TRC)------------------------------------------------------set @maxfilesize = 100 set @filename = N'C:\QueryTimeout'-------------------------------------------------------- Criacao do traceexec @rc = sp_trace_create @TraceID output, 0, @filename, @maxfilesize, NULL if (@rc != 0) goto error-- Define os eventos/colunas a serem coletados--  Evento: 10 = RPC:Completed--  Evento: 12 = SQL:BatchCompleteddeclare @on bitset @on = 1exec sp_trace_setevent @TraceID, 10, 7, @onexec sp_trace_setevent @TraceID, 10, 15, @onexec sp_trace_setevent @TraceID, 10, 31, @onexec sp_trace_setevent @TraceID, 10, 8, @onexec sp_trace_setevent @TraceID, 10, 16, @onexec sp_trace_setevent @TraceID, 10, 48, @onexec sp_trace_setevent @TraceID, 10, 64, @onexec sp_trace_setevent @TraceID, 10, 1, @onexec sp_trace_setevent @TraceID, 10, 9, @onexec sp_trace_setevent @TraceID, 10, 17, @onexec sp_trace_setevent @TraceID, 10, 25, @onexec sp_trace_setevent @TraceID, 10, 41, @onexec sp_trace_setevent @TraceID, 10, 49, @onexec sp_trace_setevent @TraceID, 10, 2, @onexec sp_trace_setevent @TraceID, 10, 10, @onexec sp_trace_setevent @TraceID, 10, 18, @onexec sp_trace_setevent @TraceID, 10, 26, @onexec sp_trace_setevent @TraceID, 10, 34, @onexec sp_trace_setevent @TraceID, 10, 50, @onexec sp_trace_setevent @TraceID, 10, 66, @onexec sp_trace_setevent @TraceID, 10, 3, @onexec sp_trace_setevent @TraceID, 10, 11, @onexec sp_trace_setevent @TraceID, 10, 35, @onexec sp_trace_setevent @TraceID, 10, 51, @onexec sp_trace_setevent @TraceID, 10, 4, @onexec sp_trace_setevent @TraceID, 10, 12, @onexec sp_trace_setevent @TraceID, 10, 60, @onexec sp_trace_setevent @TraceID, 10, 13, @onexec sp_trace_setevent @TraceID, 10, 6, @onexec sp_trace_setevent @TraceID, 10, 14, @onexec sp_trace_setevent @TraceID, 12, 7, @onexec sp_trace_setevent @TraceID, 12, 15, @onexec sp_trace_setevent @TraceID, 12, 31, @onexec sp_trace_setevent @TraceID, 12, 8, @onexec sp_trace_setevent @TraceID, 12, 16, @onexec sp_trace_setevent @TraceID, 12, 48, @onexec sp_trace_setevent @TraceID, 12, 64, @onexec sp_trace_setevent @TraceID, 12, 1, @onexec sp_trace_setevent @TraceID, 12, 9, @onexec sp_trace_setevent @TraceID, 12, 17, @onexec sp_trace_setevent @TraceID, 12, 41, @onexec sp_trace_setevent @TraceID, 12, 49, @onexec sp_trace_setevent @TraceID, 12, 6, @onexec sp_trace_setevent @TraceID, 12, 10, @onexec sp_trace_setevent @TraceID, 12, 14, @onexec sp_trace_setevent @TraceID, 12, 18, @onexec sp_trace_setevent @TraceID, 12, 26, @onexec sp_trace_setevent @TraceID, 12, 50, @onexec sp_trace_setevent @TraceID, 12, 66, @onexec sp_trace_setevent @TraceID, 12, 3, @onexec sp_trace_setevent @TraceID, 12, 11, @onexec sp_trace_setevent @TraceID, 12, 35, @onexec sp_trace_setevent @TraceID, 12, 51, @onexec sp_trace_setevent @TraceID, 12, 4, @onexec sp_trace_setevent @TraceID, 12, 12, @onexec sp_trace_setevent @TraceID, 12, 60, @onexec sp_trace_setevent @TraceID, 12, 13, @on-- Configura o filtro--   Filter: Column Duration > 500 (ms) --   Filter: Column ERROR = 2 (ABORT)set @bigintfilter = 500000exec sp_trace_setfilter @TraceID, 13, 0, 4, @bigintfilterset @intfilter = 2exec sp_trace_setfilter @TraceID, 31, 0, 0, @intfilter-------------------------------------------------------- START: Inicia a coleta de eventos------------------------------------------------------exec sp_trace_setstatus @TraceID, 1-------------------------------------------------------- FIM------------------------------------------------------error: -- select ErrorCode=@rcfinish: select * from sys.traces where id = @TraceID------------------------------------------------------  

 

STOP: Script para finalizar o trace

 -------------------------------------------------------- STOP: Trace------------------------------------------------------declare @TraceID intdeclare @filename nvarchar(512)-------------------------------------------------------- PARAMETROS--  @filename = Nome do arquivo do Trace (.TRC)------------------------------------------------------set @filename = N'C:\QueryTimeout.trc'select @TraceID = id from sys.traces where path = @filename if @TraceID is NULLBEGIN  PRINT 'Trace nao encontrado. Path=' + @filename goto finishENDexec sp_trace_setstatus @TraceID, 0exec sp_trace_setstatus @TraceID, 2select * from sys.traces where path is not nullfinish: