The output will look something like this (the system *tries* to report at exact % intervals, but it will sometimes be off by a bit):
There are a couple of undocumented trace flags you can add to get a lot more diagnostic information, either in the messages pane of Management Studio (using trace flag 3604), or in SQL Server's error log (using trace flag 3605).
Trace Flag 3014
The first trace flag for exposing more diagnostic information about the backup or restore operation is 3014. Let's run the backup again, and see the output in the messages pane:
The output:
For a restore operation:
The output is:
There are no timestamps on the output to the messages pane, so if you're using just 3604, you kind of have to watch the process and pay attention to when it "gets stuck" - and hope that it isn't a typical SSMS output buffer problem. But if you use 3605, you can see the timestamp for each step in the event log, so after the fact it should be easy to analyze and see where the time was spent.
Trace Flag 3004
Trace flag 3004 adds information to the output about file preparation, bitmaps, and instant file initialization (instant file initialization, which avoids the costly operation about zeroing out files, is only relevant for restore operations, and only for restoring data files).
For a backup:
Output:
For a restore, the additional information that is included about instant file initialization under 3004 is only directed to the error log, not to the messages pane. For this operation:
In the messages pane, we see this:
If you go to the error log, though, you'll see this information:
(Microsoft's Bob Dorr has written about TF 3004 before, but notes that it is undocumented and unsupported.)
If instant file initialization is not enabled, you'll see additional zeroing data for the data files (not necessarily in this order):
There are some scenarios that can prevent instant file initialization from helping the restore process, such as:
- the privilege not being granted to the SQL Server service account;
- the use of Transparent Data Encryption (TDE);
- the use of trace flag 1806, which disables instant file initialization;
For more details on instant file initialization, see these posts:
- Instant Initialization – What, Why and How?
- How and Why to Enable Instant File Initialization
- Misconceptions around instant file initialization
- A SQL Server DBA myth a day: (3/30) instant file initialization can be controlled from within SQL Server
- SQL Server Instant File Initialization (PQW)
Summary
If you are trying to monitor a sluggish backup or restore process, these trace flags should be able to help you determine where exactly the slowdown is occurring - it could be processing undo/redo operations, VLFs, Full-text, or writing to msdb. It could be something as simple as the fact that you expected instant file initialization to be enabled, and it wasn't. There could be other things that affect backup or restore performance but that won't become apparent under these trace flags; for example, if you are using backup compression, but trace flag 3042 is enabled, this flag changes the way the backup file is allocated during the process (documented here).
I don't recommend running these trace flags globally. In fact, I highly recommend running 3226 in general, which does something like the opposite - it prevents all of the successful backup message noise from polluting the error log. Note that 3004 and 3014 are not completely trumped by 3226. Having 3226 enabled globally will not prevent you from using these flags for troubleshooting purposes; the output will just be missing these lines:
RESTORE DATABASE successfully processed 290 pages in 0.029 seconds (78.125 MB/sec).
Comments