다음을 통해 공유

SQL Server: Understanding Minimal Logging Under Bulk-Logged Recovery Model vs. Logging in Truncate Operation

  • 아티클

Introduction

There have been articles online explaining the minimal logging behavior of SQL Server under bulk-logged recovery model, nonetheless, it still seems to be debatable and not well understood. This article attempts at explaining how minimal logging works in bulk-logged recovery model and how it is different when a truncate is fired, basically disproving that truncate is a non-logged/minimally logged operation.

Minimal Logging Under Bulk-Logged Recovery Model

Let us first understand the meaning of "minimal logging". The shortest definition per books online is, "Minimal logging involves logging only the information that is required to recover the transaction without supporting point-in-time recovery". Let's replace the word recover with rollback for simplicity. The hyperlinked article also talks about operations that can be minimally logged. The rest of this article will focus on the following two items derived from the one-line definition above:

  1. Minimal logging involves logging only the limited information required to rollback a transaction.
  2. Minimal logging doesn't support PITR (Point-in-time recovery). In other words, one cannot restore a T-log backup to a certain point-in-time if the backup file contains any bulk-logged transactions. 

First up, what exactly is logged when we say "limited information"? the answer is, only the page allocations are logged in the T-log without any reference to the actual data those pages contain, hence maintaining the less T-log size. This should be clear with the following example. 

One of the minimally logged operations(under Bulk-logged recovery model) is "SELECT...INTO". Let's create a really simple database to test how much information is recorded in the t-log as a result of this operation under 1. Full recovery model and 2. Bulk-logged recovery model but before that taking the first full backup to ensure that the database is not running under pseudo-simple recovery model.

Logging under Full-Recovery Model: 

Script 1

--Database Creation
CREATE DATABASE [TestFULL]
Go
ALTER DATABASE [TestFULL] SET RECOVERY FULL
GO
 
--First FULL backup
BACKUP DATABASE [TestFULL] TO DISK = N'F:\Backups\TestFULL_DeleteMe_FULL.bak'
WITH NOFORMAT, NOINIT, NAME = N'TestFULL-Full Database Backup', SKIP, NOREWIND, NOUNLOAD, STATS = 10
GO

Now that the database is created and the first full backup is done, its time for the minimally logged, SELECT...INTO operation. The example below uses a pre-existing database named sample to insert the records from.

Script 2

USE TestFULL
GO
SELECT Servername, InstanceName 
INTO[TestFULL].[dbo].[InstanceInfo]
FROM[Sample].[dbo].[InstanceInfo]

The above script inserted 11272 rows into the InstanceInfo table within the TestFULL database. Now, let's see how many log records it generated. The code below uses an undocumented function called fn_dblog to read the T-log file. As note of caution, this is an undocumented function and shouldn't be run against production unless you are sure of what you're doing. Below is the partial screenshot of the outcome.

Image 1

It returned 12466 rows, with operations "LOP_FORMAT_PAGE" (each entry corresponding to the entire page image) and "LOP_INSERT_ROWS" with context "LCX_HEAP" accounting for most, which roughly translates to "a record inserted into a HEAP table". This is kind of expected of a database running under full recovery model. The reason being, everything is fully logged.

Note: Fully logged under Full recovery model means different for different operations i.e. if the SELECT..INTO has any identity values then it's logging of every row whereas without identity, it's the logging of full pages. 

Minimal Logging in Bulk-Logged Recovery Model:

Now it's Bulk-logged's turn, let's repeat the same example above but this time, against a separate database running under bulk-logged recovery model. 

Script 3

--Database creation
CREATE DATABASE [TestBulkLogged]
Go
ALTER DATABASE [TestBulkLogged] SET RECOVERY BULK_LOGGED 
GO
 
--First FULL backup
BACKUP DATABASE [TestBulkLogged] TO DISK = N'F:\Backups\TestBulkLogged_DeleteMe_FULL.bak'
WITH NOFORMAT, NOINIT, NAME = N'TestBulkLogged-Full Database Backup', SKIP, NOREWIND, NOUNLOAD, STATS = 10
GO

Same story follows, run a minimally logged operation.

Script 4

Use TestBulkLogged
GO
SELECT Servername, InstanceName 
INTO [TestBulkLogged].[dbo].[InstanceInfo]
FROM [SAMPLE].[dbo].[InstanceInfo]

Use fn_dblog to get the log records generated.

Image 2

