Hola, chicos,
¿Estás bien? ¡Eso espero!

En este post me gustaría compartir con ustedes una situación en la que se produjo un punto muerto en las primeras horas de la mañana, interrumpiendo una rutina crítica, y necesitaba identificar qué sesión causó el punto muerto para planificar acciones para evitar esta situación. Para ayudar a identificar estas situaciones y tener un historial de bloqueos, presentaré algunas soluciones para lograr este objetivo.

¿Qué es un punto muerto?

Un punto muerto se genera cuando dos o más procesos intentan acceder al mismo objeto, aplicando bloqueos a ese recurso. Por lo tanto, estos procesos intentan realizar la misma acción, al mismo tiempo, sobre el mismo objeto, y un proceso espera a que el otro elimine el bloqueo para continuar con la operación.

Ejemplo, el proceso A aplica un bloqueo a la tabla del cliente para realizar una actualización. El proceso B también aplica un bloqueo a la tabla del cliente para realizar una eliminación, al mismo tiempo que el proceso A. Por lo tanto, el proceso A está esperando que el proceso B finalice la eliminación y elimine el bloqueo para continuar y el proceso B está esperando que el proceso A finalice la actualización y elimine el bloqueo para continuar.

Punto muerto ilustrado

Si SQL Server no toma medidas, se esperarían infinitamente, y esto se llama punto muerto.

Cómo generar/simular un punto muerto

Para comprender en la práctica qué es un punto muerto y cómo funciona, le mostraré cómo ocurre a diario y cómo se comporta SQL Server cuando se identifica el punto muerto.

USE [dirceuresende]
GO

IF (OBJECT_ID('dbo.Tabela1') IS NOT NULL) DROP TABLE dbo.Tabela1
CREATE TABLE dbo.Tabela1 (
    Id INT IDENTITY(1, 1),
    Nome VARCHAR(100)
)

INSERT INTO dbo.Tabela1 ( Nome )
VALUES ('Dirceu'), ('Resende')

IF (OBJECT_ID('dbo.Tabela2') IS NOT NULL) DROP TABLE dbo.Tabela2
CREATE TABLE dbo.Tabela2 (
    Id INT IDENTITY(1, 1),
    Nome VARCHAR(100)
)

INSERT INTO dbo.Tabela2 ( Nome )
VALUES ('DBA'), ('SQL Server')

Ahora generemos los puntos muertos:

Punto muerto generado:

Mensaje 1205, Nivel 13, Estado 45, Línea 10
La transacción (ID de proceso 55) se bloqueó en recursos bloqueados con otro proceso y fue elegida como víctima del bloqueo. Vuelva a ejecutar la transacción.

Tan pronto como el hilo Deadlock Monitor identificó que se estaba produciendo un punto muerto en la instancia, intentó eliminar la sesión más reciente (55), permitiendo que se procesara la sesión 58, "resolviendo" así el punto muerto generado.

Cómo funciona el hilo del monitor de interbloqueo

En SQL Server hay una característica llamada Deadlock Monitor Thread, que se ejecuta en segundo plano para identificar y “ayudar” a resolver puntos muertos en la instancia, evitando así que las sesiones se esperen infinitamente unas a otras.

Si consulta DMV sys.dm_os_waiting_tasks, notará que siempre hay una tarea del sistema con el evento REQUEST_FOR_DEADLOCK_SEARCH.

Este hilo se activa cada 5 segundos para comprobar si hay puntos muertos en la instancia. Si encuentra un punto muerto, cerrará una de las sesiones en punto muerto para liberar los recursos bloqueados a la otra sesión en espera.

¿Cómo decide SQL Server qué sesión cerrará? Es muy sencillo, siempre eliminará la sesión que tenga menor coste (generalmente la que fue “bloqueada” en último lugar), facilitando así la reversión de las transacciones realizadas por la sesión que fue elegida para ser desconectada (víctima del interbloqueo) – siempre que tengan la misma prioridad. Si las sesiones tienen la misma prioridad y el mismo coste, la víctima del punto muerto se elegirá al azar.

Cuando el subproceso Deadlock Monitor finaliza una sesión debido a un punto muerto, se ejecuta inmediatamente nuevamente para verificar que el punto muerto se haya resuelto. Si los interbloqueos continúan existiendo en la instancia, eliminará más sesiones y reducirá el tiempo de los siguientes ciclos de ejecución en 100 ms (cada ciclo), hasta que no se detecten interbloqueos.

Cómo establecer la prioridad de una sesión

Cuando el hilo del Deadlock Monitor identifica que se ha producido un punto muerto y comienza a evaluar qué sesión cerrará para “resolverlo”, el primer criterio a considerar es la prioridad de la sesión. De forma predeterminada, todas las sesiones en SQL Server tienen un valor de prioridad = 0 (NORMAL). Para cambiar la prioridad de una sesión, usamos el comando SET DEADLOCK_PRIORITY.

