0

I've got setup extended events that tracks all failed queries by specific users.

We have identical SQL Trace running side by side and expect things to work identically, however XE sessions seems not to capture failed RPC statements that are deadlocking or are calling functions.

CREATE EVENT SESSION [SqlExceptions]
ON SERVER
ADD EVENT sqlserver.error_reported (
    ACTION (
        sqlserver.client_hostname
        , sqlserver.database_name
        , sqlserver.is_system
        , sqlserver.sql_text
        , sqlserver.username
        )
    WHERE (
        [severity] > (10)
        AND [severity] < (17)
        AND (
            [username] = 'username1'
            OR [username] = 'username2'
            OR [username] = 'username3'
            OR [username] = 'username4'
            )
        )
    )
ADD TARGET package0.ring_buffer (SET max_events_limit = (1000))
    WITH (
        MAX_MEMORY = 4096 KB
        , EVENT_RETENTION_MODE = ALLOW_SINGLE_EVENT_LOSS
        , MAX_DISPATCH_LATENCY = 5 SECONDS
        , MAX_EVENT_SIZE = 0 KB
        , MEMORY_PARTITION_MODE = NONE
        , TRACK_CAUSALITY = ON
        , STARTUP_STATE = ON
        );
GO

That's how my SP code looks like:

CREATE PROCEDURE [Online].[GetSegmentation] (@Parameter INT)
AS
BEGIN
    SET NOCOUNT ON;
    BEGIN TRY
        SELECT *
        FROM dbo.SomeFunction(@Parameter);
    END TRY
    BEGIN CATCH
        EXECUTE dbo.PrintErrorMessage;
        EXECUTE dbo.LogError;
    END CATCH
END
GO

dbo.PrintErrorMessage is a legacy procedure, that prints error (It was created before THROW; statement has been added) and is still widely used. That's code:

CREATE PROCEDURE dbo.PrintErrorMessage
AS
BEGIN
    SET NOCOUNT ON;
    DECLARE @CMD NVARCHAR(200);
    DECLARE @EventType NVARCHAR(100);
    DECLARE @Parameters NVARCHAR(2000);
    DECLARE @Statement NVARCHAR(4000);
    DECLARE @ERROR_SEVERITY INT
        , @ERROR_STATE INT
        , @ERROR_NUMBER INT
        , @ERROR_LINE INT
        , @ERROR_MESSAGE VARCHAR(245)
        , @ERROR_PROCEDURE VARCHAR(256);

    SELECT @ERROR_SEVERITY = ERROR_SEVERITY()
        , @ERROR_STATE = ERROR_STATE()
        , @ERROR_NUMBER = ERROR_NUMBER()
        , @ERROR_LINE = ERROR_LINE()
        , @ERROR_MESSAGE = ERROR_MESSAGE();

    DECLARE @tempTable TABLE (
        EventType VARCHAR(100)
        , Parameters NVARCHAR(2000)
        , EventInfo NVARCHAR(4000)
        );

    SET @CMD = 'DBCC INPUTBUFFER( ' + CAST(@@SPID AS VARCHAR) + ') WITH NO_INFOMSGS';

    INSERT @tempTable
    EXEC (@CMD);

    SET @EventType = (
            SELECT EventType
            FROM @tempTable
            );
    SET @Parameters = (
            SELECT Parameters
            FROM @tempTable
            );
    SET @Statement = (
            SELECT EventInfo
            FROM @tempTable
            );

    RAISERROR (
            ' Msg %d, Line %d: %s'
            , @ERROR_SEVERITY
            , @ERROR_STATE
            , @ERROR_NUMBER
            , @ERROR_LINE
            , @ERROR_MESSAGE
            );
END;
GO

dbo.LogError is just a procedure that logs failed queries. Code:

CREATE PROCEDURE dbo.LogError
AS
BEGIN
    SET NOCOUNT ON;
    BEGIN TRY
        -- Return if there is no error information to log.
        IF ERROR_NUMBER() IS NULL
            RETURN;

        -- Return if inside an uncommittable transaction.
        -- Data insertion/modification is not allowed when 
        -- a transaction is in an uncommittable state.
        IF XACT_STATE() = - 1
        BEGIN
            PRINT 'Cannot log error since the current transaction is in an uncommittable state. ' + 'Rollback the transaction before executing [dbo].[LogError] in order to successfully log error information.';

            RETURN;
        END;

        -- get info about last executed statement
        DECLARE @CMD NVARCHAR(200);
        DECLARE @EventType NVARCHAR(100);
        DECLARE @Parameters INT;
        DECLARE @Statement NVARCHAR(4000);
        DECLARE @tempTable TABLE (
            EventType VARCHAR(100)
            , Parameters INT
            , EventInfo NVARCHAR(4000)
            );

        SET @CMD = 'DBCC INPUTBUFFER( ' + CAST(@@SPID AS VARCHAR) + ') WITH NO_INFOMSGS';

        INSERT @tempTable
        EXEC (@CMD);

        SET @EventType = (
                SELECT EventType
                FROM @tempTable
                );
        SET @Parameters = (
                SELECT Parameters
                FROM @tempTable
                );
        SET @Statement = (
                SELECT EventInfo
                FROM @tempTable
                );

        -- update dbo.Errors table with error message details
        INSERT dbo.Errors (UserName, ErrorNumber, ErrorSeverity, ErrorState, ErrorProcedure, ErrorLine, ErrorMessage, EventType, Parameter, Statement)
        VALUES (CONVERT(sysname, CURRENT_USER), ERROR_NUMBER(), ERROR_SEVERITY(), ERROR_STATE(), ERROR_PROCEDURE(), ERROR_LINE(), ERROR_MESSAGE(), @EventType, @Parameters, @Statement);
    END TRY
    BEGIN CATCH
        PRINT 'An error occurred in stored procedure [dbo].[LogError]: ';
        EXECUTE dbo.PrintErrorMessage;
        RETURN -1;
    END CATCH;
END;
GO

This procedure obiviously doesn't capture what exact RPC statements are being executed and that's why we started using XE.

I'd like to know what could be the issue that XE session does not capture failed stored procedures, executed as RPC, and what are the possible ways to fix it.

  • Queries can fail with severity higher than 17. Maybe that's why? – Erik Darling Jan 25 '17 at 12:09
  • No, that was not the case. I actually have found the issue. There was no sql statement caught in all of these cases and there was a filter based on it, I just had to add condition in my XE parser to keep NULL values as well... – Evaldas Buinauskas Jan 25 '17 at 12:10
  • You should add that as an answer to your question. – Erik Darling Jan 25 '17 at 16:41

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Browse other questions tagged or ask your own question.