Sql-server – Slow deletion of records when a trigger is enabled

deleteperformancesql serversql-server-2008-r2trigger

Thought this was solved with the link below – the work around works – but the patch doesn't. Working with Microsoft support to resolve.

http://support.microsoft.com/kb/2606883

Ok so I have an issue that I wanted to throw out to StackOverflow to see if someone has an idea.

Note this is with SQL Server 2008 R2

Issue: Deleting 3000 records from a table with 15000 records takes 3-4 minutes when a trigger is enabled and only 3-5 seconds when the trigger is disabled.

Table setup

Two tables we will call Main and Secondary. Secondary contains records of items I want to delete so when I perform the delete I join on to the Secondary table. A process runs prior to the delete statement to populate the secondary table with records to be deleted.

Delete Statement:

DELETE FROM MAIN 
WHERE ID IN (
   SELECT Secondary.ValueInt1 
   FROM Secondary 
   WHERE SECONDARY.GUID = '9FFD2C8DD3864EA7B78DA22B2ED572D7'
);

This table has a lot of columns and about 14 different NC Indexes. I tried a bunch of different things before I determined the trigger was the issue.

  • Turn on page locking (we have turned off by default)
  • Gathered Stats Manually
  • Disabled auto gathering of statistics
  • Verified Index health and fragmentation
  • Dropped the clustered index from the table
  • Examined the execution plan (nothing showing as missing indexes and the cost was 70 percent towards the actual delete with about 28 percent for the join / merge of the records

Triggers

The table has 3 triggers (one each for insert, update, and delete operations). I modified the code for the delete trigger to just return, then to select one to see how many times it is fired. It only fires one time during the entire operation (as expected). 

ALTER TRIGGER [dbo].[TR_MAIN_RD] ON [dbo].[MAIN]
            AFTER DELETE
            AS  
                SELECT 1
                RETURN

To Recap

  • With Trigger on – statement takes 3-4 minutes to complete
  • With Trigger off – statement takes 3-5 seconds to complete

Anyone have any ideas as to why?

Also note – not looking to change this architecture, add remove indexes, etc. as a solution. This table is the center piece for some major data operations and we had to tweak and tune it (indexes, page locking, etc) to allow for major concurrency operations to work without deadlocks.

Here is the execution plan xml (names were changed to protect the innocent)

<?xml version="1.0" encoding="utf-16"?>
<ShowPlanXML xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:xsd="http://www.w3.org/2001/XMLSchema" Version="1.1" Build="10.50.1790.0" xmlns="http://schemas.microsoft.com/sqlserver/2004/07/showplan">
  <BatchSequence>
    <Batch>
      <Statements>
        <StmtSimple StatementCompId="1" StatementEstRows="185.624" StatementId="1" StatementOptmLevel="FULL" StatementOptmEarlyAbortReason="GoodEnoughPlanFound" StatementSubTreeCost="0.42706" StatementText="DELETE FROM MAIN WHERE ID IN (SELECT Secondary.ValueInt1 FROM Secondary WHERE Secondary.SetTMGUID = '9DDD2C8DD3864EA7B78DA22B2ED572D7')" StatementType="DELETE" QueryHash="0xAEA68D887C4092A1" QueryPlanHash="0x78164F2EEF16B857">
          <StatementSetOptions ANSI_NULLS="true" ANSI_PADDING="true" ANSI_WARNINGS="true" ARITHABORT="false" CONCAT_NULL_YIELDS_NULL="true" NUMERIC_ROUNDABORT="false" QUOTED_IDENTIFIER="true" />
          <QueryPlan CachedPlanSize="48" CompileTime="20" CompileCPU="20" CompileMemory="520">
            <RelOp AvgRowSize="9" EstimateCPU="0.00259874" EstimateIO="0.296614" EstimateRebinds="0" EstimateRewinds="0" EstimateRows="185.624" LogicalOp="Delete" NodeId="0" Parallel="false" PhysicalOp="Clustered Index Delete" EstimatedTotalSubtreeCost="0.42706">
              <OutputList />
              <Update WithUnorderedPrefetch="true" DMLRequestSort="false">
                <Object Database="[MyDatabase]" Schema="[dbo]" Table="[MAIN]" Index="[IX_MAIN_02]" IndexKind="Clustered" />
                <Object Database="[MyDatabase]" Schema="[dbo]" Table="[MAIN]" Index="[PK_MAIN_ID]" IndexKind="NonClustered" />
                <Object Database="[MyDatabase]" Schema="[dbo]" Table="[MAIN]" Index="[UK_MAIN_01]" IndexKind="NonClustered" />
                <Object Database="[MyDatabase]" Schema="[dbo]" Table="[MAIN]" Index="[IX_MAIN_03]" IndexKind="NonClustered" />
                <Object Database="[MyDatabase]" Schema="[dbo]" Table="[MAIN]" Index="[IX_MAIN_04]" IndexKind="NonClustered" />
                <Object Database="[MyDatabase]" Schema="[dbo]" Table="[MAIN]" Index="[IX_MAIN_05]" IndexKind="NonClustered" />
                <Object Database="[MyDatabase]" Schema="[dbo]" Table="[MAIN]" Index="[IX_MAIN_06]" IndexKind="NonClustered" />
                <Object Database="[MyDatabase]" Schema="[dbo]" Table="[MAIN]" Index="[IX_MAIN_07]" IndexKind="NonClustered" />
                <Object Database="[MyDatabase]" Schema="[dbo]" Table="[MAIN]" Index="[IX_MAIN_08]" IndexKind="NonClustered" />
                <Object Database="[MyDatabase]" Schema="[dbo]" Table="[MAIN]" Index="[IX_MAIN_09]" IndexKind="NonClustered" />
                <Object Database="[MyDatabase]" Schema="[dbo]" Table="[MAIN]" Index="[IX_MAIN_10]" IndexKind="NonClustered" />
                <Object Database="[MyDatabase]" Schema="[dbo]" Table="[MAIN]" Index="[IX_MAIN_11]" IndexKind="NonClustered" />
                <Object Database="[MyDatabase]" Schema="[dbo]" Table="[MAIN]" Index="[UK_MAIN_12]" IndexKind="NonClustered" />
                <Object Database="[MyDatabase]" Schema="[dbo]" Table="[MAIN]" Index="[IX_MAIN_13]" IndexKind="NonClustered" />
                <RelOp AvgRowSize="15" EstimateCPU="1.85624E-05" EstimateIO="0" EstimateRebinds="0" EstimateRewinds="0" EstimateRows="185.624" LogicalOp="Top" NodeId="2" Parallel="false" PhysicalOp="Top" EstimatedTotalSubtreeCost="0.127848">
                  <OutputList>
                    <ColumnReference Column="Uniq1002" />
                    <ColumnReference Database="[MyDatabase]" Schema="[dbo]" Table="[MAIN]" Column="RelationshipID" />
                  </OutputList>
                  <Top RowCount="true" IsPercent="false" WithTies="false">
                    <TopExpression>
                      <ScalarOperator ScalarString="(0)">
                        <Const ConstValue="(0)" />
                      </ScalarOperator>
                    </TopExpression>
                    <RelOp AvgRowSize="15" EstimateCPU="0.0458347" EstimateIO="0" EstimateRebinds="0" EstimateRewinds="0" EstimateRows="185.624" LogicalOp="Left Semi Join" NodeId="3" Parallel="false" PhysicalOp="Merge Join" EstimatedTotalSubtreeCost="0.12783">
                      <OutputList>
                        <ColumnReference Column="Uniq1002" />
                        <ColumnReference Database="[MyDatabase]" Schema="[dbo]" Table="[MAIN]" Column="RelationshipID" />
                      </OutputList>
                      <Merge ManyToMany="false">
                        <InnerSideJoinColumns>
                          <ColumnReference Database="[MyDatabase]" Schema="[dbo]" Table="[Secondary]" Column="ValueInt1" />
                        </InnerSideJoinColumns>
                        <OuterSideJoinColumns>
                          <ColumnReference Database="[MyDatabase]" Schema="[dbo]" Table="[MAIN]" Column="ID" />
                        </OuterSideJoinColumns>
                        <Residual>
                          <ScalarOperator ScalarString="[MyDatabase].[dbo].[MAIN].[ID]=[MyDatabase].[dbo].[Secondary].[ValueInt1]">
                            <Compare CompareOp="EQ">
                              <ScalarOperator>
                                <Identifier>
                                  <ColumnReference Database="[MyDatabase]" Schema="[dbo]" Table="[MAIN]" Column="ID" />
                                </Identifier>
                              </ScalarOperator>
                              <ScalarOperator>
                                <Identifier>
                                  <ColumnReference Database="[MyDatabase]" Schema="[dbo]" Table="[Secondary]" Column="ValueInt1" />
                                </Identifier>
                              </ScalarOperator>
                            </Compare>
                          </ScalarOperator>
                        </Residual>
                        <RelOp AvgRowSize="19" EstimateCPU="0.0174567" EstimateIO="0.0305324" EstimateRebinds="0" EstimateRewinds="0" EstimateRows="15727" LogicalOp="Index Scan" NodeId="4" Parallel="false" PhysicalOp="Index Scan" EstimatedTotalSubtreeCost="0.0479891" TableCardinality="15727">
                          <OutputList>
                            <ColumnReference Column="Uniq1002" />
                            <ColumnReference Database="[MyDatabase]" Schema="[dbo]" Table="[MAIN]" Column="ID" />
                            <ColumnReference Database="[MyDatabase]" Schema="[dbo]" Table="[MAIN]" Column="RelationshipID" />
                          </OutputList>
                          <IndexScan Ordered="true" ScanDirection="FORWARD" ForcedIndex="false" ForceSeek="false" NoExpandHint="false">
                            <DefinedValues>
                              <DefinedValue>
                                <ColumnReference Column="Uniq1002" />
                              </DefinedValue>
                              <DefinedValue>
                                <ColumnReference Database="[MyDatabase]" Schema="[dbo]" Table="[MAIN]" Column="ID" />
                              </DefinedValue>
                              <DefinedValue>
                                <ColumnReference Database="[MyDatabase]" Schema="[dbo]" Table="[MAIN]" Column="RelationshipID" />
                              </DefinedValue>
                            </DefinedValues>
                            <Object Database="[MyDatabase]" Schema="[dbo]" Table="[MAIN]" Index="[PK_MAIN_ID]" IndexKind="NonClustered" />
                          </IndexScan>
                        </RelOp>
                        <RelOp AvgRowSize="11" EstimateCPU="0.00392288" EstimateIO="0.03008" EstimateRebinds="0" EstimateRewinds="0" EstimateRows="3423.53" LogicalOp="Index Seek" NodeId="5" Parallel="false" PhysicalOp="Index Seek" EstimatedTotalSubtreeCost="0.0340029" TableCardinality="171775">
                          <OutputList>
                            <ColumnReference Database="[MyDatabase]" Schema="[dbo]" Table="[Secondary]" Column="ValueInt1" />
                          </OutputList>
                          <IndexScan Ordered="true" ScanDirection="FORWARD" ForcedIndex="false" ForceSeek="false" NoExpandHint="false">
                            <DefinedValues>
                              <DefinedValue>
                                <ColumnReference Database="[MyDatabase]" Schema="[dbo]" Table="[Secondary]" Column="ValueInt1" />
                              </DefinedValue>
                            </DefinedValues>
                            <Object Database="[MyDatabase]" Schema="[dbo]" Table="[Secondary]" Index="[IX_Secondary_01]" IndexKind="NonClustered" />
                            <SeekPredicates>
                              <SeekPredicateNew>
                                <SeekKeys>
                                  <Prefix ScanType="EQ">
                                    <RangeColumns>
                                      <ColumnReference Database="[MyDatabase]" Schema="[dbo]" Table="[Secondary]" Column="SetTMGUID" />
                                    </RangeColumns>
                                    <RangeExpressions>
                                      <ScalarOperator ScalarString="'9DDD2C8DD3864EA7B78DA22B2ED572D7'">
                                        <Const ConstValue="'9DDD2C8DD3864EA7B78DA22B2ED572D7'" />
                                      </ScalarOperator>
                                    </RangeExpressions>
                                  </Prefix>
                                </SeekKeys>
                              </SeekPredicateNew>
                            </SeekPredicates>
                          </IndexScan>
                        </RelOp>
                      </Merge>
                    </RelOp>
                  </Top>
                </RelOp>
              </Update>
            </RelOp>
          </QueryPlan>
        </StmtSimple>
      </Statements>
    </Batch>
  </BatchSequence>
</ShowPlanXML>

Best Answer

The row-versioning framework introduced in SQL Server 2005 is used to support a number of features, including the new transaction isolation levels READ_COMMITTED_SNAPSHOT and SNAPSHOT. Even when neither of these isolation levels are enabled, row-versioning is still used for AFTER triggers (to facilitate generation of the inserted and deleted pseudo-tables), MARS, and (in a separate version store) online indexing.

As documented, the engine may add a 14-byte postfix to each row of a table that is versioned for any of these purposes. This behaviour is relatively well-known, as is the addition of the 14-byte data to every row of an index that is rebuilt online with a row-versioning isolation level enabled. Even where the isolation levels are not enabled, one extra byte is added to non-clustered indexes only when rebuilt ONLINE.

Where an AFTER trigger is present, and versioning would otherwise add 14 bytes per row, an optimization exists within the engine to avoid this, but where a ROW_OVERFLOW or LOB allocation cannot occur. In practice, this means the maximum possible size of a row must be less than 8060 bytes. In calculating maximum possible row sizes, the engine assumes for example that a VARCHAR(460) column could contain 460 characters.

The behaviour is easiest to see with an AFTER UPDATE trigger, though the same principle applies to AFTER DELETE. The following script creates a table with a maximum in-row length of 8060 bytes. The data fits on a single page, with 13 bytes of free space on that page. A no-op trigger exists, so the page is split and versioning information added:

USE Sandpit;
GO
CREATE TABLE dbo.Example
(
    ID          integer NOT NULL IDENTITY(1,1),
    Value       integer NOT NULL,
    Padding1    char(42) NULL,
    Padding2    varchar(8000) NULL,

    CONSTRAINT PK_Example_ID
    PRIMARY KEY CLUSTERED (ID)
);
GO
WITH
    N1 AS (SELECT 1 AS n UNION ALL SELECT 1),
    N2 AS (SELECT L.n FROM N1 AS L CROSS JOIN N1 AS R),
    N3 AS (SELECT L.n FROM N2 AS L CROSS JOIN N2 AS R),
    N4 AS (SELECT L.n FROM N3 AS L CROSS JOIN N3 AS R)
INSERT TOP (137) dbo.Example
    (Value)
SELECT
    ROW_NUMBER() OVER (ORDER BY (SELECT 0))
FROM N4;
GO
ALTER INDEX PK_Example_ID 
ON dbo.Example 
REBUILD WITH (FILLFACTOR = 100);
GO
SELECT
    ddips.index_type_desc,
    ddips.alloc_unit_type_desc,
    ddips.index_level,
    ddips.page_count,
    ddips.record_count,
    ddips.max_record_size_in_bytes
FROM sys.dm_db_index_physical_stats(DB_ID(), OBJECT_ID(N'dbo.Example', N'U'), 1, 1, 'DETAILED') AS ddips
WHERE
    ddips.index_level = 0;
GO
CREATE TRIGGER ExampleTrigger
ON dbo.Example
AFTER DELETE, UPDATE
AS RETURN;
GO
UPDATE dbo.Example
SET Value = -Value
WHERE ID = 1;
GO
SELECT
    ddips.index_type_desc,
    ddips.alloc_unit_type_desc,
    ddips.index_level,
    ddips.page_count,
    ddips.record_count,
    ddips.max_record_size_in_bytes
FROM sys.dm_db_index_physical_stats(DB_ID(), OBJECT_ID(N'dbo.Example', N'U'), 1, 1, 'DETAILED') AS ddips
WHERE
    ddips.index_level = 0;
GO
DROP TABLE dbo.Example;

The script produces the output shown below. The single-page table is split into two pages, and the maximum physical row length has increased from 57 to 71 bytes (= +14 bytes for the row-versioning information).

Update example

DBCC PAGE shows that the single updated row has Record Attributes = NULL_BITMAP VERSIONING_INFO Record Size = 71, whereas all other rows in the table have Record Attributes = NULL_BITMAP; record Size = 57.

The same script, with the UPDATE replaced by a single row DELETE produces the output shown:

DELETE dbo.Example
WHERE ID = 1;

Delete example

There is one fewer row in total (of course!), but the maximum physical row size has not increased. Row versioning information is only added to rows needed for the trigger pseudo-tables, and that row was ultimately deleted. The page split remains, however. This page-splitting activity is responsible for the slow performance observed when the trigger was present. If the definition of the Padding2 column is changed from varchar(8000) to varchar(7999), the page no longer splits.

Also see this blog post by SQL Server MVP Dmitri Korotkevitch, which also discusses the impact on fragmentation.

Related Question