This time, it generated only 291 records of which, LOP_INSERT_ROWS accounted for only 15. Hence, less number of records = less amount of space used in the T-log file. 

Full vs Bulk-Logged:

The next obvious question is, "so what did it actually log?", the answer to this is given in the beginning of the article that, only the page allocations are logged in the log file and there is no reference to the actual data contained on those pages. Bulk-logged differs from Full recovery model in a way that it doesn't log (or record) every row inserted as part of a bulk operation, what it does log is the information about the data page allocations. This is handled by an allocation page called Bulk Change Map. This page keeps track of the changed extents (affected by bulk operations) by changing the bit value to 1. This is the only information about the minimal operation, the t-log knows and nothing beyond this. 

Testing For Minimal Logging Under Bulk-Logged Recovery Model:

Going back to the original discussion of minimal logging, let us validate the two requirements that have to be met in order for a transaction to fully qualify as minimally logged.

First Requirement:

1.It should only log information that is required to recover or rollback a transaction: Let's go ahead and see this in action: continuing with the same example above, let's roll back the SELECT...INTO transaction.

Script 5

USE TestBulkLogged
GO
BEGIN  TRANSACTION TranA
 
SELECT Servername, InstanceName 
INTO [TestBulkLogged].[dbo].[InstanceInfo2]
FROM [sample].[dbo].[InstanceInfo]
GO
WAITFOR DELAY '00:00:05'
ROLLBACK

and..it successfully rolled back the transaction. This proves that SQL Server, under bulk-logged recovery model, logs information (page allocations) that is needed to rollback a transaction but...wait, isn't this behavior same under FULL recovery? The answer is yes, but the difference is, under full, it logs everything and then undoes it upon rollback. Another important distinction to note is, under bulk-logged, it can only de-allocate the pages that gets logged as a result of minimal logged operation. As in our example above, it simply de-allocated all the pages upon rollback. There is no way it can roll forward or redo a transaction, in other words, it CANNOT replay the contents from the log records to roll forward the data as it doesn't have any idea about the actual data. It just logged the page allocations and it can re-allocate that from the log records but it cannot, again, cannot roll forward the data page contents. In contrast, under a full recovery model, all the information required to rollback or roll forward a transaction is logged.

Now that it's clear that there's no roll forward in bulk-logged recovery for minimally logged transactions, so how exactly does SQL Server recover from an instance crash or an abrupt shutdown? In case of Full recovery model, since everything is logged, if SQL crashes and tries to come back up, it recovers the database by reading the T-log and rolling back the uncommitted transactions and rolling forward any committed ones. This is possible because of the fully logging nature of Full-recovery model.

In contrast, under bulk-logged, SQL Server T-log doesn't have any idea about the data pages (affected by a minimally logged operation) and hence,  rolling forward is not possible with the limited information in the T-log. Instead, it follows a different architecture altogether when dealing with minimally logged operations and that is, from the Bulk Change Map (discussed briefly above), it knows what all extents got changed as a result of minimally logged operation and a process named "Eager Writer" ensures that all the changed extents(the ones caused by minimal logging) are hardened to disk before the transaction completes. All the changed data pages are flushed to disk by the time transaction completes so they are guaranteed to be on the disk. Hence, roll forward is not needed/never happens for minimally logged transactions during the crash recovery event. MVP Gail Shaw discusses this here.

Microsoft defines Eager Writer as "a process that writes dirty data pages associated with nonlogged operations such as bulk insert and select into. This process allows creating and writing new pages to take place in parallel. That is, the calling operation does not have to wait until the entire operation finishes before writing the pages to disk."

One of the cons of Bulk-logged recovery model is, large T-log backup size. When a T-log backup runs, it normally backs up the log records since the last T-log backup. Under Bulk-Logged recovery model, if the log has any minimally logged transactions, then the log backup doesn't simply backup the log records, instead, it uses the Bulk Change Map to know what all extents were affected by the minimally logged operation and copies their extent images to the backup file. Hence, it includes all the modified extents images in the t-log backup, making the backup size large. This is to ensure that the minimally logged transactions can be restored from the backup. It should also be noted that the extents images, as they exist at the time of t-log backup are copied to the backup file. 

Second Requirement:
  1. Let's test the second requirement of minimal logging i.e. Point-in-time-recovery should NOT be allowed from a log backup that has bulk(minimally) logged transactions. The example below creates a database and tries to recover it to a specific point in time. The final result is given at the end of the code below.

Script 6

