Backup Internals – Trace Flag 3014

Trace Flag 3014–  This is one of the undocumented Trace flags in SQL Server, which basically gives a detailed information(Well, This might not be useful in most of the cases) regarding File Creation, Padding and much more related Info while you are taking a Backup of your Database.

Do you really need this Info? IMHO, 95% of the cases, i would say NO. I consider this as Just an FYI kind of Information. When i try to troubleshoot Backup/Restore Issues, I rather enable Trace Flags 3004 and 3014 along with 3605(to enable logging of all the entries in our Error Log) instead of Just enabling Single Flag(Make sure you disable these Flags once you are done with diagnostics).

Let’s See what exactly get’s logged when i Enable these Trace Flags and Take a Full Database Backup.

2011-09-15 22:00:40.470 spid54 BackupStream(0): Starting MSDA of size 384 extents
2011-09-15 22:00:40.470 spid54 Started file C:\Program Files\Microsoft SQL Server\MSSQL10_50.PROD\MSSQL\DATA\3014_demo.mdf
2011-09-15 22:00:40.780 spid54 Completed file C:\Program Files\Microsoft SQL Server\MSSQL10_50.PROD\MSSQL\DATA\3014_demo.mdf
2011-09-15 22:00:40.790 spid54 Padding MSDA with 327680 bytes
2011-09-15 22:00:40.790 spid54 BackupStream(0): Total MSDA: 384 extents
2011-09-15 22:00:40.860 Backup Database backed up. Database: 3014_demo, creation date(time): 2011/09/15(21:46:19), pages dumped: 3100, first LSN: 163:1808:37, last LSN: 163:1824:1, number of dump devices: 1, device information: (FILE=2, TYPE=DISK: {‘D:\Backs\3014_full.bak’}).

So..Basically you can see exact times while starting backup stream , how many Extents being affected, what file(s) etc…Again This is Just an FYI information in most of the cases while you are dealing with Backups, where as the Trace Flag 3004(see here) is Extremely Useful while investigating DB Restore Issues. YMMV!


Diagnosing Database Restores – Trace Flag 3004

Recently one of my fellow DBA had an issue with a Database Restore, where he was restoring a database using a full backup(from GUI) and the wizard was progressed upto 100% and it stayed there for more than 30 Minutes and he pinged me to see what’s going on!! Well, The actual issue was the database which he took the backup had 16000+ VLF’s!!(Very Very Bad sign of Log file sizing) and the log file size was close to 78 GB and there was a hugeeee open transaction(which SQL will Undo while restoring the Backup). Note he was creating a brand new database, So SQL will be creating brand new files and remember transaction log file will be Zero Initialized always as apposed to Data files(If Instant File Initialization is enabled on your Instance).

Our focus in this post is not regarding VLF’s and how Log file should be managed, but to identify what’s happening behind the scenes with your Database Restore and kind of identifying current Phase of restore process. For this you can make use of  Undocumented trace flag 3004 along with 3605 to get the events logged in our Error Log. You can enable this trace flag either globally or at session level. (No need of  touching your start up parameters for these trace flags) Please see the below Screenshot.

For demo purpose, Let’s restore a Full Backup of a database(it has an Open Transaction) and let’s see how our Error Log looks like with this trace flag being enabled.

I’ve restored the DB,  see the Error Log in the below Screenshot.

Focus on these steps where you can note the actual time SQL Server took for Zeroing your Log File, Redo,Undo and all other required Information.

1.Zeroing C:\Program Files\Microsoft SQL Server\MSSQL10_50.PROD\MSSQL\DATA\3005_Demo_1.ldf
from page 1 to 20584 (0x2000 to 0xa0d0000)
2.Restore: Waiting for log zero on 3005_Demo
3.Zeroing completed on
C:\Program Files\Microsoft SQL Server\MSSQL10_50.PROD\MSSQL\DATA\3005_Demo_1.ldf
4.Restore: LogZero complete
5.Starting up database ‘3005_Demo’.
6.The database ‘3005_Demo’ is marked RESTORING and is in a state that does not allow recovery to be run.
7.Starting up database ‘3005_Demo’.
8.Recovery is writing a checkpoint in database ‘3005_Demo’ (19).
9.Recovery completed for database 3005_Demo (database ID 19) in 9 second(s)
(analysis 20 ms, redo 1801 ms, undo 7690 ms.)
10.Restore is complete on database ‘3005_Demo’. The database is now available.
Database was restored: Database: 3005_Demo, creation date(time): 2011/08/23(23:16:47), first LSN: 38:19:1 blabla

Hope this is informative!