2

Good morning all - I have a monitoring software that is showing one of my audit triggers is firing 1+ million times an hour, when I look at the audit tables there are about 3000 records entered - The triggers have an update, insert, and delete paths to write to the audit table, so anytime its called, it should be an entry in the audit table. Is there a way with extended events to see what fired the trigger off? I'm not sure how to trace it back to the calling table/event/etc.
Thanks

3 Answers 3

3

You can create an Extended Events session tracking event module_start with a filter on your trigger name while also capturing action tsql_stack.

Demo

Let's create supporting objects

CREATE TABLE dbo.YourTable (
    Id int PRIMARY KEY
    , Filler varchar(50)
);

GO

CREATE TABLE dbo.AnotherTable (
    Id int PRIMARY KEY
    , Filler varchar(50)
);

CREATE TABLE dbo.YourTableAudit (
    Id int
    , UpdatedDate datetime2(0)
);
go
CREATE TRIGGER YourTable_UpdateAudit
ON YourTable
FOR UPDATE
AS
BEGIN
    INSERT INTO dbo.YourTableAudit (Id, UpdatedDate)
    SELECT i.Id, GETUTCDATE()
    FROM inserted i;
END;
GO
CREATE PROCEDURE dbo.NestedProcedure
AS
BEGIN
    PRINT 'Nested Procedure'

    UPDATE dbo.YourTable
    SET Filler = 'UpdatedValue'
    WHERE ID = 1;
END;
GO
CREATE PROCEDURE MainProcedure
AS
BEGIN
    EXEC dbo.NestedProcedure;
END;
GO
CREATE TRIGGER AnotherTable_ConvolutedTrigger
ON AnotherTable
AFTER INSERT
AS
BEGIN
    EXEC dbo.MainProcedure;
END;

INSERT INTO dbo.YourTable (Id, Filler)
VALUES (1, 'A')

In my scenario, the Audit Trigger is called YourTable_UpdateAudit and there are multiple paths how it can be activated

  • Direct update on YourTable
  • Direct execution of the NestedProcedure
  • Direct execution of the MainProcedure
  • Insert to AnotherTable via the AnotherTable_ConvolutedTrigger

Let's prepare the XE session and start it up

CREATE EVENT SESSION TriggerCallstack
ON SERVER
ADD EVENT sqlserver.module_start
(
    SET
        collect_statement = (1)
    ACTION
    (
        sqlserver.client_app_name
        , sqlserver.client_hostname
        , sqlserver.database_name
        , sqlserver.server_principal_name
        , sqlserver.session_id
        , sqlserver.tsql_stack
        , sqlserver.username
    )
    WHERE ([object_name] = N'YourTable_UpdateAudit')
)
ADD TARGET package0.event_file
(
    SET filename = N'TriggerCallstack'
    , max_file_size = (5)
)
, ADD TARGET package0.histogram
(
    SET filtering_event_name = N'sqlserver.module_start'
    , slots = (128)
    , source = N'sqlserver.tsql_stack'
)
GO
ALTER EVENT SESSION TriggerCallstack ON SERVER STATE = START

This event mainly collects tsql_stack and other information useful for tracing the issue like host_name and client_app_name.

It also has two types of targets - event file and histogram.

  • An event file is useful for getting individual calls and details.
  • Histogram is when you want all the distinct tsql_stacks (call paths) and their frequency.

I can simulate three different stacks with these calls

EXEC dbo.MainProcedure

INSERT INTO dbo.AnotherTable (Id, Filler)
VALUES (1, 'A')

EXEC dbo.NestedProcedure

You can then open the event file or histogram and copy the tsql_stack value (everything between the <frames> tags) into this snippet.

DECLARE @stackOrFrame xml = '' /* <--- insert <frames>..</frames> here */

;WITH
xmlShred AS
(
    SELECT
        COALESCE
        (
            CONVERT(varbinary(64), f.n.value('.[1]/@handle', 'varchar(max)'), 1),
            CONVERT(varbinary(64), f.n.value('.[1]/@sqlhandle', 'varchar(max)'), 1)
        ) AS handle,
        COALESCE
        (
            f.n.value('.[1]/@offsetStart', 'int'),
            f.n.value('.[1]/@stmtstart', 'int')
        ) AS offsetStart,
        COALESCE
        (
            f.n.value('.[1]/@offsetEnd', 'int'),
            f.n.value('.[1]/@stmtend', 'int')
        ) AS offsetEnd,
        f.n.value('.[1]/@line', 'int') AS line,
        f.n.value('.[1]/@level', 'tinyint') AS stackLevel
    FROM @stackOrFrame.nodes('//frame') AS f(n)
)
SELECT
    xs.stackLevel
    , db_name(dest.dbid) as dbName
    , object_schema_name(dest.objectid, dest.dbid) as objSch
    , object_name(dest.objectid, dest.dbid) as objName
    , ca.outerText
    , ca2.statementText
FROM
    xmlShred AS xs
    CROSS APPLY sys.dm_exec_sql_text(xs.handle) AS dest
    CROSS APPLY (SELECT dest.text FOR XML PATH(''), TYPE) AS ca(outerText)
    CROSS APPLY
    (
        select trim
        (
            SUBSTRING
            (   dest.text
                , (xs.offsetStart / 2) +1
                , (
                    (
                        CASE
                            WHEN xs.offsetEnd = -1 or xs.offsetEnd is null
                                then len(convert (nvarchar(max), dest.text)) * 2
                            ELSE xs.offsetEnd
                        END 
                        - xs.offsetStart / 2
                   ) / 2) +1
            )
        )
        FOR XML PATH(''), TYPE
    ) AS ca2(statementText)
ORDER BY xs.stackLevel
OPTION (RECOMPILE);

Example of an output

enter image description here

The 1st level is the watched Trigger.

This snippet is reading data from the plan cache, so if you have a cache churn or are too slow, you might not be able to resolve all the handles.

Dynamic SQL also usually doesn't show up.

1

The triggers have an update, insert, and delete paths to write to the audit table, so anytime it's called, it should be an entry in the audit table.

Not necessarily. Triggers always fire, even if the triggering action affected no rows. This is why triggers usually have a statement like this at the very start:

IF ROWCOUNT_BIG() = 0 RETURN; -- Return immediately

In such cases, the trigger will fire, but nothing else will happen.

There is another caveat, in that MERGE statements fire triggers for each action defined in the MERGE statement. So, a MERGE with INSERT, UPDATE, and DELETE actions can fire three groups of triggers. Each trigger will see a ROWCOUNT for the total number of rows affected by all actions combined.

In that case, the test on ROWCOUNT_BIG() or @@ROWCOUNT will not exit the trigger right at the start. The inserted and deleted virtual tables will always contain the right number of rows (including zero) so the rest of your trigger might still end up not writing any audit rows.

0

A trigger is fired by the change in the table. Just look at the trigger's header: ON table AFTER INSERT and you get your answer.

What makes a change to the table is completely different thing - that is indeed requires some auditing. Luckily, SQL Server has some capability for this: https://learn.microsoft.com/en-us/sql/relational-databases/security/auditing/create-a-server-audit-and-server-audit-specification?view=sql-server-ver16

And if your "triggers" are not really triggers buy some kind of application driven stored procedures or even simple statements... If your application does not keep logic logs - then you are out of luck completely.

1
  • Thanks, White Owl - I understand the execution of the trigger, but the trigger supposedly "fires" and there is no underlying change on the calling table, or the actual audit, so it "Fires" but no data is moving? Jun 6, 2023 at 15:50

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.