Identificar problemas e realizar troubleshoot está intimamente ligado ao dia a dia de qualquer Administrador de Banco de Dados (DBA). Independentemente do Sistema de Gerenciamento de Banco de Dados (SGBD) no qual se trabalha, vasculhar e escovar bit a fim de solucionar problemas é uma atividade rotineira do DBA, assim como em muitos casos atuando de forma proativa na identificação de sintomas antes que eles virem problemas para seu ambiente.

Acredito que uma das principais dificuldades do troubleshoot é inicia-lo. Por onde começar? Como começar? Que ferramenta utilizar? A resposta para essas perguntas sem duvida é a chave para iniciar um bom troubleshoot. Neste artigo, vamos estudar as Wait Statistics no Microsoft SQL Server, compreendendo suas estruturas internas e seu funcionamento com o intuito de captar como podemos utilizá-las no pontapé inicial de um troubleshoot.

O que é Wait Statistics?

Para entendermos as wait statistics ou estatísticas de espera, vamos primeiro pensar de uma forma diferente. Quando solicitamos alguma coisa ao SQL Server, uma série de tarefas é executada para retornar e efetivar nossa solicitação, certo? A solicitação é dividida em threads e um schedule aloca o processador para executar esses works; até aí tudo bem, o SQL Server está intimamente ligado ao sistema operacional, que por sua vez controla seus recursos.

Vamos imaginar um cenário no qual um processo xpto do SQL Server entra em execução no processador, e esse processo xpto sinaliza que precisa utilizar o recurso de I/O, mas o disco está em uso por outro processo. Com isso, o processo xpto do SQL Server que estava em execução é retirado do processador e colocado em uma fila não ordenada, passando a ser denominado suspenso. Esse processo xpto fica suspenso até que seja notificado que o recurso já está disponível, com isso, o processo xpto é colocado em espera e entra na fila (FIFO) para ser processado novamente. E assim por diante: sempre que um processo está em execução (RUNNABLE) precisa de um recurso e não está disponível, ele é enviado para a fila de suspensos ate que o recurso fique disponível. Com a dmv sys.dm_exec_request, conseguimos identificar os processos e seus estados.

Com esse comentário sucinto sobre os processos, fica mais fácil de entender as famosas estatísticas de espera. O SQL Server mantém o controle total do tempo de seus processos, tornando possível identificar o tempo que cada processo levou do início ao fim e contabilizando o tempo na fila de execução (RUNNABLE) e também nas filas de suspenso e espera por algum recurso específicos.

Ok, mas o que realmente são as wait statistics? Por alto, são objetos que armazenam ocorrências de espera registrada pelo SQL Server. Beleza, Luiz, mas o que é espera para o SQL Server? Sempre que o banco de dados precisa esperar por algum recurso, seja ele disco, RAM, CPU, rede, OLEDB, enfim, tudo que cause alguma obstrução na execução do processo, pode ser categorizado como espera. Como mencionado anteriormente, o processo xpto estava em execução e solicitou recurso de disco que já estava alocado para outro processo e, devido a isso, teve que esperar pelo recurso para finalizar o processamento. Esse tempo é armazenado e são as famosas wait statistics, estatísticas de espera ou ainda eventos de espera.

Existem vários tipos de espera que chamamos de wait types, e conseguimos analisá-las e identificar onde está o gargalo, por exemplo, determinar se estamos sofrendo com pressão de CPU, RAM, Disco ou se estamos com muito CXPACKET, que são as famosas esperas nas consultas paralelas. Realizando esse estudo, conseguimos direcionar um caminho mais lógico para o troubleshoot, conduzindo com foco para solucionar o problema raiz e evitamos perca de tempo analisando coisas alheias ao problema central.

É importante ressaltar que as estatísticas de espera estão no nível de instância e seus valores são reiniciados toda vez que ocorre um stop/start no serviço do SQL Server, ou de forma manual com o comando T-SQL DBCC SQLPERF(‘sys.dm_os_wait_stats’,CLEAR);

O script a seguir retorna uma lista com as principais estatísticas de espera registradas em uma determinada instância SQL Server.

