Why am I not getting minimal logging when inserting to indexed tables

Question

I'm testing minimal logging inserts in different scenarios and from what I've read INSERT INTO SELECT into a heap with a non clustered index using TABLOCK and SQL Server 2016+ should minimally log, however in my case when doing this I'm getting full logging. My database is in the simple recovery model and I successfully get minimally logged inserts on a heap with no indexes and TABLOCK.

I'm using an old backup of the Stack Overflow database to test on and have created a replicate of the Posts table with the following schema...

CREATE TABLE [dbo].[PostsDestination](
    [Id] [int] NOT NULL,
    [AcceptedAnswerId] [int] NULL,
    [AnswerCount] [int] NULL,
    [Body] [nvarchar](max) NOT NULL,
    [ClosedDate] [datetime] NULL,
    [CommentCount] [int] NULL,
    [CommunityOwnedDate] [datetime] NULL,
    [CreationDate] [datetime] NOT NULL,
    [FavoriteCount] [int] NULL,
    [LastActivityDate] [datetime] NOT NULL,
    [LastEditDate] [datetime] NULL,
    [LastEditorDisplayName] [nvarchar](40) NULL,
    [LastEditorUserId] [int] NULL,
    [OwnerUserId] [int] NULL,
    [ParentId] [int] NULL,
    [PostTypeId] [int] NOT NULL,
    [Score] [int] NOT NULL,
    [Tags] [nvarchar](150) NULL,
    [Title] [nvarchar](250) NULL,
    [ViewCount] [int] NOT NULL
)
CREATE NONCLUSTERED INDEX ndx_PostsDestination_Id ON PostsDestination(Id)

I then try to copy the posts table into this table...

INSERT INTO PostsDestination WITH(TABLOCK)
SELECT * FROM Posts ORDER BY Id 

From looking at fn_dblog and the log file usage I can see I'm not getting minimal logging from this. I've read that versions before 2016 require trace flag 610 to minimally log to indexed tables, I've also tried setting this but still no joy.

I'm guessing I'm missing something here?

EDIT - More Info

To add more info I'm using the following procedure that I've written to try to detect minimal logging, maybe I've got something here wrong...

/*
    Example Usage...

    EXEC sp_GetLogUseStats
   @Sql = '
      INSERT INTO PostsDestination
      SELECT TOP 500000 * FROM Posts ORDER BY Id ',
   @Schema = 'dbo',
   @Table = 'PostsDestination',
   @ClearData = 1

*/

CREATE PROCEDURE [dbo].[sp_GetLogUseStats]
(   
   @Sql NVARCHAR(400),
   @Schema NVARCHAR(20),
   @Table NVARCHAR(200),
   @ClearData BIT = 0
)
AS

IF @ClearData = 1
   BEGIN
   TRUNCATE TABLE PostsDestination
   END

/*Checkpoint to clear log (Assuming Simple/Bulk Recovery Model*/
CHECKPOINT  

/*Snapshot of logsize before query*/
CREATE TABLE #BeforeLogUsed(
   [Db] NVARCHAR(100),
   LogSize NVARCHAR(30),
   Used NVARCHAR(50),
   Status INT
)
INSERT INTO #BeforeLogUsed
EXEC('DBCC SQLPERF(logspace)')

/*Run Query*/
EXECUTE sp_executesql @SQL

/*Snapshot of logsize after query*/
CREATE TABLE #AfterLLogUsed(    
   [Db] NVARCHAR(100),
   LogSize NVARCHAR(30),
   Used NVARCHAR(50),
   Status INT
)
INSERT INTO #AfterLLogUsed
EXEC('DBCC SQLPERF(logspace)')

