Dziennik transakcji rośnie z powodu długotrwałych transakcji podczas korzystania z funkcji przechwytywania zmian danych — SQL Server & Azure SQL

Ten artykuł ułatwia monitorowanie i identyfikowanie problemu ciągłego wzrostu dziennika transakcji spowodowanego długotrwałymi transakcjami w bazie danych z włączoną funkcją przechwytywania zmian danych (CDC) w SQL Server, Azure SQL Database i Azure SQL Managed Instance.

Symptomy

Rozpatrzmy następujący scenariusz:

• Włącz funkcję Przechwytywanie zmian danych w bazie danych.
• Źródłem danych zmian dla cdc jest dziennik transakcji. W miarę wstawiania, aktualizacji i usuwania do śledzonych tabel źródłowych wpisy opisujące te zmiany są dodawane do dziennika.
• Dziennik transakcji w bazie danych rośnie z powodu długotrwałych transakcji.
• Podczas wykonywania zapytań dotyczących bazy danych sys.database dla danej bazy danych kolumna log_reuse_wait_desc zawiera wartość REPLICATION.

W tym scenariuszu plik dziennika transakcji bazy danych stopniowo rośnie, co prowadzi do nadmiernego zużycia miejsca w dzienniku transakcji. Gdy rozmiar dziennika transakcji osiągnie maksymalny zdefiniowany limit, zapis w bazie danych zakończy się niepowodzeniem.

Przyczyna

W bazie danych z włączoną funkcją CDC opóźnienie zadania przechwytywania wstrzymuje obcinanie dziennika w celu zapewnienia, że zmiany mogą zostać przechwycone z dziennika transakcji do tabel zmian CDC, co zapobiega utracie danych zmian.

Obejście problemu

Za pomocą języka Transact-SQL (T-SQL) można określić próg dziennika transakcji i interwał czasu monitorowania dziennika transakcji. W razie potrzeby możesz zakończyć transakcje, ustawiając wartość @kill_oldest_tran = 1.

Aby monitorować dziennik transakcji, użyj następującego zapytania języka T-SQL:

DECLARE 
    -- Log Transactions that generated Txlog over this size
    @transaction_log_bytes_used INT = 5242880,    -- 5MB (UPDATE)
    -- Log full threshold
    @log_full_threshold INT = 30,                 -- Percent (UPDATE)
    -- Kill Oldest Tran (0 = FALSE or 1 = TRUE)
    @kill_oldest_tran BIT = 0,                    --(UPDATE)
    -- Log Transactions over this duration
    @active_tran_time_minutes INT = 15,           --(UPDATE)
    -- This variable specifies the loop delay, format is Hours:minutes:seconds
    @delay VARCHAR(9) = '00:10:00',
    @runtime DATETIME,
    @starttime DATETIME,
    @msg NVARCHAR(100),
    @oldest_tran_id BIGINT,
    @oldest_tran_session_id INT,
    @oldest_tran_begin_time DATETIME,
    @killstr NVARCHAR(100)

IF OBJECT_ID('tblDiagLongTransactions') IS NULL
BEGIN
    CREATE TABLE tblDiagLongTransactions 
    (
        [datacollectiontime] [datetime] NOT NULL,
        [transaction_id] [bigint] NOT NULL,
        [name] [nvarchar](32) NOT NULL,
        [transaction_begin_time] [datetime] NOT NULL,
        [transaction_type] [int] NOT NULL,
        [transaction_state] [int] NOT NULL,
        [session_id] [int] NOT NULL,
        [is_user_transaction] [bit] NOT NULL,
        [database_transaction_log_bytes_used] [bigint] NOT NULL,
        [login_time] [datetime] NOT NULL,
        [last_request_start_time] [datetime] NOT NULL,
        [last_request_end_time] [datetime] NULL,
        [transaction_isolation_level] [smallint] NOT NULL,
        [host_name] [nvarchar](128) NULL,
        [nt_user_name] [nvarchar](128) NULL,
        [command] [nvarchar](32) NULL,
        [status] [nvarchar](30) NULL,
        [cpu_time] [int] NULL,
        [total_elapsed_time] [int] NULL,
        [Transaction_time_in_mins] [int] NULL,
        [logical_reads] [bigint] NULL,
        [wait_time] [int] NULL,
        [wait_type] [nvarchar](60) NULL,
        [wait_resource] [nvarchar](256) NULL,
        [blocking_session_id] [smallint] NULL,
        [program_name] [nvarchar](128) NULL,
        [granted_query_memory] [int] NULL,
        [writes] [bigint] NULL,
        [Request Reads] [bigint] NULL,
        [Session Reads] [bigint] NOT NULL,
        [Session Logical Reads] [bigint] NOT NULL,
        [statement_text] [nvarchar](max) NULL,
        [batch_text] [nvarchar](max) NULL,
        [objectid] [int] NULL,
        [query_hash] BINARY(8),
        [query_plan_hash] BINARY(8),
        [mostrecentsqltext] [nvarchar](max) NULL
    ) ON [PRIMARY]
