Understanding database recovery with SQL Server 2016 Extended Events
Sometimes after a SQL Server restart you see that database recovery takes a long time and you want to know what is causing the delay. Up until SQL Server 2014 we could get some info from the SQL Server error log, but in SQL Server 2016 we can get much more insight with Extended Events.
Normally we used to track database recovery using the SQL Server Error Log which shows messages like:
SQL Server 2016 provides 3 Extended Events for capturing more information for database recovery:
First let's create a Extended Events sessions which will capture the details, this can be done with both SQL Server Management Studio (SSMS) or a T-SQL query.
Create SQL Server Extended Events Session
In SSMS, right click on Management > Extended Events > Sessions > New Session Wizard.
We can search the database_recovery events through a search, which shows 3 events as shown below. We can also see the Extended Events details and the fields that are captured for each event.
In the next screen, we can set additional fields to capture with the default fields. I have selected database_name and event_sequence.
In next screen, select the location and size of the file along with the maximum number of files.
Verify the settings and events in the next summary page. We can see that Auto Start is set to off, this means if the SQL service restarts it will not automatically start capturing the events.
We can also generate the query from the script options.
CREATE EVENT SESSION [Database_Recovery_Xevents] ON SERVER ADD EVENT sqlserver.database_recovery_progress_report( ACTION(package0.event_sequence,sqlserver.database_name)), ADD EVENT sqlserver.database_recovery_times( ACTION(package0.event_sequence,sqlserver.database_name)), ADD EVENT sqlserver.database_recovery_trace( ACTION(package0.event_sequence,sqlserver.database_name)) ADD TARGET package0.event_file(SET filename=N'Database_Recovery_Xevents') WITH (STARTUP_STATE=OFF) GO
To start the Extended Events session with a SQL Server restart, edit the session and enable the "Start the event session at server startup" check box.
This can also be done using the following T-SQL command:
ALTER EVENT SESSION [Database_Recovery_Xevents] ON SERVER WITH (STARTUP_STATE=ON) GO
SQL Server Database Recovery Information
As you may know, database recovery in SQL Server consists of the following phases:
I have the Extended Events session running, I ran some queries in the Adventureworks database to generate a workload and then restarted the SQL Server Service. Now we will look at the events that were captured.
By default, the event log shows the name and timestamp only, so we will select additional columns here.
Also, we will do analysis for just the Adventureworks database (this is database_id 8 on my server) and the event name of database_recovery_progress_report.
We can see the output below shows details about the recovery phase, elapsed time remaining, percent_complete and total elapsed time in seconds.
Similarly if we want to see the database_recovery_times events, then change the filter accordingly and it will show the output as follows. As we can see with database_recovery_times events we can get recovery time for specific steps during the database startup.
Now if we want further detailed information about recovery, set the filter for database_recovery_trace and analyze these events.
Here we can see more details of the start recovery process.
As seen above we can get details about each phase, some of the important events are:
- Virtual log file summary
- Estimated log amount for analysis
- Preparation of 'Dirty Page Table' (DPT) and 'Active Transaction Table' (ATT)
- Rolling forward all the changes that took place with estimated transaction log and transactions
- Undo phases of the transactions with details
- Recovery completion progress
- Post recovery operations
We can analyze the information for our databases which can help us to understand if recovery time is longer for a database.
About the author
View all my tips