SQL Server – Lag between SQL Server Instance Startup and Database Availability

Introduction

We have automated our OS patches install.

And, wanted to see how long it is taken our databases to come backup once the SQL Instance engine itself is up.

Code

Guideline

We will query the errorlog file to get the SQL Instance start up time and then get date the initial check db completed?

Why the initial Check DB?  Well, when a SQL Instance starts, each database is checked prior to availing it.

The certification goes something like:

  1. Database Checkdb
    • CHECKDB for database ‘dem’ finished without errors on 2016-09-30 22:10:09.343 (local time). This is an informational message only; no user action is required.
  2. If there transactions that needs to rolledback/forward, then recovery needs to occur before checkdb is ran
    • Recovery of database ‘ppsivr’ (10) is 1% complete (approximately 930 seconds remain). Phase 1 of 3. This is an informational message only. No user action is required.
    • Recovery completed for database rbpivr1 (database ID 11) in 19 second(s) (analysis 9303 ms, redo 28 ms, undo 10285 ms.) This is an informational message only. No user action is required.
    • Recovery is complete. This is an informational message only. No user action is required.
    • CHECKDB for database ‘rbpivr1’ finished without errors on 2016-09-30 22:25:34.697 (local time). This is an informational message only; no user action is required.

So for us to get the lag between SQL Instance start and database availability we will do the following

  1. Access errrorlog using sp_readerrorlog
  2. The first line written when sql starts is
    • ErrorLog – First line in error log

      errorlog-sqlinstancestartup
  3. Recovery And Check DB
    • Recovery and CheckDB in errorlog
    • recoveryandcheckdb
    • As Checkdb can be initiated by users, we will filter for the one that has process id with an s at its end
    • Sample Check DB entries in errorlogerrorlog-checkdbsample

Actual Code

 


set nocount on;

declare @errorLogNumber int
declare @process  varchar(120)
declare @database sysname

/*
	Declare Table That we will use to track SQL Instance Boot Up Data
*/
declare @errorLogBootUp TABLE
(
	  [id]			bigint identity(1,1)
	, [LogDate]		datetime
	, [ProcessInfo] varchar(60)
	, [Text]		varchar(600)

	, [isSystem]
		as case
			when left(
						reverse([ProcessInfo])
						, 1
					) = 's'
					then 1
			else 0
		   end	
)

/*
	Declare Table That we will use to track Specific Processes
*/
declare @errorLogSpecificProcess TABLE
(
	  [id]			bigint identity(1,1)
	, [LogDate]		datetime
	, [ProcessInfo] varchar(60)
	, [Text]		varchar(600)

	, [isSystem]
		as case
			when left(
						reverse([ProcessInfo])
						, 1
					) = 's'
					then 1
			else 0
		   end	
)

set @errorLogNumber = 0
set @process = 'Microsoft SQL Server'

/*
	Get Boot Up Data
*/
insert into @errorLogBootUp
(
	  [LogDate]
	, [ProcessInfo]
	, [Text]		

)
EXEC sp_readerrorlog @errorLogNumber, 1, @process

/*
	Only keep the earliest data
*/
delete 
from   @errorLogBootUp
where  [id] != 1

set @database = 'dem'
set @process = 'checkdb'

insert into @errorLogSpecificProcess
(
	  [LogDate]
	, [ProcessInfo]
	, [Text]		

)
EXEC sp_readerrorlog 0, 1, @process, @database

/*
	Only keep System Data
*/
delete 
from   @errorLogSpecificProcess
where  [isSystem] != 1

select 
		  [src] = '@errorLogBootup'
		, tblELBU.*
from   @errorLogBootUp tblELBU

select 
		  [src] = '@errorLogSpecificProcess'
		, tblELSP.*
from   @errorLogSpecificProcess tblELSP

select 
		   [database]
			= @database

		 , [SQLInstanceStartUp]
			= tblELBU.LogDate

		 , [DBAvail]
			= tblELSP.LogDate

		,  [lagBetweenSystemStartAndDBAvailInSeconds]
			= datediff(second, tblELBU.LogDate, tblELSP.LogDate)

		,  [lagBetweenSystemStartAndDBAvailInMinutes]
			= datediff(minute, tblELBU.LogDate, tblELSP.LogDate)

from   @errorLogBootUp tblELBU

cross apply @errorLogSpecificProcess tblELSP




Output

timetaken

Summary

In our case, it is not really taken long for our databases to come back up.

It could taken longer depending on whether it was a bad crash and we have a lot of activities to rollback or forward.

 

 

Leave a Reply

Please log in using one of these methods to post your comment:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s