--Database creation
CREATE DATABASE [TestBulkLogged]
Go
ALTER DATABASE [TestBulkLogged] SET RECOVERY BULK_LOGGED 
GO
 
--First FULL backup
BACKUP DATABASE [TestBulkLogged] TO DISK = N'F:\Backups\TestBulkLogged_DeleteMe_FULL.bak'
WITH NOFORMAT, NOINIT, NAME = N'TestBulkLogged-Full Database Backup', SKIP, NOREWIND, NOUNLOAD, STATS = 10
GO
 
--Run a Minimally logged transaction
USE TestBulkLogged
GO
SELECT Servername, InstanceName 
INTO TestBulkLogged.dbo.InstanceInfo
FROM Sample.dbo.InstanceInfo
GO
 
-- T-log backup. This contains the above minimally logged operation.
SELECT GETDATE()
GO
BACKUP LOG [TestBulkLogged] TO DISK = N'F:\Backups\TestBulkLogged_DeleteMe_TLog.trn'
WITH NOFORMAT, NOINIT, NAME = N'TestBulkLogged-Transaction Log Backup', SKIP, NOREWIND, NOUNLOAD, STATS = 10
GO
 
--Drop the DB
DROP DATABASE TestBulkLogged
GO
 
--Restore the FULL backup
USE [master]
RESTORE DATABASE [TestBulkLogged] FROM  DISK = N'F:\Backups\TestBulkLogged_DeleteMe_FULL.bak'
WITH  FILE = 1, NORECOVERY, NOUNLOAD, STATS = 5
GO
 
--Restore the T-log to a point-in-time
RESTORE LOG [TestBulkLogged]  FROM DISK = N'F:\Backups\TestBulkLogged_DeleteMe_TLog.trn'
WITH  FILE = 1, NOUNLOAD, STATS = 10, STOPAT = N'2017-06-06T12:00:12'
GO

Because the T-log backup had minimally logged transaction, the attempt to recover to a point-in-time failed with the following error:

Msg 4341, Level 16, State 1, Line 1

This log backup contains bulk-logged changes. It cannot be used to stop at an arbitrary point in time.

This means, either the entire log backup should be restored or nothing. Hence, under bulk-logged, point-in-time recovery is not possible from a log backup that contains any minimally logged operations.

Is TRUNCATE minimally logged?

Continuing with the second half of this article, let's see if TRUNCATE passes the two tests to be qualified as a minimally logged operation.

First Requirement:
  1. The example below is trying to rollback a truncate operation.

Script 7

--Insert some data
USE TestBulkLogged
GO
SELECT Servername, InstanceName 
INTO [TestBulkLogged].[dbo].[InstanceInfo]
FROM [sample].[dbo].[InstanceInfo]
GO
 
--Total row count
SELECT COUNT(*) AS BeforeTruncate FROM [TestBulkLogged].[dbo].[InstanceInfo]
 
--Rollback a truncate
BEGIN  TRANSACTION
TRUNCATE TABLE [TestBulkLogged].[dbo].[InstanceInfo]
WAITFOR DELAY '00:00:05'
ROLLBACK
 
--Total row count post truncate
SELECT  COUNT(*) AS AfterTruncate FROM [TestBulkLogged].[dbo].[InstanceInfo]

Below is the output:

Image 3

The fact that the rollback was able to restore all the records back into the table is self-evident that truncate is not a minimally-logged but a fully-logged operation. Remember, a minimally logged operation can only deallocate the data pages upon rollback but cannot reallocate the pages. Hence, truncate doesn't meet the first requirement of minimal logging. The confusion that truncate is a non-logged operation arises from the article which states "TRUNCATE TABLE is a non-logged operation that does not fire triggers." The truncate follows a mechanism called "Deferred-drop". Paul Randal talks about it here.

Pro-tip: Read MVP Shashank Singh's (aka Shanky) article where he demonstrated truncate's behavior. 

Second Requirement:
  1. Now let's test the second requirement and see if Point-in-time recovery is possible from a log backup that contains the truncate operation.

Script 8

--Database creation
CREATE DATABASE [TestTruncate]
Go
ALTER DATABASE [TestTruncate] SET RECOVERY FULL
GO
 
--First FULL backup
BACKUP DATABASE [TestTruncate] TO DISK = N'F:\Backups\TestTruc_DeleteMe_FULL.bak'
WITH NOFORMAT, NOINIT, NAME = N'TestTruncate-Full Database Backup', SKIP, NOREWIND, NOUNLOAD, STATS = 10
GO
 