/*Return before and after log size*/
SELECT 
   CAST(#AfterLLogUsed.Used AS DECIMAL(12,4)) - CAST(#BeforeLogUsed.Used AS DECIMAL(12,4)) AS LogSpaceUsersByInsert
FROM 
   #BeforeLogUsed 
   LEFT JOIN #AfterLLogUsed ON #AfterLLogUsed.Db = #BeforeLogUsed.Db
WHERE 
   #BeforeLogUsed.Db = DB_NAME()

/*Get list of affected indexes from insert query*/
SELECT 
   @Schema + '.' + so.name + '.' +  si.name AS IndexName
INTO 
   #IndexNames
FROM 
   sys.indexes si 
   JOIN sys.objects so ON si.[object_id] = so.[object_id]
WHERE 
   si.name IS NOT NULL
   AND so.name = @Table
/*Insert Record For Heap*/
INSERT INTO #IndexNames VALUES(@Schema + '.' + @Table)

/*Get log recrod sizes for heap and/or any indexes*/
SELECT 
   AllocUnitName,
   [operation], 
   AVG([log record length]) AvgLogLength,
   SUM([log record length]) TotalLogLength,
   COUNT(*) Count
INTO #LogBreakdown
FROM 
   fn_dblog(null, null) fn
   INNER JOIN #IndexNames ON #IndexNames.IndexName = allocunitname
GROUP BY 
   [Operation], AllocUnitName
ORDER BY AllocUnitName, operation

SELECT * FROM #LogBreakdown
SELECT AllocUnitName, SUM(TotalLogLength)  TotalLogRecordLength 
FROM #LogBreakdown
GROUP BY AllocUnitName

Inserting into a heap with no indexes and TABLOCK using following code...

EXEC sp_GetLogUseStats
   @Sql = '
      INSERT INTO PostsDestination
      SELECT * FROM Posts ORDER BY Id ',
   @Schema = 'dbo',
   @Table = 'PostsDestination',
   @ClearData = 1

I get these results

At 0.0024mb log file growth, very small log record sizes and very few of them I'm happy that this is using minimal logging.

If I then create a non clustered index on id...

CREATE INDEX ndx_PostsDestination_Id ON PostsDestination(Id)

Then run my same insert again...

Not only am I not getting minimal logging on the non clustered index but I've also lost it on the heap. After doing some more tests it seems if I make ID clustered it does minimally log but from what I've read 2016+ should minimally log to a heap with non clustered index when tablock is used.

FINAL EDIT :

I've reported the behaviour to Microsoft on the SQL Server UserVoice and will update if I get a response. I've also written up the full details of the minimal log scenarios that I couldn't get to work at https://gavindraper.com/2018/05/29/SQL-Server-Minimal-Logging-Inserts/

Answer 1

I can reproduce your results on SQL Server 2017 using the Stack Overflow 2010 database, but not (all of) your conclusions.

Minimal logging to the heap is unavailable when using INSERT...SELECT with TABLOCK to a heap with a nonclustered index, which is unexpected. My guess is INSERT...SELECT cannot support bulk loads using RowsetBulk (heap) at the same time as FastLoadContext (b-tree). Only Microsoft would be able to confirm if this is a bug or by design.

The nonclustered index on the heap is minimally logged (assuming TF610 is on, or SQL Server 2016+ is used, enabling FastLoadContext) with the following caveats:

• Only rows inserted to newly allocated pages are minimally logged.
• Rows added to the first index page are not minimally logged, if the index was empty at the start of the operation.

The 497 LOP_INSERT_ROWS entries shown for the nonclustered index correspond to the first page of the index. Since the index was empty beforehand, these rows are fully logged. The remaining rows are all minimally logged. If documented trace flag 692 is enabled (2016+) to disable FastLoadContext, all nonclustered index rows are minimally logged.

---

I found that minimal logging is applied to both the heap and nonclustered index when bulk loading the same table (with index) using BULK INSERT from a file:

BULK INSERT dbo.PostsDestination
FROM 'D:\SQL Server\Posts.bcp'
WITH (TABLOCK, DATAFILETYPE = 'native');

I note this for completeness. Bulk loading using INSERT...SELECT uses different code paths, so the fact the behaviours differ is not entirely unexpected.

---

For full details about minimal logging using RowsetBulk and FastLoadContext with INSERT...SELECT see my three part series on SQLPerformance.com:

1. Minimal Logging with INSERT…SELECT into Heap Tables
2. Minimal Logging with INSERT…SELECT into Empty Clustered Tables
3. Minimal Logging with INSERT…SELECT and Fast Load Context

---

Other scenarios from your blog post

Comments are closed so I will address these briefly here.

Empty Clustered Index With Trace 610 Or 2016+

This is minimally logged using FastLoadContext without TABLOCK. The only rows fully logged are those inserted to the first page because the clustered index was empty at the start of the transaction.

Clustered Index With Data and Trace 610 OR 2016+

This is also minimally logged using FastLoadContext. Rows added to the existing page are fully logged, the remainder are minimally logged.

Clustered Index With NonClustered Indexes and TABLOCK Or Trace 610/SQL 2016+

This can also be minimally logged using FastLoadContext as long as the nonclustered index is maintained by a separate operator, DMLRequestSort is set to true, and the other conditions laid out in my posts are met.

Answer 2

The below document is old but still an excellent read.

In SQL 2016 trace flag 610 and ALLOW_PAGE_LOCKS are on by default, but someone may have disabled them.

Data Load Performance Guide

(3) Depending on the plan chosen by the optimizer, the nonclustered index on the table may either be fully- or minimally logged.

The SELECT Statement may be the problem because you've got a TOP and ORDER BY. You're inserting data into the Table in a different order to the Index, so SQL might be doing a lot of Sorting in the background.

UPDATE 2

You might actually be getting Minimal logging. With TraceFlag 610 ON, the Log behaves differently, SQL will Reserve enough space in the Log to perform a Roll-back if things go wrong, but will not actually use the Log.

This is probably counting the Reserved (unused) space

EXEC('DBCC SQLPERF(logspace)')

This code splits out Reserved from Used

SELECT
    database_transaction_log_bytes_used
    ,database_transaction_log_bytes_reserved
    ,*
FROM sys.dm_tran_database_transactions 
WHERE database_id = DB_ID()

I suppose Minimal logging (as far as Microsoft is concerned) is actually about performing the least amount of IO on the log, and not how much of the log is reserved.

Take a look at this link.

UPDATE 1

Try using TABLOCKX instead of TABLOCK. With Tablock you still have a shared lock, so SQL might be logging in case another process kicks off.

TABLOCK may need to be used in conjunction with HOLDLOCK. This enforces the Tablock until the end of your transaction.

Also put a lock on the source table [Posts], logging may be taking place because the source table could change whilst your transaction is taking place. Paul White achieved minimal logging when the source was not a SQL table.