Bulk Logged Recovery Model and Point In Time Recovery

A couple weeks ago I spoke with a customer who was having problems with their index rebuilds after a SQL Server upgrade. The database is about 160 GB and they upgraded from SQL Server 2000 to SQL Server 2005. Since the upgrade, the index rebuilds have been failing because the transaction log is filling up.  Transaction log backups run every two hours. The customer has an Involuntary DBA who contacted me because she had found an article online explaining that she could switch to Bulk Logged recovery model before the Index Rebuild job ran, and then switch back after the rebuilds finished.

I explained that before she go that route, she should really figure out why the log is filling up…and that has turned into anoter blog post for another day (let’s hope for next week). We then discussed the implication of switching to Bulk Logged recovery model, from Full recovery, before running index rebuilds, and then switching back.

The big benefit of this switch is that the transaction log itself will not grow as much during the rebuild because index rebuilds are minimally logged operations.  However, it is important to realize that transaction log backups will still be about the same size as if the database were in Full Recovery while the rebuilds executed. Even though the bulk operation is minimally logged, all the extents that are modified still have to be written to the log backup for recovery purposes.

What is also very important to remember (and this is what I really wanted to make sure the customer understood) is that you are unable to restore to a specific point in time when the database is in the bulk logged mode. This is a myth that Paul Randal ( blog | @PaulRandal ) dispelled in his Mythbuster series.

If a customer switches to the Bulk Logged recovery model for rebuilds, but user activity is still occurring during that time, IF there is a disaster before the database is switched back to Full Recovery and a transaction log backup taken, they will lose all user activity which occurred during that time frame. For some people this might not be an issue – if you’re a Monday through Friday, 9 to 5 shop, you probably know that no one is in your database at 3 AM on Sundays. Howerver, for 24/7 customers who have users in the database all the time, that data loss is a possibility. Once the customer understood the risks, they could then make the right decision for them.

Now, not that I don’t believe Paul, but I’d never actually tried this so after I finished my call with the customer I did a little test. The script is below and I did indeed prove that what Paul said was true (shocker, I know).

{code}

/* create database */

CREATE DATABASE Movies

ON PRIMARY (

NAME = N’Movies’,

FILENAME = N’C:DatabasesMovies.mdf’ ,

SIZE = 4069KB ,

FILEGROWTH = 1024KB

)

LOG ON (

NAME = N’Movies_log’,

FILENAME = N’C:DatabasesMovies_log.ldf’ ,

SIZE = 1024KB ,

FILEGROWTH = 1024KB

)

USE Movies

GO

/* create table for testing */

CREATE TABLE dbo.titles (

name VARCHAR (1000),

releaseyear SMALLDATETIME,

rating VARCHAR(5)

)

/* add a clustered index so we have something to rebuild */

CREATE CLUSTERED INDEX CI_ReleaseYear ON dbo.titles (releaseyear)

/* add some data */

INSERT INTO dbo.titles (

name, releaseyear, rating

)

VALUES

(‘The Hangover’, ‘2009-06-05 00:00:00’, ‘R’),

(‘The Hunt for Red October’, ‘1990-03-02 00:00:00’, ‘PG’),

(‘Apollo 13’, ‘1995-06-30 00:00:00’, ‘PG’),

(‘A Few Good Men’, ‘1994-12-11 00:00:00’, ‘R’),

(‘The Natural’, ‘1984-05-11 00:00:00’, ‘PG’)

/* perform a full backup */

BACKUP DATABASE Movies

TO DISK = N’C:BackupsMovies_full.bak’

WITH NOFORMAT, STATS = 10

/* add some more data */

INSERT INTO dbo.titles (

name, releaseyear, rating

)

VALUES

(‘IronMan’, ‘2008-05-02 00:00:00’, ‘PG-13’),

(‘The Incredibles’, ‘2004-11-05 00:00:00’, ‘PG’),

(‘Apollo 13’, ‘1995-06-30 00:00:00’, ‘PG’)

/* perform a transaction log backup */

BACKUP LOG [Movies]

TO DISK = N’C:BackupsMovies_tlog.trn’

WITH NOFORMAT, STATS = 10

/* switch the recovery model */

ALTER DATABASE Movies

SET RECOVERY BULK_LOGGED WITH NO_WAIT

/* add some more data */

INSERT INTO dbo.titles (

name, releaseyear, rating

)

VALUES

(‘The Truman Show’, ‘1998-06-05 00:00:00’, ‘PG-13’),

(‘All The President”s Men’, ‘1976-04-09 00:00:00’, ‘R’)

/* note the current time (BEFORE running the alter below)

this is the time to which we will try to restore */

select getdate()

/* rebuild index */

ALTER INDEX CI_ReleaseYear ON dbo.titles REBUILD

/* oh no! disaster!  don’t panic…really…you have backups…right? */

/* perform a tail of the log backup */

BACKUP LOG [Movies]

TO DISK = N’C:BackupsMovies_tail_log.trn’

WITH NORECOVERY, NOFORMAT, STATS = 10

/* drop the database – note this is for our test only

If this happened in production we would NOT drop the production database */

USE master

GO

DROP DATABASE Movies

/* restore the database using the full backup */

RESTORE DATABASE MoviesRestored

FROM DISK = N’C:BackupsMovies_full.bak’

WITH FILE = 1,

MOVE N’Movies’ TO N’C:DatabasesMoviesRestored.mdf’,

MOVE N’Movies_log’ TO N’C:DatabasesMoviesRestored_1.ldf’,

NORECOVERY, NOUNLOAD, STATS = 10

/* restore the first transaction log backup we took, before changing recovery model */

RESTORE LOG MoviesRestored

FROM DISK = N’C:BackupsMovies_tlog.trn’

WITH FILE = 1,

NORECOVERY, NOUNLOAD, STATS = 10

/* try to restore the second transation log backup to the specific point

in time noted before the index rebuild was executed

change the time as appropriate */

RESTORE LOG MoviesRestored

FROM DISK = N’C:BackupsMovies_tail_log.trn’

WITH FILE = 1, NOUNLOAD, STATS = 10, STOPAT = N’2011-02-24T22:22:32.640′

/*

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.

Msg 4338, Level 16, State 1, Line 1

The STOPAT clause specifies a point too early to allow this backup set to be restored.

Choose a different stop point or use RESTORE DATABASE WITH RECOVERY to recover at the current point.

Msg 3013, Level 16, State 1, Line 1

RESTORE LOG is terminating abnormally.

*/

/* If you restore the database to any time after the tail of the log

backup was taken, it will work, but then you have no point in time recovery */

RESTORE LOG MoviesRestored

FROM DISK = N’C:BackupsMovies_tail_log.trn’

WITH FILE = 1, NOUNLOAD, STATS = 10, STOPAT = N’2011-02-24T22:23:32.640′

/*

/*————————

RESTORE LOG MoviesRestored

FROM DISK = N’C:BackupsMovies_tail_log.trn’

WITH FILE = 1, NOUNLOAD, STATS = 10, STOPAT = N’2011-02-24T22:23:32.640′

————————*/

44 percent processed.

89 percent processed.

100 percent processed.

Processed 16 pages for database ‘MoviesRestored’, file ‘Movies’ on file 1.

Processed 2 pages for database ‘MoviesRestored’, file ‘Movies_log’ on file 1.

This backup set contains records that were logged before the designated point in time.

The database is being left in the restoring state so that more roll forward can be performed.

RESTORE LOG successfully processed 18 pages in 0.024 seconds (5.798 MB/sec).

*/

/* finish recovering the database */

RESTORE DATABASE MoviesRestored

/* clean up code, backups are still on disk…somewhere… */

USE master

GO

DROP DATABASE MoviesRestored

{/code}

*Updated March 13, 2011 courtesy of an error in the tail-log backup syntax noticed by Paul White ( blog | @SQL_Kiwi ).  Thank you Paul!

There are no comments yet. Be the first and leave a response!

Leave a Reply

Wanting to leave an <em>phasis on your comment?

Trackback URL http://erinstellato.com/2011/02/bulk-logged-recovery-model-point-time-recovery/trackback/