--Create a table and insert 10 records and note down the time with SELECT GETDATE()
SELECT GETDATE()
USE TestTruncate
GO
CREATE TABLE Tab1 (ID  int  default '1')
GO
INSERT INTO Tab1  DEFAULT  VALUES
GO 10
 
--Truncate the table and note the time 
SELECT GETDATE()
TRUNCATE  TABLE Tab1
GO
 
--insert 20 records and note the time 
SELECT GETDATE()
INSERT INTO Tab1  default  values
GO 20
 
--Take a log backup which contains the above three cases
BACKUP LOG [TestTruncate] TO DISK = N'F:\Backups\TestTrunc_DeleteMe_LOG.trn'
WITH NOFORMAT, NOINIT, NAME = N'TestTruncate-Transaction Log Backup', SKIP, NOREWIND, NOUNLOAD, STATS = 10
GO

Now is the time to start restoring the full backup followed by the log backup to each of the three points in time. The first one starts below:

Script 9

--Restore the Full followed by the T-log backup with STOPAT the first point-in-time i.e. 2017-06-04T19:10:00
USE [master]
ALTER  DATABASE [TestTruncate] SET SINGLE_USER WITH ROLLBACK IMMEDIATE
RESTORE DATABASE [TestTruncate] FROM DISK = N'F:\Backups\TestTruc_DeleteMe_FULL.bak'
WITH  FILE = 1, NORECOVERY, NOUNLOAD, REPLACE, STATS = 5
GO
RESTORE LOG [TestTruncate] FROM DISK = N'F:\Backups\TestTrunc_DeleteMe_LOG.trn'
WITH  FILE = 1, NOUNLOAD, STATS = 10, STOPAT = N'2017-06-04T19:10:00', recovery
GO SELECT *  FROM  Tab1

Image 4

Output:

Restore the log backup to the second point-in-time:

Script 10

--restore the DB with replace but this time, STOPAT the second point-in-time i.e. 2017-06-04T19:13:50
USE [master]
ALTER  DATABASE [TestTruncate] SET SINGLE_USER WITH ROLLBACK IMMEDIATE
RESTORE DATABASE [TestTruncate] FROM DISK = N'F:\Backups\TestTruc_DeleteMe_FULL.bak'
WITH  FILE = 1, NORECOVERY, NOUNLOAD, REPLACE, STATS = 5
GO
RESTORE LOG [TestTruncate] FROM DISK = N'F:\Backups\TestTrunc_DeleteMe_LOG.trn'
WITH  FILE = 1, NOUNLOAD, STATS = 10, STOPAT = N'2017-06-04T19:13:50', recovery
GO SELECT * FROM  Tab1

Image 5

Output:

Restore to the third point-in-time:

Script 11

--restore the DB with replace again but this time, STOPAT the third point-in-time i.e. 2017-06-04T19:14:20
USE [master]
ALTER  DATABASE [TestTruncate] SET SINGLE_USER WITH ROLLBACK IMMEDIATE
RESTORE DATABASE [TestTruncate] FROM DISK = N'F:\Backups\TestTruc_DeleteMe_FULL.bak'
WITH  FILE = 1, NORECOVERY, NOUNLOAD, REPLACE, STATS = 5
GO
RESTORE LOG [TestTruncate] FROM DISK = N'F:\Backups\TestTrunc_DeleteMe_LOG.trn'
WITH  FILE = 1, NOUNLOAD, STATS = 10, STOPAT = N'2017-06-04T19:14:20', recovery
GO SELECT * FROM  Tab1

Image 6

Output:

Hence,  the Log-backup which spanned the truncate operation was able to be restored point-in-time. This disproves the theory that truncate is a non-logged or minimally logged operation.

Conclusion:

Although Bulk-logged recovery model provides advantages of minimal logging and keeps the t-log from growing as a result of  bulk operations, there are some cons associated with it, as follows:

 (a) The performance may be impacted for minimally logged operations due to the 'Eager Writer' process having to write the data pages to disk at the same time when the log records are being written to disk. This performance bottleneck may not hold true all the times though.

(b) Point-in-time recovery is not possible from a T-log backup that contains any minimally logged transactions. Hence, data loss.

(c) Large T-log backup sizes.

With all the risks involved, a careful determination needs to be made when choosing to run under bulk-logged model. Nevertheless, it is still useful in case of any bulk transactions.

**
Return to Top
**

See Also: