My backup and SLEEP_BPOOL_FLUSH

I noticed that my backup was taking longer than usual.

I went to Perfmon to look at some counters, more specifically Physical disk:Avg sec/read(orange/yellow line) and Physical disk:Avg sec/write(blue line), yes it was very busy, much busier than normal.

bak2

Waits stats was painting the following picture: I was very intrigued with the sleep_bpool_flush so I headed straight over to the waits library.

waits1bak

You get this wait type when the checkpoint process realizes that it’s saturating the I/O subsystem. (https://www.sqlskills.com/help/waits/sleep_bpool_flush/), so it seemed that my backup could not even issue a checkpoint successfully. With that thinking I decided to do a manual checkpoint which just made the problem worse.

blockme

After some detective work I found the answer. Someone enabled TDE and it was going though the encryption process whilst I was trying to take a backup so my backup was never going to complete anytime soon.

The error message I was ended up with was  “Msg 5901, Level 16, State 1, Line 7 One or more recovery units belonging to database ‘NEWdb’ failed to generate a checkpoint”.

You can use the following query to understand the state of the encryption process for your databases.

SELECT
db.name,db.is_encrypted,dm.encryption_state,dm.percent_complete,dm.key_algorithm,dm.key_length
FROM
sys.databases db
LEFT OUTER JOIN sys.dm_database_encryption_keys dm
ON db.database_id = dm.database_id

bak3

When you have a state of 2 it means encryption is in progress, you may have heard of this as an encryption scan.

This behaviour is confirmed via Books on line and totally makes sense. (Last bullet point)

The following operations are not allowed during the CREATE DATABASE ENCRYPTION KEY, ALTER DATABASE ENCRYPTION KEY, DROP DATABASE ENCRYPTION KEY, or ALTER DATABASE…SET ENCRYPTION statements.

  • Dropping a file from a filegroup in the database.
  • Dropping the database.
  • Taking the database offline.
  • Detaching a database.
  • Transitioning a database or filegroup into a READ ONLY state.
  • Using an ALTER DATABASE command.
  • Starting a database or database file backup.

You live and learn.

SQL Server Restore to LSN

For this post I want to show you how I recovered to a LSN where I did do this on a server where I wanted to go back to a time just before a delete occurred.

This is my setup.

ALTER DATABASE [AdventureWorks2014] SET RECOVERY FULL
GO

BACKUP DATABASE [AdventureWorks2014] TO DISK = 'C:\SQLSERVER\backups\AdventureWorks2014.bak'WITH COMPRESSION

BACKUP LOG [AdventureWorks2014] TO DISK = 'C:\SQLSERVER\backups\AdventureWorks2014LOG1.bak'

-- DELETE occurred  (BAD USER)

DELETE FROM [Person].[Password]
WHERE BusinessEntityID = 2

BACKUP LOG [AdventureWorks2014] TO DISK = 'C:\SQLSERVER\backups\AdventureWorks2014LOG2.bak'

Lets gain some insight into the transaction log.

SELECT * FROM
fn_dblog (NULL, NULL)

trans

0000002e:00000348:0002 is The LSN where the transaction begins – LOP_BEGIN_XACT for transaction ID 0000:000015dd

This will be my recovery point. This LSN will be the STOPBEFOREMARK clause in my RESTORE code.

 RESTORE DATABASE [AdventureWorks2014DR]
    FROM DISK = 'C:\SQLSERVER\backups\AdventureWorks2014.BAK'
WITH
    MOVE N'AdventureWorks2014_Data' TO N'C:\SQLSERVER\AdventureWorks2014_Data2.mdf',
    MOVE N'AdventureWorks2014_Log' TO N'C:\SQLSERVER\AdventureWorks2014_log2.ldf',
   NORECOVERY
GO

RESTORE LOG [AdventureWorks2014DR]
FROM
    DISK = 'C:\SQLSERVER\backups\AdventureWorks2014LOG1.bak'
WITH
NORECOVERY;

RESTORE LOG [AdventureWorks2014DR]
FROM
    DISK = 'C:\SQLSERVER\backups\AdventureWorks2014LOG2.bak'
WITH
    STOPBEFOREMARK = 'lsn:0x0000002e:00000348:0002',
    NORECOVERY;
GO

RESTORE DATABASE [AdventureWorks2014DR] WITH RECOVERY;
GO

SELECT * FROM [Person].[Password]

Yes I have my delete back.

trans2

Let’s prove a point and go too far ahead. I will go past the commit; we wouldn’t expect it to be recovered right?

So let’s recover to LSN 0000002e:00000358:0001 (after the commit)


RESTORE DATABASE [AdventureWorks2014DR]
    FROM DISK = 'C:\SQLSERVER\backups\AdventureWorks2014.BAK'
WITH
    MOVE N'AdventureWorks2014_Data' TO N'C:\SQLSERVER\AdventureWorks2014_Data2.mdf',
    MOVE N'AdventureWorks2014_Log' TO N'C:\SQLSERVER\AdventureWorks2014_log2.ldf',
   NORECOVERY
GO

RESTORE LOG [AdventureWorks2014DR]
FROM
    DISK = 'C:\SQLSERVER\backups\AdventureWorks2014LOG1.bak'
WITH
NORECOVERY;

RESTORE LOG [AdventureWorks2014DR]
FROM
    DISK = 'C:\SQLSERVER\backups\AdventureWorks2014LOG2.bak'
WITH
    STOPBEFOREMARK = 'lsn:0x0000002e:00000358:0001',
    NORECOVERY;
GO

RESTORE DATABASE [AdventureWorks2014DR] WITH RECOVERY;
GO

USE [AdventureWorks2014DR]
go
SELECT * FROM [Person].[Password]

Nope, it’s too far ahead.

pd.JPG

Who did it?

Quite simply look for the Transaction SID for your Current LSN of interest.

 SELECT SUSER_SNAME(0x01050000000000051500000011C35F73E7CBDD7DA837D665F7620000) AS [WhoDidIt];