Olá pessoal,
Tudo bem com vocês ? Espero que sim!
Nesse post eu gostaria de compartilhar com vocês uma situação onde ocorreu um deadlock na madrugada, interrompendo uma rotina crítica, e precisava identificar qual a sessão que ocasionou o deadlock para planejar ações que evitem essa situação. Para ajudar na identificação dessas situações e ter um histórico de deadlocks, vou apresentar algumas soluções para atingir esse objetivo.
O que é um deadlock?
Um deadlock é gerado, quando dois ou mais processos tentam acessar um mesmo objeto, aplicando locks nesse recurso. Sendo assim, esses processos tentam realizar a mesma ação, ao mesmo tempo, no mesmo objeto, e um processo fica aguardando o outro remover o lock para continuar a operação.
Exemplo, o processo A aplica um lock na tabela cliente para realizar um update. O processo B também aplica um lock na tabela cliente para realizar um delete, ao mesmo tempo do processo A. Sendo assim, o processo A fica aguardando o processo B terminar o delete e remover o lock para continuar e o processo B fica aguardando o processo A terminar o update e remover o lock para continuar.
Deadlock ilustrado
Caso o SQL Server não tome uma ação, eles iriam esperar um ao outro infinitamente, e isso é chamado de deadlock.
Como gerar/simular um deadlock
Para entender na prática o que é um deadlock e como ele funciona, vou mostrar a vocês como ele acontece no dia a dia e como o SQL Server se comporta quando o deadlock é identificado.
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 |
USE [dirceuresende] GO IF (OBJECT_ID('dbo.Tabela1') IS NOT NULL) DROP TABLE dbo.Tabela1 CREATE TABLE dbo.Tabela1 ( Id INT IDENTITY(1, 1), Name VARCHAR(100) ) INSERT INTO dbo.Tabela1 ( Name ) VALUES ('Dirceu'), ('Resende') IF (OBJECT_ID('dbo.Tabela2') IS NOT NULL) DROP TABLE dbo.Tabela2 CREATE TABLE dbo.Tabela2 ( Id INT IDENTITY(1, 1), Name VARCHAR(100) ) INSERT INTO dbo.Tabela2 ( Name ) VALUES ('DBA'), ('SQL Server') |
Agora vamos gerar os deadlocks:
Deadlock gerado:
Msg 1205, Level 13, State 45, Line 10
Transaction (Process ID 55) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction.
Assim que o Deadlock Monitor Thread identificou que estava ocorrendo um deadlock na instância, ele tratou de eliminar a sessão mais recente (55), permitindo que a sessão 58 pudesse ser processada, “resolvendo” assim, o deadlock gerado.
Como funciona o Deadlock Monitor Thread
No SQL Server existe um recurso chamado Deadlock Monitor Thread, que é executado em background para identificar e “ajudar” a resolver deadlocks na instância, evitando assim, que as sessões fiquem infinitamente aguardando uma a outra.
Se você fizer uma consulta na DMV sys.dm_os_waiting_tasks, você vai perceber que existem sempre uma tarefa de sistema com o evento REQUEST_FOR_DEADLOCK_SEARCH.
Essa thread é acionada a cada 5 segundos para verificar se existem deadlocks na instância. Se ela encontrar algum deadlock, ela vai matar uma das sessões em deadlock para liberar os recursos travados para a outra sessão que está aguardando.
Como o SQL Server decide qual sessão ele vai eliminar? É bem simples, ele vai eliminar sempre a sessão que possui o menor custo (geralmente, a que foi “lockada” por último), facilitando assim, o rollback das transações realizadas pela sessão que foi escolhida para ser desconectada (vítima do deadlock) – Desde que elas possuam a mesma prioridade. Caso as sessões tenham a mesma prioridade e o mesmo custo, a vítima do deadlock será escolhido aleatoriamente.
Quando o Deadlock Monitor Thread elimina uma sessão por conta de deadlock, ele é executado novamente imediatamente para verificar se o deadlock foi resolvido. Se continuar existindo deadlocks na instância, ele vai eliminar mais sessões e vai diminuindo o tempo dos próximos ciclos de execução em 100ms (a cada ciclo), até que nenhum deadlock seja detectado.
Como definir a prioridade de uma sessão
Quando o Deadlock Monitor Thread identifica que ocorreu um deadlock e começa a avaliar qual sessão ele vai eliminar para “resolver” isso, o primeiro critério a ser considerado é a prioridade da sessão. Por padrão, todas as sessões no SQL Server possuem o valor de prioridade = 0 (NORMAL). Para alterar a prioridade de uma sessão, temos o comando SET DEADLOCK_PRIORITY.
Parâmetros:
– LOW: Prioridade abaixo de NORMAL, cujo valor é -5.
– NORMAL: Prioridade padrão, cujo valor é 0.
– HIGH: Prioridade acima da NORMAL, cujo valor é 5.
– <numeric-priority>: É um intervalo de valor inteiro (-10 a 10) para fornecer 21 níveis de prioridade de deadlock ao invés de apenas 3 caso utilize as pré-definidas.
Exemplos:
|
1 2 3 |
SET DEADLOCK_PRIORITY HIGH -- Comando equivalente a SET DEADLOCK_PRIORITY 5 SET DEADLOCK_PRIORITY -5 SET DEADLOCK_PRIORITY 10 -- Valor máximo |
Vocês se lembram do exemplo que eu criei acima para simular o deadlock? E se a gente executasse novamente, mas alterando a prioridade da sessão que foi eliminada como vítima do deadlock? O que aconteceria?
Aqui é o trecho que conseguia terminar de processar – Agora virou a vítima do Deadlock
Já esse trecho, era a vítima do deadlock no exemplo anterior, pois as duas sessões tinham a mesma prioridade, mas a segunda sessão foi escolhida como vítima do deadlock, porque ela estava com o lock há menos tempo.
Vejam que aumentando a prioridade dela, conseguimos alterar o comportamento do Deadlock Monitor Thread para que esse comando, que considero muito importante, não seja vítima de deadlocks por conta de outros comandos que não tem tanta relevância para o meu negócio, nesse exemplo.
Como identificar os deadlocks que ocorreram na instância
Existem várias métodos que podem ser utilizados para identificar os locks que ocorreram na instância, de modo que você consiga identificar e avaliar os locks depois que eles ocorreram, uma vez que o DBA não vai ficar monitorando manualmente todos os deadlocks, em todas as instâncias do ambiente, o tempo todo.
Como identificar os deadlocks utilizando Trace
Uma maneira fácil e prática de se identificar os locks da instância, é ativar um trace utilizando a trace flag 1222, conforme demonstro abaixo:
|
1 |
DBCC TRACEON (1222,-1) |
Caso você queira verificar se essa traceflag está ativa, basta executar o comando abaixo:
Uma vez que esse trace está ativo, sempre que ocorrer um deadlock na instância, esse evento ficará gravado no log do SQL Server, no qual você pode consultar utilizando a sp_readerrorlog:
Como identificar os deadlocks utilizando DMV’s do System Health
O System Health é um monitoramento utilizando Extended Events (XE), tipo um Default Trace, que fica sendo executado em background e coletando informações da instância. Ele está disponível a partir do SQL Server 2008 e suas informações só podem ser acessadas utilizando query.
Apenas é importante ressaltar que o System Health não salva os registros de deadlock por muito tempo. Por este motivo, você pode criar uma rotina que faça isso por você ou utilize outro método para coletar seus logs de deadlock, como Extended Events.
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 |
DECLARE @TimeZone INT = DATEDIFF(HOUR, GETUTCDATE(), GETDATE()) SELECT DATEADD(HOUR, @TimeZone, xed.value('@timestamp', 'datetime2(3)')) AS CreationDate, xed.query('.') AS XEvent FROM ( SELECT CAST(st.[target_data] AS XML) AS TargetData FROM sys.dm_xe_session_targets AS st INNER JOIN sys.dm_xe_sessions AS s ON s.[address] = st.event_session_address WHERE s.[name] = N'system_health' AND st.target_name = N'ring_buffer' ) AS [Data] CROSS APPLY TargetData.nodes('RingBufferTarget/event[@name="xml_deadlock_report"]') AS XEventData (xed) ORDER BY CreationDate DESC |
Result:
Exemplo de XML:
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 |
<event name="xml_deadlock_report" package="sqlserver" timestamp="2017-09-30T08:52:17.021Z"> <data name="xml_report"> <type name="xml" package="package0" /> <value> <deadlock> <victim-list> <victimProcess id="process22856895468" /> </victim-list> <process-list> <process id="process22856895468" taskpriority="0" logused="256" waitresource="RID: 5:1:120152:0" waittime="1276" ownerId="100827" transactionname="user_transaction" lasttranstarted="2017-09-30T05:52:09.267" XDES="0x22852874ef8" lockMode="U" schedulerid="3" kpid="4972" status="suspended" spid="55" sbid="0" ecid="0" priority="0" trancount="2" lastbatchstarted="2017-09-30T05:52:15.733" lastbatchcompleted="2017-09-30T05:52:15.733" lastattention="2017-09-30T05:51:56.183" clientapp="Microsoft SQL Server Management Studio - Query" hostname="VM-DBA" hostpid="2200" loginname="dirceu.resende" isolationlevel="read committed (2)" xactid="100827" currentdb="5" lockTimeout="4294967295" clientoption1="671090784" clientoption2="390200"> <executionStack> <frame procname="adhoc" line="2" stmtstart="58" stmtend="162" sqlhandle="0x02000000d53b14098425a955752508609e778b8d1cad4e760000000000000000000000000000000000000000"> unknown </frame> <frame procname="adhoc" line="2" stmtstart="132" stmtend="246" sqlhandle="0x02000000df5cef22a95ff03a6b0b4379023f56344638fab40000000000000000000000000000000000000000"> unknown </frame> </executionStack> <inputbuf> -- Passo 6 - Ao tentar travar a Tabela 1, irá ocorrer o deadlock UPDATE dbo.Tabela1 SET Nome = 'Deadlock!!!' WHERE Id = 1 </inputbuf> </process> <process id="process22856895c28" taskpriority="0" logused="256" waitresource="RID: 5:1:120160:0" waittime="5384" ownerId="100823" transactionname="user_transaction" lasttranstarted="2017-09-30T05:52:05.730" XDES="0x2285dcd12c8" lockMode="U" schedulerid="3" kpid="7140" status="suspended" spid="58" sbid="0" ecid="0" priority="0" trancount="2" lastbatchstarted="2017-09-30T05:52:11.623" lastbatchcompleted="2017-09-30T05:52:11.623" lastattention="1900-01-01T00:00:00.623" clientapp="Microsoft SQL Server Management Studio - Query" hostname="VM-DBA" hostpid="2200" loginname="dirceu.resende" isolationlevel="read committed (2)" xactid="100823" currentdb="5" lockTimeout="4294967295" clientoption1="671090784" clientoption2="390200"> <executionStack> <frame procname="adhoc" line="2" stmtstart="58" stmtend="162" sqlhandle="0x02000000d4ef7525180f7893808f3cd0667e81ca40a029cc0000000000000000000000000000000000000000"> unknown </frame> <frame procname="adhoc" line="2" stmtstart="148" stmtend="250" sqlhandle="0x02000000ac5ae60e9734454ae1a17a4d4a6483a8c4c981d30000000000000000000000000000000000000000"> unknown </frame> </executionStack> <inputbuf> -- Passo 5 - Vou tentar travar a Tabela (já possui lock na outra sessão) UPDATE dbo.Tabela2 SET Nome = 'Teste' WHERE Id = 1 </inputbuf> </process> </process-list> <resource-list> <ridlock fileid="1" pageid="120152" dbid="5" objectname="dirceuresende.dbo.Tabela1" id="lock22846d87980" mode="X" associatedObjectId="72057594052280320"> <owner-list> <owner id="process22856895c28" mode="X" /> </owner-list> <waiter-list> <waiter id="process22856895468" mode="U" requestType="wait" /> </waiter-list> </ridlock> <ridlock fileid="1" pageid="120160" dbid="5" objectname="dirceuresende.dbo.Tabela2" id="lock22846d9fb00" mode="X" associatedObjectId="72057594052345856"> <owner-list> <owner id="process22856895468" mode="X" /> </owner-list> <waiter-list> <waiter id="process22856895c28" mode="U" requestType="wait" /> </waiter-list> </ridlock> </resource-list> </deadlock> </value> </data> </event> |
Para criar um histórico de deadlocks manualmente, basta criar um Job que execute esse comando:
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 |
USE [dirceuresende] GO IF (OBJECT_ID('dbo.Historico_Deadlocks_Resumido') IS NULL) BEGIN CREATE TABLE dbo.Historico_Deadlocks_Resumido ( Dt_Log DATETIME, Ds_Log XML ) END DECLARE @Ultimo_Log DATETIME = ISNULL((SELECT MAX(Dt_Log) FROM dbo.Historico_Deadlocks_Resumido WITH(NOLOCK)), '1900-01-01') INSERT INTO dbo.Historico_Deadlocks_Resumido SELECT xed.value('@timestamp', 'datetime2(3)') as CreationDate, xed.query('.') AS XEvent FROM ( SELECT CAST([target_data] AS XML) AS TargetData FROM sys.dm_xe_session_targets AS st INNER JOIN sys.dm_xe_sessions AS s ON s.[address] = st.event_session_address WHERE s.[name] = N'system_health' AND st.target_name = N'ring_buffer' ) AS [Data] CROSS APPLY TargetData.nodes('RingBufferTarget/event[@name="xml_deadlock_report"]') AS XEventData (xed) WHERE xed.value('@timestamp', 'datetime2(3)') > @Ultimo_Log ORDER BY CreationDate DESC |
Como identificar os deadlocks utilizando Extended Events (XE)
O recurso de Extended Events é muito útil para diversas atividades no dia a dia do DBA, e identificação de deadlocks é uma excelente justificativa para começar a utilizá-los. Como a interface para configuração de nova sessão está disponível apenas a partir da versão 2012 do SSMS, vou demonstrar como criar a sessão utilizando a GUI e também por linha de comando.
Inicie uma nova sessão do XE pela interface do SSMS
Nomeie a sessão do XE que você está criando
Marque a opção de não utilizar template
Selecione o evento “xml_deadlock_report”
Selecione os campos globais que você deseja incluir na sessão (fique à vontade)
Aplique os filtros que você deseja (ou deixe em branco para não utilizar filtros)
Selecione onde você deseja salvar os logs, o tamanho máximo e outras configurações da sua sessão
Resumo das configurações da sessão
Após concluir a criação da sessão, lembre-se de ativá-la.
Script gerado:
|
1 2 3 4 5 6 7 8 9 10 |
CREATE EVENT SESSION [Deadlocks] ON SERVER ADD EVENT sqlserver.xml_deadlock_report( ACTION(sqlserver.client_app_name, sqlserver.client_hostname, sqlserver.database_name, sqlserver.plan_handle, sqlserver.session_id, sqlserver.session_server_principal_name, sqlserver.sql_text) ) ADD TARGET package0.event_file(SET filename = N'C:\Logs\Deadlocks.xel') WITH (MAX_MEMORY=4096 KB, EVENT_RETENTION_MODE=ALLOW_SINGLE_EVENT_LOSS, MAX_DISPATCH_LATENCY=30 SECONDS, MAX_EVENT_SIZE=0 KB, MEMORY_PARTITION_MODE=NONE, TRACK_CAUSALITY=OFF, STARTUP_STATE=ON) GO ALTER EVENT SESSION Deadlocks ON SERVER STATE = START GO |
Para consultar os dados dos eventos gerados pela sessão XE, basta executar a query abaixo:
|
1 2 |
SELECT event_data = CONVERT(XML, event_data) FROM sys.fn_xe_file_target_read_file(N'C:\Logs\Deadlocks*.xel', NULL, NULL, NULL); |
Ou se você quiser já gravar na tabela os dados extraídos do XML, segue minha sugestão de consulta:
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104 105 106 107 108 109 110 111 |
IF (OBJECT_ID('dbo.Historico_Deadlocks') IS NULL) BEGIN -- DROP TABLE dbo.Historico_Deadlocks CREATE TABLE dbo.Historico_Deadlocks ( [Dt_Log] DATETIME2, [isVictim] INT, [processId] VARCHAR(100), [processSqlCommand] XML, [resourceDBId] INT, [resourceDBName] NVARCHAR(128), [resourceObjectName] VARCHAR(128), [processWaitResource] VARCHAR(100), [processWaitTime] INT, [processTransactionName] VARCHAR(60), [processStatus] VARCHAR(60), [processSPID] INT, [processClientApp] VARCHAR(256), [processHostname] VARCHAR(256), [processLoginName] VARCHAR(256), [processIsolationLevel] VARCHAR(256), [processCurrentDb] VARCHAR(256), [processCurrentDbName] NVARCHAR(128), [processTranCount] INT, [processLockMode] VARCHAR(10), [resourceFileId] INT, [resourcePageId] INT, [resourceLockMode] VARCHAR(2), [resourceProcessOwner] VARCHAR(128), [resourceProcessOwnerMode] VARCHAR(2) ) END DECLARE @Ultimo_Log DATETIME2 = ISNULL((SELECT MAX(Dt_Log) FROM dbo.Historico_Deadlocks WITH(NOLOCK)), '1900-01-01'), @TimeZone INT = DATEDIFF(HOUR, GETUTCDATE(), GETDATE()) IF (OBJECT_ID('tempdb..#xml_deadlock') IS NOT NULL) DROP TABLE #xml_deadlock SELECT * INTO #xml_deadlock FROM ( SELECT module_guid, package_guid, [object_name], [file_name], [file_offset], DATEADD(HOUR, @TimeZone, CAST(timestamp_utc AS DATETIME2)) AS Dt_Evento, CAST(event_data AS XML) AS TargetData FROM sys.fn_xe_file_target_read_file(N'C:\Logs\Deadlocks*.xel', NULL, NULL, NULL) ) AS [dados] WHERE Dt_Evento > @Ultimo_Log ORDER BY Dt_Evento DESC INSERT INTO dbo.Historico_Deadlocks SELECT DATEADD(HOUR, @TimeZone, dados.event_data.value('@timestamp', 'datetime2')) AS [timestamp], (CASE WHEN vitima.dados.value('@id', 'varchar(100)') = processo.dados.value('@id', 'varchar(100)') THEN 1 ELSE 0 END) AS isVictim, processo.dados.value('@id', 'varchar(100)') AS [processId], processo.dados.query('(inputbuf/text())') AS [processSqlCommand], recurso.resourceDBId, DB_NAME(recurso.resourceDBId) AS resourceDBName, recurso.resourceObjectName, processo.dados.value('@waitresource', 'varchar(100)') AS [processWaitResource], processo.dados.value('@waittime', 'int') AS [processWaitTime], processo.dados.value('@transactionname', 'varchar(60)') AS [processTransactionName], processo.dados.value('@status', 'varchar(60)') AS [processStatus], processo.dados.value('@spid', 'int') AS [processSPID], processo.dados.value('@clientapp', 'varchar(256)') AS [processClientApp], processo.dados.value('@hostname', 'varchar(256)') AS [processHostname], processo.dados.value('@loginname', 'varchar(256)') AS [processLoginName], processo.dados.value('@isolationlevel', 'varchar(256)') AS [processIsolationLevel], processo.dados.value('@currentdb', 'varchar(256)') AS [processCurrentDb], DB_NAME(processo.dados.value('@currentdb', 'varchar(256)')) AS [processCurrentDbName], processo.dados.value('@trancount', 'int') AS [processTranCount], processo.dados.value('@lockMode', 'varchar(10)') AS [processLockMode], recurso.resourceFileId, recurso.resourcePageId, recurso.resourceLockMode, recurso.resourceProcessOwner, recurso.resourceProcessOwnerMode FROM #xml_deadlock A CROSS APPLY A.TargetData.nodes('//event') AS dados(event_data) CROSS APPLY dados.event_data.nodes('data/value/deadlock/victim-list/victimProcess') AS vitima(dados) OUTER APPLY dados.event_data.nodes('data/value/deadlock/process-list/process') AS processo(dados) LEFT JOIN ( SELECT A.Dt_Evento, recurso.dados.value('@fileid', 'int') AS [resourceFileId], recurso.dados.value('@pageid', 'int') AS [resourcePageId], recurso.dados.value('@dbid', 'int') AS [resourceDBId], recurso.dados.value('@objectname', 'varchar(128)') AS [resourceObjectName], recurso.dados.value('@mode', 'varchar(2)') AS [resourceLockMode], [owner].dados.value('@id', 'varchar(128)') AS [resourceProcessOwner], [owner].dados.value('@mode', 'varchar(2)') AS [resourceProcessOwnerMode] FROM #xml_deadlock A CROSS APPLY A.TargetData.nodes('//ridlock') AS recurso(dados) OUTER APPLY recurso.dados.nodes('owner-list/owner') AS owner(dados) ) AS recurso ON recurso.resourceProcessOwner = processo.dados.value('@id', 'varchar(100)') AND recurso.Dt_Evento = A.Dt_Evento |
Result:
And that's it, folks!
Espero que tenham gostado do post e até a próxima.
Portuguese 
English
Descobri, o xml no 2014 eh diferente, alterei para o: ‘//ridlock’ para linha: CROSS APPLY A.TargetData.nodes(‘//objectlock’) AS recurso(dados)
Ótimo post, me ajudou muito. Rodei em Sql 2019 e funcionou perfeitamente.
Porem fui fazer em um SQL2014 e tive q alterar a linha 54 de timestamp_utc para CURRENT_TIMESTAMP, depois disso até a parte da #xml_deadlock inseriu perfeitamente na temp, porem ao inserir na tabela Historico_Deadlocks não foi. Alguma dica?
Obrigado pelo post e sucesso.
Parabéns!!!
Muito Bom deveria fazer cursos de vídeo
Obrigado, meu amigo! Está nos planos!! rs
Parabéns, muito bem explicado e em detalhes…
Show!
O nível instrucional desse blog é fenomenal!
Parabéns!