Parámetros:
– BAJA: Prioridad inferior a NORMAL, cuyo valor es -5.
– NORMAL: Prioridad predeterminada, cuyo valor es 0.
– ALTA: Prioridad superior a NORMAL, cuyo valor es 5.
: es un rango de valores enteros (-10 a 10) para proporcionar 21 niveles de prioridad de interbloqueo en lugar de solo 3 si se utilizan los predefinidos.

Ejemplos:

SET DEADLOCK_PRIORITY HIGH -- Comando equivalente a SET DEADLOCK_PRIORITY 5
SET DEADLOCK_PRIORITY -5
SET DEADLOCK_PRIORITY 10 -- Valor máximo

¿Recuerdas el ejemplo que creé arriba para simular un punto muerto? ¿Qué pasaría si lo volviéramos a ejecutar, pero cambiando la prioridad de la sesión que fue eliminada como víctima del punto muerto? ¿Qué pasaría?

Aquí está el extracto que logré terminar de procesar: ahora te has convertido en víctima de Deadlock

Esta sección fue la víctima del punto muerto en el ejemplo anterior, ya que las dos sesiones tenían la misma prioridad, pero la segunda sesión fue elegida como víctima del punto muerto porque había estado bloqueada por menos tiempo.

Vea que al aumentar su prioridad, pudimos cambiar el comportamiento del hilo Deadlock Monitor para que este comando, que considero muy importante, no sea víctima de interbloqueos debido a otros comandos que no son tan relevantes para mi negocio, en este ejemplo.

Cómo identificar interbloqueos que ocurrieron en la instancia

Hay varios métodos que se pueden utilizar para identificar bloqueos que ocurrieron en la instancia, de modo que pueda identificar y evaluar los bloqueos después de que hayan ocurrido, ya que el DBA no monitoreará manualmente todos los interbloqueos, en todas las instancias del entorno, todo el tiempo.

Cómo identificar puntos muertos usando Trace

Una forma fácil y práctica de identificar los bloqueos de la instancia es activar un seguimiento utilizando el indicador de seguimiento 1222, como se muestra a continuación:

DBCC TRACEON (1222,-1)

Si desea verificar si este traceflag está activo, simplemente ejecute el siguiente comando:

Una vez que este seguimiento esté activo, cada vez que se produzca un interbloqueo en la instancia, este evento se registrará en el registro de SQL Server, que puede consultar mediante sp_readerrorlog:

Cómo identificar puntos muertos utilizando los DMV de estado del sistema

El estado del sistema se monitorea mediante eventos extendidos (XE), como un seguimiento predeterminado, que se ejecuta en segundo plano y recopila información de la instancia. Está disponible desde SQL Server 2008 y solo se puede acceder a su información mediante consulta.

Es importante tener en cuenta que System Health no guarda registros de interbloqueos durante mucho tiempo. Por este motivo, puede crear una rutina que haga esto por usted o utilizar otro método para recopilar los registros de interbloqueo, como Eventos extendidos.

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

Resultado:

Ejemplo de XML:

<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 crear un historial de interbloqueos manualmente, simplemente cree un trabajo que ejecute este comando:

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

Cómo identificar puntos muertos mediante eventos extendidos (XE)

La función Eventos extendidos es muy útil para diversas actividades en la vida diaria de un DBA, e identificar puntos muertos es una excelente justificación para comenzar a utilizarlos. Como la interfaz para configurar una nueva sesión solo está disponible en la versión 2012 de SSMS, demostraré cómo crear la sesión usando la GUI y también mediante la línea de comando.

Inicie una nueva sesión XE desde la interfaz SSMS

Nombra la sesión XE que estás creando

Seleccione la opción para no usar plantilla

Seleccione el evento "xml_deadlock_report"

Seleccione los campos globales que desea incluir en la sesión (siéntase libre)

Aplica los filtros que quieras (o déjalo en blanco para no usar filtros)

Seleccione dónde desea guardar los registros, el tamaño máximo y otras configuraciones para su sesión

Resumen de configuración de sesión

Una vez que termines de crear la sesión, recuerda activarla.

Guión generado:

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 los datos de eventos generados por la sesión XE, simplemente ejecute la siguiente consulta:

SELECT event_data = CONVERT(XML, event_data) 
FROM sys.fn_xe_file_target_read_file(N'C:\Logs\Deadlocks*.xel', NULL, NULL, NULL);

O si desea registrar los datos extraídos del XML en la tabla, siga mi consulta sugerida:

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

Resultado:

¡Eso es todo, amigos!
Espero que hayas disfrutado del post y hasta la próxima.