-- Retorna Wait Statistics
WITH [Waits] AS
    (SELECT
        [wait_type],
        [wait_time_ms] / 1000.0 AS [WaitS],
        ([wait_time_ms] - [signal_wait_time_ms]) / 1000.0 AS [ResourceS],
        [signal_wait_time_ms] / 1000.0 AS [SignalS],
        [waiting_tasks_count] AS [WaitCount],
        100.0 * [wait_time_ms] / SUM ([wait_time_ms]) OVER() AS [Percentage],
        ROW_NUMBER() OVER(ORDER BY [wait_time_ms] DESC) AS [RowNum]
    FROM sys.dm_os_wait_stats
    WHERE [wait_type] NOT IN (
        N'BROKER_EVENTHANDLER',         N'BROKER_RECEIVE_WAITFOR',
        N'BROKER_TASK_STOP',            N'BROKER_TO_FLUSH',
        N'BROKER_TRANSMITTER',          N'CHECKPOINT_QUEUE',
        N'CHKPT',                       N'CLR_AUTO_EVENT',
        N'CLR_MANUAL_EVENT',            N'CLR_SEMAPHORE',
        N'DBMIRROR_DBM_EVENT',          N'DBMIRROR_EVENTS_QUEUE',
        N'DBMIRROR_WORKER_QUEUE',       N'DBMIRRORING_CMD',
        N'DIRTY_PAGE_POLL',             N'DISPATCHER_QUEUE_SEMAPHORE',
        N'EXECSYNC',                    N'FSAGENT',
        N'FT_IFTS_SCHEDULER_IDLE_WAIT', N'FT_IFTSHC_MUTEX',
        N'HADR_CLUSAPI_CALL',           N'HADR_FILESTREAM_IOMGR_IOCOMPLETION',
        N'HADR_LOGCAPTURE_WAIT',        N'HADR_NOTIFICATION_DEQUEUE',
        N'HADR_TIMER_TASK',             N'HADR_WORK_QUEUE',
        N'KSOURCE_WAKEUP',              N'LAZYWRITER_SLEEP',
        N'LOGMGR_QUEUE',                N'ONDEMAND_TASK_QUEUE',
        N'PWAIT_ALL_COMPONENTS_INITIALIZED',
        N'QDS_PERSIST_TASK_MAIN_LOOP_SLEEP',
        N'QDS_CLEANUP_STALE_QUERIES_TASK_MAIN_LOOP_SLEEP',
        N'REQUEST_FOR_DEADLOCK_SEARCH', N'RESOURCE_QUEUE',
        N'SERVER_IDLE_CHECK',           N'SLEEP_BPOOL_FLUSH',
        N'SLEEP_DBSTARTUP',             N'SLEEP_DCOMSTARTUP',
        N'SLEEP_MASTERDBREADY',         N'SLEEP_MASTERMDREADY',
        N'SLEEP_MASTERUPGRADED',        N'SLEEP_MSDBSTARTUP',
        N'SLEEP_SYSTEMTASK',            N'SLEEP_TASK',
        N'SLEEP_TEMPDBSTARTUP',         N'SNI_HTTP_ACCEPT',
        N'SP_SERVER_DIAGNOSTICS_SLEEP', N'SQLTRACE_BUFFER_FLUSH',
        N'SQLTRACE_INCREMENTAL_FLUSH_SLEEP',
        N'SQLTRACE_WAIT_ENTRIES',       N'WAIT_FOR_RESULTS',
        N'WAITFOR',                     N'WAITFOR_TASKSHUTDOWN',
        N'WAIT_XTP_HOST_WAIT',          N'WAIT_XTP_OFFLINE_CKPT_NEW_LOG',
        N'WAIT_XTP_CKPT_CLOSE',         N'XE_DISPATCHER_JOIN',
        N'XE_DISPATCHER_WAIT',          N'XE_TIMER_EVENT')
    )
SELECT
    [W1].[wait_type] AS [WaitType],
    CAST ([W1].[WaitS] AS DECIMAL (16, 2)) AS [Wait_S],
    CAST ([W1].[ResourceS] AS DECIMAL (16, 2)) AS [Resource_S],
    CAST ([W1].[SignalS] AS DECIMAL (16, 2)) AS [Signal_S],
    [W1].[WaitCount] AS [WaitCount],
    CAST ([W1].[Percentage] AS DECIMAL (5, 2)) AS [Percentage],
    CAST (([W1].[WaitS] / [W1].[WaitCount]) AS DECIMAL (16, 4)) AS [AvgWait_S],
    CAST (([W1].[ResourceS] / [W1].[WaitCount]) AS DECIMAL (16, 4)) AS [AvgRes_S],
    CAST (([W1].[SignalS] / [W1].[WaitCount]) AS DECIMAL (16, 4)) AS [AvgSig_S]
FROM [Waits] AS [W1]
INNER JOIN [Waits] AS [W2]
    ON [W2].[RowNum] <= [W1].[RowNum]
GROUP BY [W1].[RowNum], [W1].[wait_type], [W1].[WaitS],
    [W1].[ResourceS], [W1].[SignalS], [W1].[WaitCount], [W1].[Percentage]
HAVING SUM ([W2].[Percentage]) - [W1].[Percentage] < 95; -- percentage threshold
GO

No caso dessa instância, o vilão principal com 61,34% é o wait type LCK_M_S, o que significa que a transação está esperando muito tempo para adquirir bloqueio compartilhado (shared lock). Isso pode ser por decorrência de transações muito longas, configuração do isolation level e por mais algumas coisas. Em segundo lugar, foi capturado o wait type IO_COMPLETION, com 14.47%, o que significa que operações estão esperando um tempo significativo por I/O, seja ela leitura ou escrita. Essa espera pode ser diagnosticada pela perda de desempenho, e alguns dos motivos podem ser concorrências no subsistema de armazenamento e discos lentos. Analisando o terceiro wait type, PAGEIOLATCH_SH que segundo Book Online é

PAGEIOLATCH_SH
Occurs when a task is waiting on a latch for a buffer that is in an I/O request. The latch request is in Shared mode. Long waits may indicate problems with the disk subsystem.

é possível observar uma relação entre eles. Teoricamente, o problema de um é gerado pela existência do outro, o que indica que estão intimamente ligados á mesma solução. Com essas informações obtidas através das wait statistics, conseguimos traçar um caminho, uma linha de raciocino no troubleshoot a fim de solucionar o problema.

As informações coletadas pelas estatísticas são de extrema importância e altamente relevantes no ambiente na caça ao problema, mas elas não são mágicas e não irão nos dizer exatamente qual é a solução para todos os problemas que podem ocorrer no SQL Server. Cabe a nós analisá-las da melhor forma possível com o propósito de trilhar de forma mais inteligente um troubleshoot eficiente.

Bons estudos.