END

WHILE (1=1)
BEGIN
    -- Check if the database log used space is over the threshold

    SET @runtime = GETDATE()
    INSERT INTO tblDiagLongTransactions
    SELECT DISTINCT 
        @runtime AS datacollectiontime,
        atr.transaction_id,
        atr.name,
        transaction_begin_time,
        transaction_type,
        transaction_state,
        dsr.session_id,
        dsr.is_user_transaction,
        dtr.database_transaction_log_bytes_used,
        s.login_time,
        s.last_request_start_time,
        s.last_request_end_time,
        s.transaction_isolation_level,
        s.host_name,
        s.nt_user_name,
        r.command,
        r.status,
        r.cpu_time,
        r.total_elapsed_time,
        DATEDIFF(mi, transaction_begin_time, getdate()) AS 'Transaction_time_in_mins',
        r.logical_reads,
        r.wait_time,
        r.wait_type,
        r.wait_resource,
        r.blocking_session_id,
        s.program_name,
        r.granted_query_memory,
        r.writes,
        r.reads AS [Request Reads],
        s.reads AS [Session Reads],
        s.logical_reads AS [Session Logical Reads],
        (REPLACE(REPLACE(REPLACE(REPLACE(SUBSTRING(qt.text, r.statement_start_offset / 2 + 1,
            (CASE WHEN r.statement_end_offset = -1 THEN LEN(CONVERT(NVARCHAR(MAX), qt.text)) * 2
                ELSE r.statement_end_offset
            END - r.statement_start_offset) / 2), ' ', ''), CHAR(13), ''), CHAR(10), ''), CHAR(9), '')) AS statement_text,
        SUBSTRING(REPLACE(REPLACE(REPLACE(REPLACE(qt.text, ' ', ''), CHAR(13), ''), CHAR(10), ''), CHAR(9), ''), 1, 256) AS batch_text,
        qt.objectid,
        query_hash,
        query_plan_hash,
        mqt.text
    FROM sys.dm_tran_active_transactions atr
    INNER JOIN sys.dm_tran_database_transactions dtr ON atr.transaction_id = dtr.transaction_id
    INNER JOIN sys.dm_tran_session_transactions dsr ON atr.transaction_id = dsr.transaction_id
    LEFT OUTER JOIN sys.dm_exec_sessions s ON dsr.session_id = s.session_id
    LEFT OUTER JOIN sys.dm_exec_connections conn ON s.session_id = dsr.session_id
    LEFT OUTER JOIN sys.dm_exec_requests r ON r.session_id = s.session_id
    OUTER APPLY sys.dm_exec_sql_text(r.sql_handle) AS qt
    OUTER APPLY sys.dm_exec_sql_text(conn.most_recent_sql_handle) AS mqt
    WHERE s.session_id != @@spid
        AND atr.transaction_type != 2
        AND (database_transaction_log_bytes_used > @transaction_log_bytes_used
            OR datediff(minute, transaction_begin_time, getdate()) > @active_tran_time_minutes)
    
    -- Check Log full threshold
    IF @kill_oldest_tran = 1
    BEGIN
        IF EXISTS (
            SELECT 1 FROM sys.dm_db_log_space_usage
            WHERE used_log_space_in_percent >= @log_full_threshold
        )
        BEGIN
            SELECT TOP 1
                @oldest_tran_id = atr.transaction_id,
                @oldest_tran_begin_time = transaction_begin_time,
                @oldest_tran_session_id = dsr.session_id
            FROM sys.dm_tran_active_transactions atr
            LEFT OUTER JOIN sys.dm_tran_database_transactions dtr ON atr.transaction_id = dtr.transaction_id
            LEFT OUTER JOIN sys.dm_tran_session_transactions dsr ON atr.transaction_id = dsr.transaction_id
            LEFT OUTER JOIN sys.dm_exec_sessions s ON dsr.session_id = s.session_id
            WHERE dsr.session_id != @@spid
                AND is_user_transaction = 1
            ORDER BY transaction_begin_time DESC

            SELECT @oldest_tran_id AS TranID, @oldest_tran_begin_time AS TranbeginTime, @oldest_tran_session_id AS SessionID
            SET @killstr = 'KILL ' + CAST(@oldest_tran_session_id AS VARCHAR(100))
            PRINT @killstr
            
            -- Kill oldest tran
            EXEC (@killstr)
            -- Checkpoint
            CHECKPOINT
        END
    END

    -- Change the polling interval as required
    WAITFOR DELAY @delay

END