gotchasqlMajor
Why does DELETE leave a lingering effect on performance?
Viewed 0 times
effectwhydeleteleavelingeringdoesperformance
Problem
At the end is a test script for comparing the performance between a @table variable and a #temp table. I think I've set it up correctly - the performance timings are taken outside of the DELETE/TRUNCATE commands. The results that I am getting are as follows (times in milliseconds).
Just to make sure I'm sane, this shows that CURRENT_TIMESTAMP (aka
It's quite consistent in the jump between the first run and the subsequent runs when DELETE is used to clear the table. What am I missing in my understanding of DELETE? I have repeated this many times, swapped the order, sized tempdb to not require growth etc.
```
CREATE TABLE #values (
id int identity primary key, -- will be clustered
name varchar(100) null,
number int null,
type char(3) not null,
low int null,
high int null,
status smallint not null
);
GO
SET NOCOUNT ON;
DECLARE @values TABLE (
id int identity primary key clustered,
name varchar(100) null,
number int null,
type char(3) not null,
low int null,
high int null,
status smallint not null
);
DECLARE @ExecutionTime TABLE( Duration bigINT )
DECLARE @StartTime DATETIME, @i INT = 1;
WHILE (@i <= 5)
BEGIN
DELETE @values;
DBCC freeproccache With NO_InfoMSGS;
DBCC DROPCLEANBUFFERS With NO_InfoMSGS;
SET @StartTime = CURRENT_TIMESTAMP -- alternate
@Table Variable #Temp (delete) #Temp (truncate)
--------------- -------------- ----------------
5723 5180 5506
15636 14746 7800
14506 14300 5583
14030 15460 5386
16706 16186 5360Just to make sure I'm sane, this shows that CURRENT_TIMESTAMP (aka
GetDate()) is taken at the time of the statement, not of the batch, so there should be no interaction between TRUNCATE/DELETE with the SET @StartTime = CURRENT_TIMESTAMP statement.select current_timestamp
waitfor delay '00:00:04'
select current_timestamp
-----------------------
2012-10-21 11:29:20.290
-----------------------
2012-10-21 11:29:24.290It's quite consistent in the jump between the first run and the subsequent runs when DELETE is used to clear the table. What am I missing in my understanding of DELETE? I have repeated this many times, swapped the order, sized tempdb to not require growth etc.
```
CREATE TABLE #values (
id int identity primary key, -- will be clustered
name varchar(100) null,
number int null,
type char(3) not null,
low int null,
high int null,
status smallint not null
);
GO
SET NOCOUNT ON;
DECLARE @values TABLE (
id int identity primary key clustered,
name varchar(100) null,
number int null,
type char(3) not null,
low int null,
high int null,
status smallint not null
);
DECLARE @ExecutionTime TABLE( Duration bigINT )
DECLARE @StartTime DATETIME, @i INT = 1;
WHILE (@i <= 5)
BEGIN
DELETE @values;
DBCC freeproccache With NO_InfoMSGS;
DBCC DROPCLEANBUFFERS With NO_InfoMSGS;
SET @StartTime = CURRENT_TIMESTAMP -- alternate
Solution
This difference only seems to apply when the object is a B+tree. When removing the
But with the PK I found a similar pattern in my tests as well with typical results below.
My theory is that there there is some optimisation available when doing bulk inserts to local temporary B+ trees that only applies when it does not already have any pages allocated.
I base this on the following observations.
-
When running various versions of your test code I only saw this pattern with
-
In order to get the slower performance it is not necessary to have previously added and removed a large amount of rows from the table. Simply adding a single row and leaving it in there is sufficient.
-
-
Using the VS 2012 profiler shows that in the faster case SQL Server uses a different code path. 36% of the time is spent in
Running
after the delete returns
I found that it was possible to reduce the time discrepancy somewhat by enabling trace flag 610.
This had the effect of reducing the quantity of logging substantially for the subsequent inserts (down from 350 MB to 103 MB as it no longer logs the individual inserted row values) but this had only a minor improvement in timings for the 2nd and subsequent
From looking in the transaction log I noticed that the initial inserts against empty local temporary tables seem even more minimally logged (at 96 MB).
Notably these faster inserts had only
The log used in all three cases was as follows (I have deleted the log records for updates to system base tables to reduce the amount of text but they are still included in the totals)
Logging first insert against
```
+-----------------------+----------+----------------------------------------------+---------------+---------+
| Operation | Context | AllocUnitName | Size in Bytes | Cnt |
+-----------------------+----------+----------------------------------------------+---------------+---------+
| LOP_BEGIN_XACT | LCX_NULL | NULL | 83876 | 658 |
| LOP_COMMIT_XACT | LCX_NULL | NULL | 34164 | 657 |
| LOP_CREATE_ALLOCCHAIN | LCX_NULL | NULL | 120 | 3 |
| LOP_FORMAT_PAGE | LCX_HEAP | dbo.#531856C7 | 84 | 1 |
| LOP_FORMAT_PAGE | LCX_IAM | dbo.#4F47C5E3.PK__#4F47C5E__3213E83F51300E55 | 84 | 1 |
| LOP_FORMAT_PAGE | LCX_IAM | dbo.#531856C7
primary key on the table variable so it is a heap I got the following results2560
2120
2080
2130
2140But with the PK I found a similar pattern in my tests as well with typical results below.
+--------+--------+---------+-------------------+
| @table | #table | ##table | [permanent_table] |
+--------+--------+---------+-------------------+
| 2670 | 2683 | 9603 | 9703 |
| 6823 | 6840 | 9723 | 9790 |
| 6813 | 6816 | 9626 | 9703 |
| 6883 | 6816 | 9600 | 9716 |
| 6840 | 6856 | 9610 | 9673 |
+--------+--------+---------+-------------------+My theory is that there there is some optimisation available when doing bulk inserts to local temporary B+ trees that only applies when it does not already have any pages allocated.
I base this on the following observations.
-
When running various versions of your test code I only saw this pattern with
@table_variables and #temp tables. Not permanent tables in tempdb nor ## tables.-
In order to get the slower performance it is not necessary to have previously added and removed a large amount of rows from the table. Simply adding a single row and leaving it in there is sufficient.
-
TRUNCATE deallocates all pages from the table. DELETE will not cause the last page in the table to be deallocated. -
Using the VS 2012 profiler shows that in the faster case SQL Server uses a different code path. 36% of the time is spent in
sqlmin.dll!RowsetBulk::InsertRow vs 61% of the time spent in sqlmin.dll!RowsetNewSS::InsertRow for the slower case.Running
SELECT *
FROM sys.dm_db_index_physical_stats(2,OBJECT_ID('tempdb..#values'),1,NULL, 'DETAILED')after the delete returns
+-------------+------------+--------------+--------------------+
| index_level | page_count | record_count | ghost_record_count |
+-------------+------------+--------------+--------------------+
| 0 | 1 | 0 | 1 |
| 1 | 1 | 1 | 0 |
| 2 | 1 | 1 | 0 |
+-------------+------------+--------------+--------------------+I found that it was possible to reduce the time discrepancy somewhat by enabling trace flag 610.
This had the effect of reducing the quantity of logging substantially for the subsequent inserts (down from 350 MB to 103 MB as it no longer logs the individual inserted row values) but this had only a minor improvement in timings for the 2nd and subsequent
@table , #table cases and the gap still remains. The trace flag improved the general performance of inserts to the other two table types significantly.+--------+--------+---------+-------------------+
| @table | #table | ##table | [permanent_table] |
+--------+--------+---------+-------------------+
| 2663 | 2670 | 5403 | 5426 |
| 5390 | 5396 | 5410 | 5403 |
| 5373 | 5390 | 5410 | 5403 |
| 5393 | 5410 | 5406 | 5433 |
| 5386 | 5396 | 5390 | 5420 |
+--------+--------+---------+-------------------+From looking in the transaction log I noticed that the initial inserts against empty local temporary tables seem even more minimally logged (at 96 MB).
Notably these faster inserts had only
657 transactions (LOP_BEGIN_XACT /LOP_COMMIT_XACT pairs) compared with over 10,000 in the slower cases. In particular LOP_FORMAT_PAGE operations seem much reduced. The slower cases have a transaction log entry for this for each page in the table (about 10,270) compared with only 4 such entries in the fast case.The log used in all three cases was as follows (I have deleted the log records for updates to system base tables to reduce the amount of text but they are still included in the totals)
Logging first insert against
@table_var (96.5 MB)```
+-----------------------+----------+----------------------------------------------+---------------+---------+
| Operation | Context | AllocUnitName | Size in Bytes | Cnt |
+-----------------------+----------+----------------------------------------------+---------------+---------+
| LOP_BEGIN_XACT | LCX_NULL | NULL | 83876 | 658 |
| LOP_COMMIT_XACT | LCX_NULL | NULL | 34164 | 657 |
| LOP_CREATE_ALLOCCHAIN | LCX_NULL | NULL | 120 | 3 |
| LOP_FORMAT_PAGE | LCX_HEAP | dbo.#531856C7 | 84 | 1 |
| LOP_FORMAT_PAGE | LCX_IAM | dbo.#4F47C5E3.PK__#4F47C5E__3213E83F51300E55 | 84 | 1 |
| LOP_FORMAT_PAGE | LCX_IAM | dbo.#531856C7
Code Snippets
2560
2120
2080
2130
2140+--------+--------+---------+-------------------+
| @table | #table | ##table | [permanent_table] |
+--------+--------+---------+-------------------+
| 2670 | 2683 | 9603 | 9703 |
| 6823 | 6840 | 9723 | 9790 |
| 6813 | 6816 | 9626 | 9703 |
| 6883 | 6816 | 9600 | 9716 |
| 6840 | 6856 | 9610 | 9673 |
+--------+--------+---------+-------------------+SELECT *
FROM sys.dm_db_index_physical_stats(2,OBJECT_ID('tempdb..#values'),1,NULL, 'DETAILED')+-------------+------------+--------------+--------------------+
| index_level | page_count | record_count | ghost_record_count |
+-------------+------------+--------------+--------------------+
| 0 | 1 | 0 | 1 |
| 1 | 1 | 1 | 0 |
| 2 | 1 | 1 | 0 |
+-------------+------------+--------------+--------------------++--------+--------+---------+-------------------+
| @table | #table | ##table | [permanent_table] |
+--------+--------+---------+-------------------+
| 2663 | 2670 | 5403 | 5426 |
| 5390 | 5396 | 5410 | 5403 |
| 5373 | 5390 | 5410 | 5403 |
| 5393 | 5410 | 5406 | 5433 |
| 5386 | 5396 | 5390 | 5420 |
+--------+--------+---------+-------------------+Context
StackExchange Database Administrators Q#27309, answer score: 20
Revisions (0)
No revisions yet.