Implications of the SQL Server Bulk Logged recovery model on point in time restores
Choosing the database recovery model is one of the more important choices DBAs have. If the business does not need to recover a database to a point in time (PIT) then the SIMPLE recovery model is the choice for you. However, if PIT recovery is necessary, you must use the FULL recovery model. The other recovery model, BULK LOGGED exists so that you have the ability to make certain operations faster while still being able to potentially recover to a PIT. However, going the way of BULKED LOGGED is not without its potential dangers. In this blog post I want to take a look at why you shouldn’t use the BULK LOGGED operation as a full-time database recovery model and expect to be able to recover to a point in time should a failure occur.
First, I’ll create a database to use for the demos.
USE [master]
GO
IF DB_ID('MinimalLoggingRecovery') IS NOT NULL
BEGIN
ALTER DATABASE MinimalLoggingRecovery
SET SINGLE_USER WITH ROLLBACK IMMEDIATE
DROP DATABASE MinimalLoggingRecovery
END
GO
CREATE DATABASE MinimalLoggingRecovery ON PRIMARY
( NAME = N'MinimalLoggingRecovery_Data', FILENAME = N'C:\SQL\MinimalLoggingRecovery_Data.mdf' ,
SIZE = 1024MB , MAXSIZE = UNLIMITED, FILEGROWTH = 50MB )
LOG ON
( NAME = N'MinimalLoggingRecovery_Log', FILENAME = N'C:\SQL\MinimalLoggingRecovery_log.LDF' ,
SIZE = 100MB , MAXSIZE = 1024MB, FILEGROWTH = 25MB)
GO
Next, make sure the database is set to the BULK LOGGED recovery model.
ALTER DATABASE MinimalLoggingRecovery
SET RECOVERY BULK_LOGGED
GO
USE MinimalLoggingRecovery
GO
Now I am going to create two tables to use in the example. The first table, ImportantClusteredTable, will mimic an OLTP table used by a mission critical application. Imagine that records are inserted into this table on a regular basis and the table supports the day to day needs of the business. The other table, NonImportantHeapTable, will be a user table that a staff DBA creates to load some data into for maintenance operations. This table supports no business function.
CREATE TABLE ImportantClusteredTable
(
Fld1 INT NOT NULL, Fld2 INT NOT NULL, Fld3 INT NOT NULL , Fld4 INT IDENTITY(1,1) PRIMARY KEY CLUSTERED
)
GO
CREATE TABLE NonImportantHeapTable
(
Fld1 INT NOT NULL, Fld2 INT NOT NULL, Fld3 INT NOT NULL
)
GO
Create a full database backup so that the database does not behave as though it is in the SIMPLE recovery model.
BACKUP DATABASE MinimalLoggingRecovery
TO DISK = 'C:\SQL\MinimalLoggingRecoveryFull.bak' WITH INIT
GO
My first operation will be to insert 5000 records into the ImportantClusteredTable table. This will be a fully logged operation (assuming you do not have Trace Flag 610 enabled).
DECLARE @Value INT
SET @Value = 1
INSERT INTO ImportantClusteredTable(Fld1, Fld2, Fld3)
SELECT TOP 5000 @Value, SalesOrderDetailID + 100, SalesOrderDetailID + 99
FROM AdventureWorks2012.Sales.SalesOrderDetail
GO
To prove that the operation was fully logged, use the sys.fn_dblog function to return the log records generated associated with that specific table name.
SELECT LogRecordCount1 = COUNT(*)
FROM sys.fn_dblog(null, null)
WHERE AllocUnitName LIKE '%ImportantClusteredTable%'
GO
The query above returned 5172 log records on my system.
Next, perform a checkpoint followed by a log backup. This will ensure that the log records are flushed to disk and that the fn_dblog function no longer returns information associated w/ the log records flushed to disk.
CHECKPOINT
GO
BACKUP LOG MinimalLoggingRecovery
TO DISK = 'C:\SQL\MinimalLoggingRecoveryLog1.bak' WITH INIT
GO
Perform the same INSERT operation again and view the number of log records generated. This number will likely be slightly different from the number above.
DECLARE @Value INT
SET @Value = 2
INSERT INTO ImportantClusteredTable(Fld1, Fld2, Fld3)
SELECT TOP 5000 @Value, SalesOrderDetailID + 100, SalesOrderDetailID + 99
FROM AdventureWorks2012.Sales.SalesOrderDetail
GO
SELECT LogRecordCount2 = COUNT(*)
FROM sys.fn_dblog(null, null)
WHERE AllocUnitName LIKE '%ImportantClusteredTable%'
GO
In my case I see 5153 log records.
Perform another checkpoint and log backup.
CHECKPOINT
GO
BACKUP LOG MinimalLoggingRecovery
TO DISK = 'C:\SQL\MinimalLoggingRecoveryLog2.bak' WITH INIT
GO
Now, update all of the records from the original INSERT statement so that Fld1 is 9999. View the log records generated from this UPDATE statement. Again, this is a fully logged operation. (See link below for operations that are minimally logged)
UPDATE ImportantClusteredTable
SET Fld3 = 9999
WHERE Fld1 = 1
GO
SELECT LogRecordCountAfterUpdate = COUNT(*)
FROM sys.fn_dblog(null, null)
WHERE AllocUnitName LIKE '%ImportantClusteredTable%'
GO
In this case I had 5000 log records – which is the same number as the number of records I updated.
Get the current timestamp on the system and wait 5 seconds. After waiting 5 seconds, perform a BULK LOGGED operation. In this case the NonImportantHeapTable is INSERTed into using the TABLOCK hint. This will cause the INSERT operation to be minimally logged. This is to mimic a scenario where a user or application performs a minimally logged operation while in the BULK LOGGED recovery mode.
SELECT GETDATE()
WAITFOR DELAY '0:0:5'
DECLARE @Value INT
SET @Value = 3
INSERT INTO NonImportantHeapTable WITH(TABLOCK)(Fld1, Fld2, Fld3)
select TOP 5000 @Value, SalesOrderDetailID + 100, SalesOrderDetailID + 99
FROM AdventureWorks2012.Sales.SalesOrderDetail
GO
SELECT LogRecordCountAfterBL = COUNT(*)
FROM sys.fn_dblog(null, null)
WHERE AllocUnitName LIKE '%NonImportantHeapTable%'
Looking at the log records generated for the NonImportantHeapTable, I see 64 log records. Since this was a minimally logged operation, only allocation page changes were captured in the transaction log.
Capture a point in time after the BULK LOGGED operation occurs.
SELECT GETDATE() --make sure we know what time to restore to
GO
Here are the values I captured from the SELECT GETDATE() statements above.
2013-04-12 14:07:18.913 --before
2013-04-12 14:07:24.190 --after
Now, assume an unfortunate event occurs and puts the state of the business in jeopardy – maybe a user accidentally deletes all sales made in the past 45 minutes (assume it’s a LOT of sales). For the given scenario, you determine that best course of action is to restore the database to a point in time BEFORE the error occurs. No sweat – you’ve been taking log backups every hour, right?
So, the first thing you’ll want to do is take a tail log backup to ensure that you preserve all log records currently in the transaction log but not yet reflected in a log backup. You decide to use WITH NORECOVERY to ensure no new modifications can occur that modify the state of the database.
use master
go
BACKUP LOG MinimalLoggingRecovery
TO DISK = 'C:\SQL\MinimalLoggingRecoveryLog3.bak' WITH INIT, NORECOVERY
GO
Next, restore the full backup and use NORECOVERY.
RESTORE DATABASE MinimalLoggingRecovery
FROM DISK = 'c:\SQL\MinimalLoggingRecoveryFull.bak'
WITH NORECOVERY
GO
Next, restore the 2 log backups you made using NORECOVERY.
RESTORE LOG MinimalLoggingRecovery
FROM DISK = 'c:\SQL\MinimalLoggingRecoveryLog1.bak'
WITH NORECOVERY
GO
RESTORE LOG MinimalLoggingRecovery
FROM DISK = 'c:\SQL\MinimalLoggingRecoveryLog2.bak'
WITH NORECOVERY
This is the delicate part. You know the deletion occurred at around 2013-04-12 14:07:18.913 (I used the first GETDATE() statement returned from the output above). This point in time is BEFORE any BULK LOGGED operation occurred, but after our last log backup (not including the tail log) occurred.
RESTORE LOG MinimalLoggingRecovery
FROM DISK = 'c:\SQL\MinimalLoggingRecoveryLog3.bak'
WITH NORECOVERY, STOPAT = '2013-04-12 14:07:18.913'
However, you receive the following error on the RESTORE statement. Why?
Well, the BULK LOGGED recovery model can be a fickle beast. You see, when the insert into the heap table above occurred, it only logged allocation page changes as it was minimally logged. When the tail log backup was taken, it contained that minimally logged operation. Since it is possible that the tail log backup contained operations that cannot be reconstituted (again – only the allocation pages were changed there – there is no record of the data page changes) it is not possible to recover to a point in time for that transaction log backup interval. I can restore the entire tail log backup, but that would put us back to where we started – the data would still be missing. So, essentially the data changes made after the last log backup that didn’t contain bulk logged operations, are gone.
As a precaution to save yourself some time (and potentially frustration), use the RESTORE HEADERONLY command to determine if a particular backup contains minimally logged operations:
RESTORE HEADERONLY
FROM DISK = 'c:\SQL\MinimalLoggingRecoveryLog3.bak'
The moral of the story here is to ensure that you do not run your databases in the BULK LOGGED recovery mode perpetually. If you need to be able to recover to a point in time, you must stay in the FULL recovery model. It is perfectly OK to switch from FULL to BULK LOGGED to perform minimally logged operations (such as index rebuild operations), just make sure that once you do, you switch back to the FULL recovery model and take a log backup. Otherwise, if you may run into unfortunate situations like the one I described here.
Thanks,
Tim Chapman – SQL Dedicated Premier Field Engineer
Comments
- Anonymous
October 22, 2016
Hi Tim, Thank you for Great post !"As a precaution to save yourself some time (and potentially frustration), use the RESTORE HEADERONLY command to determine if a particular backup contains minimally logged operations...." highlights very important point.After taking full backup of my test database, I changed the recovery model from FULL to Bulk-logged and created a index then changed recovery model to FULL and took transaction log backup. When I did RESTORE HEADERONLY for given transaction log backup file, it shows HasBulkLoggedData to 1 which means backup file contains minimally logged operation so in such cases changing the recovery model to FULL doesn't mean PIT recovery is possible with said log backup. I thought otherwise so tested the same. Thank you.Anil