Monday, February 27, 2017

Understanding SQL Server backups

One of my friends and colleagues (Jayaruwan alias JB) recently asked me a question regarding SQL Server backup. The question was, during the backup operation, what will happen to the data changes? Are those data recorded in the backup? If so till what point?

I knew for a fact that the data changes during the backup operation will get written to the backup. To demo this, I did the following test.

You need to open two query windows in SSMS. In this demo, I used SQL Server 2016 and bit large sample database named, AdventureWorksDW2016CTP3.

To run the demo yourself, you can follow the below steps.
Open two query windows in SSMS and copy and paste the below code in each query window.

 

--Window 1

--part 1
USE AdventureworksDW2016CTP3;
GO
DROP TABLE IF EXISTS backuptest
GO
CREATE TABLE backuptest
(
    Id int identity(1,1) primary key,
    Test_Desc varchar(1000)
)
GO

--part 2
DECLARE @msg3 binary(128);
SET @msg3=CAST('Kick off the full backup of AdventureworksDW2016CTP3' AS binary(128));

WHILE 1=1
INSERT INTO backuptest (Test_Desc)
SELECT command + ' ' + CAST(percent_complete AS varchar) + ' ' + CONVERT(varchar, GETDATE() ,121) FROM sys.dm_exec_requests
WHERE context_info=@msg3;
GO

--part 3
USE AdventureworksDW2016CTP3
GO
SELECT * FROM backuptest

--part 4
USE master;

 

Copy and paste the below code snippet in the 2nd Window.

 

--Window 2

--part 1
USE master;
GO
DECLARE @msg3 binary(128);
SET @msg3=CAST('Kick off the full backup of AdventureworksDW2016CTP3' AS binary(128));
SET CONTEXT_INFO @msg3;

PRINT 'Backup Database Started at : ' + CONVERT(varchar, GETDATE() ,121);
BACKUP DATABASE AdventureworksDW2016CTP3 TO DISK='C:\temp\AdventureWorksDW2016CTP3_full.bak'
WITH INIT;
PRINT 'Backup Database finished at : ' + CONVERT(varchar, GETDATE() ,121);
GO

--part 2
RESTORE DATABASE AdventureworksDW2016CTP3 FROM DISK='C:\temp\AdventureWorksDW2016CTP3_full.bak'

 

Execute the Part 1 and part 2 queries in Window 1.
Immediately move to the window 2 and execute the part 1. Watch the execution of the second Window, which is BACKUP DATABASE statement and once it's  completed, you need to stop the execution of Query Window 1.

You need to copy and paste the result of the backup operation which is similar to the following.

Backup Database Started at : 2017-02-27 22:21:58.270
Processed 186680 pages for database 'AdventureworksDW2016CTP3', file 'AdventureWorksDW2014_Data' on file 1.
Processed 39 pages for database 'AdventureworksDW2016CTP3', file 'AdventureWorksDW2014_Log' on file 1.
BACKUP DATABASE successfully processed 186719 pages in 14.817 seconds (98.450 MB/sec).
Backup Database finished at : 2017-02-27 22:22:13.200

It has the information of what time the backup started and what time it finished.

Now, you can check the data in backuptest table by executing the part 3 of the query in Window 1. See below figure for sample data set;

 

image

 

You can notice there are many rows inserted along with the percent completed of the backup statement which executed in parallel to the BACKUP DATABASE statement in Query Window 2. For later reference, copy and paste the result set to an Excel sheet. After carefully observing the data set, you need to change the database to master in Query Window 1 (part 4)

 

At this point, you've a full backup file in the local directory and we know that while the backup operation in progress we inserted the data to a table in Query Window 1.

 

Now switch back to the Query Window 2 and restore the database using the part 2. Upon completion of the restore, observe the data in backuptest table using part 3 of the Query in Window 1.

 

You can notice, most of the data changes happened during the backup process is still there. See the below figure;

image

 

The last entry recorded in the table is “BACKUP DATABASE 99.9967 2017-02-27 22:22:13.060”. At that point, database backup statement is completed 99% and the time is 22:22:13:060. We also have the backup statement completed time which is, “2017-02-27 22:22:13.200”. So actually it has missed 140 milliseconds worth of data.

 

You can do this demo yourself and get more understanding.

Cheers!

Monday, February 20, 2017

SQLSaturday582 - Melbourne

It was an honor to speak at SQLSaturday at Melbourne on 11th Feb, 2017. My session was about SQL Server Statistics and New Cardinality Estimator model. However, I could not go through some of the demos due to time restriction. I received much positive feedback so I'm finally happy about the session overall. 

You can find the presentation artifacts here.

Thanks, everyone who attended my session.

How to interpret Disk Latency

I was analyzing IO stats in one of our SQL Servers and noticed that IO latency (Read / Write) are very high. As a rule of thumb, we know tha...