SQL Server – Transaction Log Usage – Metrics

Background

Reviewing Transaction Log Utilization and wanted to briefly document the SQL Code snippets out on the Internet.

 

Outline

  1. DBCC SQLPERF(logspace)
  2. sys.dm_os_performance_counters
    • Object Name
      • SQLServer:Databases
    • Counter Name
      • Log File(s) Size (KB)
      • Log File(s) Used Size (KB)

Performance Counters

DBCC

DBCC sqlperf

Code

dbcc sqlperf(logspace)
go

Output

DBCCSQLPerf_20180611_1139AM.png

Performance Counters

Performance Counters – “Object Name :- SQLServer:Databases” // “Counter Name :- LogFile”

Code – Tabulated

SELECT
        [object]
		= rtrim(pc1.[object_name])

	, [database]
		= rtrim(pc1.instance_name)

	, [logSizeMB]
		= cast
			(
				pc1.cntr_value/1024.0
					as decimal(30, 2)
			)

	, [logUsedMB]
		= cast
			(
				pc2.cntr_value/1024.0
					as decimal(30, 2)
			)

	, [logAvailMB]
		= cast
			(
				(pc1.cntr_value - pc2.cntr_value)
					/1024.0
					as decimal(30, 2)
			)

	, [percentUtilization]
		= cast
			(
				(

						( pc2.cntr_value*100.00 )
					/ NULLIF(pc1.cntr_value, 0)

				)
				as decimal(10, 2)
			)

FROM   sys.dm_os_performance_counters as pc1

JOIN   sys.dm_os_performance_counters as pc2

	ON   pc1.[instance_name] = pc2.[instance_name]
	AND  pc1.[object_name] = pc2.[object_name]

where ( 1 = 1 )

AND pc1.[object_name] = 'SQLServer:Databases'

AND pc2.[object_name] = 'SQLServer:Databases'

AND pc1.counter_name = 'Log File(s) Size (KB)'

AND pc2.counter_name = 'Log File(s) Used Size (KB)'

AND pc1.instance_name not in
		(
				'_Total'
			, 'mssqlsystemresource'
		)

AND pc1.cntr_value > 0

order by

	[logUsedMB] desc

 

Output

performanceCounter_20180611_1133AM.png

Code – XML

select 

	tblInner.[node]

from
	(

		SELECT
              [object]
			    = rtrim(pc1.[object_name])

			, [database]
				= rtrim(pc1.instance_name)

			, [logSizeMB]
				= cast
					(
						pc1.cntr_value/1024.0
							as decimal(30, 2)
					)

			, [logUsedMB]
				= cast
					(
						pc2.cntr_value/1024.0
							as decimal(30, 2)
					)

			, [logAvailMB]
				= cast
					(
						(pc1.cntr_value - pc2.cntr_value)
							/1024.0
							as decimal(30, 2)
					)

			, [percentUtilization]
				= cast
					(
						(

								( pc2.cntr_value*100.00 )
							/ NULLIF(pc1.cntr_value, 0)

						)
						as decimal(10, 2)
					)

		FROM   sys.dm_os_performance_counters as pc1

		JOIN   sys.dm_os_performance_counters as pc2

			ON   pc1.[instance_name] = pc2.[instance_name]
			AND  pc1.[object_name] = pc2.[object_name]

		where ( 1 = 1 )

		AND pc1.[object_name] = 'SQLServer:Databases'

		AND pc2.[object_name] = 'SQLServer:Databases'

		AND pc1.counter_name = 'Log File(s) Size (KB)'

		AND pc2.counter_name = 'Log File(s) Used Size (KB)'

		AND pc1.instance_name not in
				(
					  '_Total'
					, 'mssqlsystemresource'
				)

		AND pc1.cntr_value > 0

		order by
			[logUsedMB] desc

		for xml
			  PATH('database')
			, root('list')

	) tblInner(node)

Output – XML

performanceCounter_XML_20180611_1137AM

 

References

  1. Microsoft
    • Developer
      • Downloads > Programs > Community > Documentation
        • Is there something like DBCC SQLPERF(LOGSPACE) that will show be a list of the databases and how much free space in each?
          Link

SQL Server – DBCC Info

Background

A few posts back we spoke about “SQL Server – Mapping DBCC Commands to Dynamic Management Views ( DMV )“.

That post is here.

 

DBCC DBINFO

Introduction

DBCC DBINFO offers concise metadata at the database level.

 

SYNTAX

Its syntax is elementary and here it is “DBCC dbinfo with tableresults“.

 

Sample

ROWS

Display result as rows

Query


dbcc dbinfo with tableresults, no_infomsgs

Output

 

COLUMNS

Query



set nocount on
go

set XACT_ABORT on
go


declare @tblDBInfo TABLE
(
      [parentObject] sysname not null

    , [object]		 sysname not null

    , [field]		 sysname not null

    , [sequenceNbr]  smallint 
                     identity(1,1) not null

    , [value]        nvarchar(4000) not null

    , primary key
        (
              [parentObject] 
            , [object]		 
            , [field]		 
            , [sequenceNbr]
        )
)

declare @servername sysname
declare @dbid		int
declare @dbname		sysname

set @servername = cast(
                        serverproperty('servername')
                        as sysname
                      )

set @dbid = db_id()

set @dbname = db_name()

insert into @tblDBInfo
(
      [parentObject]
    , [object]		
    , [field]		
    , [value]       
)
exec ('dbcc dbinfo with tableresults, no_infomsgs')

select *

from   @tblDBInfo

order by 
        [field] asc

; with cteExclusion
(
      [dbid]
    , [Field] 
)
as
(
    select 
           2 as [dbid]
        , 'dbi_dbccLastKnownGood' as [Field]

)
, cteDBInfo
(
      [servername]
    , [dbid]
    , [Field]
    , [VALUE]
)
as
(

    select 
              @servername
            , @dbid
            , tblDBI.Field
            , tblDBI.[VALUE]

    from   @tblDBInfo tblDBI

    where  tblDBI.Field in
            (
                  'dbi_dbccLastKnownGood'
                , 'dbi_version'
                , 'dbi_createVersion'
                , 'dbi_LastLogBackupTime'
                , 'dbi_crdate'
                , 'dbi_dbname'
                , 'dbi_dbid'
                , 'dbi_cmptlevel'
            )


    and not exists
        (
            select 1
            from   cteExclusion cteEX
            where  cteEX.[dbid] = @dbid
            and    cteEX.Field = tblDBI.[Field]   
        )


)

, ctePivot
as
(
    select 
              cteDBI.[serverName]
            , cteDBI.[dbid]
            , cteDBI.[dbi_dbccLastKnownGood]
            , [dbi_version]
            , [dbi_createVersion]
            , [dbi_LastLogBackupTime]
            , [dbi_crdate]
            , [dbi_dbname]
            , [dbi_dbid]
            , [dbi_cmptlevel]	

    from   cteDBInfo cteDBI

    PIVOT
        (
            MAX(VALUE)
    
            FOR [Field] in
            (
                  [dbi_dbccLastKnownGood]
                , [dbi_version]
                , [dbi_createVersion]
                , [dbi_LastLogBackupTime]
                , [dbi_crdate]
                , [dbi_dbname]
                , [dbi_dbid]
                , [dbi_cmptlevel]
            )

        ) cteDBI

)

select 
          cteDBI.[servername]
        , cteDBI.[dbid]
        , cteDBI.[dbi_dbccLastKnownGood]
        , [dbi_version]
        , [dbi_createVersion]
        , [dbi_LastLogBackupTime]
        , [dbi_crdate]
        , [dbi_dbname]
        , [dbi_dbid]
        , [dbi_cmptlevel]

from   ctePivot cteDBI


Output

Summary

DBCC DBINFO has a wealth of information.

Nuggets include:

  1. Database Attributes
    • Compatibility level
    • Collation
    • Containment
    • Create Date
    • Database ID ( dbid )
    • Database name ( dbname )
    • MirrorId ( Mirrored database )
    • familyGUID ( Restored DB & Snapshot )
    • Safety ( Mirrored database )
    • Database Version
    • Database Create Version
  2. Operation Tracking
    • Last time dbcc checkdb was ran
    • Last time Transaction Log backup was taken

SQL Server – Unable to shrink Transaction Log file

Background

Received an alert stating that we have gotten below our threshold of 10% on one of DB Servers.

Thanks goodness no late night phone calls.

Only saw it coming to work this morning.

The good and bad about smartphone.

TroubleShooting

Windows Desktop

Folder

Image

Explanation

  1. ppsivr_8.ldf is 28 GB

SQL Metadata

Outline

Here are dynamic management views ( DMVs) that we will access…

  1. dbcc sqlperf(logspace)
  2. sys.database_files
  3. sys.databases
  4. sys.dm_exec_requests & sysprocesses

 

Review Transaction Log File Sizes

SQL


dbcc sqlperf(logspace)

Output

 

Explanation

  1. ppsivr
    • Log Size MB
      • 27,699 MB
      • 27 GB

Review Database File Sizes

SQL


-- replace with targeted database
use [database]

SELECT 
		  [name]

		, [type]
			= tblSDF.[type_desc]

		, [filename]
			= tblSDF.[physical_name]

		, [allocatedMB]
			= tblSDF.size / 128

		, [usedMB]
			= CAST(FILEPROPERTY(name, 'SpaceUsed') AS int)
				/ 128

		, [availableSpaceMB]
				 = ( size - CAST(FILEPROPERTY(name, 'SpaceUsed') AS int) )
					/ 128

FROM sys.database_files tblSDF

order by
		tblSDF.size desc
;

Output

Review Database Transaction Log Re-usability State

SQL


declare @dbid   int
declare @dbname sysname

set @dbname = 'ppsivr'
set @dbid = db_id(@dbname)

select 
		    tblSD.[database_id]
		  , tblSD.[name]
		  , tblSD.[log_reuse_wait_desc]

from   sys.databases tblSD

where  (
			   (@dbid is null)

			or ( tblSD.[database_id] = @dbid)
		
	   )

Output

Explanation

  1. log_reuse_wait_desc
    • The database is not re-cycling its transaction log due to an ‘Active Transaction’

Review Current DB Requests

Code



declare @dbid   int
declare @dbname sysname

set @dbname = 'ppsivr'
set @dbid = db_id(@dbname)

select 
		  tblSDER.[session_id]

		, [database] 
			= db_name(tblSDER.[database_id])

		, [openTransaction]
			= tblSP.[open_tran]

		, tblSDER.[status]

		, tblSDER.[command]

		, tblSDER.[percent_complete]

		, tblSDER.wait_type

		, tblSDER.last_wait_type

		, tblSDER.[reads]

		, tblSDER.[writes]

from   sys.dm_exec_requests tblSDER

inner join master..sysprocesses tblSP

	on tblSDER.[session_id] = tblSP.[spid]

where  (

	         ( tblSDER.[open_tran] != 0 )

	      or ( tblSDER.[database_id] = @dbid)

      )



Output

Explanation

  1. User Transactions
    • It does not appear that we have user transactions that are current using our targeted database
  2. Background
    • WAIT_XTP_OFFLINE_CKPT_NEW_LOG
      • It does does not apply that WAIT_XTP_OFFLINE_CKPT_NEW_LOG updates the percent_complete column as so it is a bit difficult to track its current progress

 

Remediation

Here are the things we tried:

  1. dbcc shrinkfile
  2. Take database offline and bring back online

Attempt to Shrink Transaction Log Files

SQL


use [ppsivr]
go

dbcc shrinkfile('ppsivr_log')
go

Output

Explanation

  1. We want to take a good look at Current Size and Used Pages
    • In our case they are same
    • What is in our Transaction Log File?

 

Take Database Offline and bring it back online

Force termination of ongoing sessions

SQL


use master
go

ALTER DATABASE [ppsivr]
	SET SINGLE_USER WITH ROLLBACK IMMEDIATE
	;

alter database [ppsivr] set offline;

alter database [ppsivr] set online;

ALTER DATABASE [ppsivr]
	SET MULTI_USER WITH ROLLBACK IMMEDIATE
	;

 

Summary

But, nothing worked!

We will come back and talk about what worked.

References

  1. Microsoft
    • Support.Microsoft.com
      • FIX: Offline checkpoint thread shuts down without providing detailed exception information in SQL Server 2014
        Link

SQL Server – Transaction Log Management – Recovery Mode

Background

It is finally time to revisit a blog posting I started on Dec 21st, 2016.

That post is titled “SQL Server – Error – Cannot shrink log file because the logical file located at the end of the file is in use“.

And, it is here.

Issue

Received an alarm that our database files are growing and so sought to find out why.

 

TroubleShooting

Transaction Log – Utilization Metrics from Performance Counter

transactionLog.IUDF_UtilizationMetricsFromPerformanceCounters

Code

use master
go

if schema_id('transactionLog') is null
begin

	exec('create schema [transactionLog] authorization [dbo]')

end
go

if object_id('[transactionLog].[IUDF_UtilizationMetricsFromPerformanceCounters]') is null
begin

	exec(
			'create function [transactionLog].[IUDF_UtilizationMetricsFromPerformanceCounters]
			()
			RETURNS table
			AS
			RETURN 
			(
				SELECT 
					[shell] = 1/0
		   );
	   	   '
		)

end
go


alter function [transactionLog].[IUDF_UtilizationMetricsFromPerformanceCounters]
()
returns TABLE
as
return
(

	with cte
	(
		  [dbid]
		, [database]
		, [counter]
		, [size]
	)
	as
	(
 
		SELECT
				  [dbid]
					= db_id(RTRIM(instance_name)) 
 
				, [database]
					= RTRIM(instance_name) 
 
				, tblDMOPC.counter_name
 
				, cntr_value log_size_kb
 
		FROM  sys.dm_os_performance_counters tblDMOPC
 
		WHERE tblDMOPC.object_name = 'SQLServer:Databases'
 
		AND   tblDMOPC.counter_name like 'Log File' + '%'
 
		AND   tblDMOPC.instance_name <> '_Total'
 
	)
	, ctePivot
	as
	(
		select *
 
		from   cte
		pivot 
				(
					avg ([size]) 
							for [counter] in
								(
									  [Log File(s) Used Size (KB)]                                                                                                           
									, [Log File(s) Size (KB)]                                                                                                           
								)
				) as avgSize
 
	)
 
	select 

			  [cteP].[dbid]

			, [cteP].[database]
 
			, [usedMB] = [Log File(s) Used Size (KB)]
							/ 1000
 
			, [totalMB] =  [Log File(s) Size (KB)]
							/ 1000
 
			, [%]
				= cast
					(
						( [Log File(s) Used Size (KB)] * 100.00)
						/ ( [Log File(s) Size (KB)])
						as decimal(10,2 )
					)

			, [recoveryModel]
				= tblSD.recovery_model_desc

			, [log reuse wait]
				= tblSD.log_reuse_wait_desc
			
	from   ctePivot cteP

	inner join sys.databases tblSD

		on cteP.[dbid] = tblSD.database_id
 

)
go


Output

qa_20170207_0958pm

Explanation

  1. Before capturing the screenshot above, our target database, QA_rbpivr1, was in FULL RECOVERY
    • It’s transaction log size was 8 GB
    • And, 3.2 GB of the 8GB is in use

 

Why so much Transaction Log is being held up?

Recovery Mode

Again for QA_rbpiv1  3.2 GB is being used.

Let us review how database is configured

qa_recoverymode_20170207_1009am

We see that the Recovery Mode for our database is Full.

Backup Dates

databaseproperty_options_general_backupdate_qa_20170207_1013am

 

Explanation
  1. The last full backup was taken last night Feb 2nd, 2017 and it completed at 8:35 PM
  2. And, the last Transaction backup was taken on Sunday Feb 5th, 2017 at 6 PM

 

 

Transaction Backup History

Let us review our Transaction Backup History

 

sqlserveragent_transactionbackuphistory_qa_20170207_1019am

Explanation:

  1. Before today, transaction backups were occurred on 2/5/2017, 1/29/2017, 1/22/2017
  2. And, they were occurring each hour
  3. Looked back at the Calendar and those days fell on Sundays

 

 

Review Scheduled Transaction Backup

jobproperties-databasebackup-userdatabases-log-schedules-sunday-eachhour

 

Explanation:

  1. Schedule is Weekly on Sundays
  2. And, the frequency is each hour

 

Correction

Our bad.

Revise Schedule

sqlserveragent_transactionbackuphistory_qa_20170207_1028am

Explanation:

  1. Changed Schedule’s frequency from Weekly to Daily

 

Metadata

Review Checkpoints in Error Log File

Enable Logging of Checkpoints in ErrorLog file

Enable Trace Flags

Code

dbcc traceon (3502, 3504, 3605, -1 )

Review

Code

dbcc tracestatus

Output

dbcctracestatus

Review ErrorLog file

Let us review our error logs and make sure that Checkpoints are indeed been logged.

logfileviewer_20170207_1220pm

 

transactionLog.sp_checkPointsInErrorLogFileAggregate

 

Code

 


use [master]
go

if object_id('transactionLog.sp_checkPointsInErrorLogFileAggregate') is null
begin

	exec('create procedure [transactionLog].[sp_checkPointsInErrorLogFileAggregate] as ')

end
go

alter procedure [transactionLog].[sp_checkPointsInErrorLogFileAggregate] 
as  

begin

	set nocount on;
  
	declare @p1  INT
	declare @p2  INT
	declare @p3  VARCHAR(255)
	declare @p4  VARCHAR(255)
  
	declare @tblErrorLog     TABLE
	(
		  [id] int not null
			identity(1,1)
  
		, [LogDate] datetime
  
		, [ProcessInfo] sysname
  
		, [Text]        varchar(600) null
  
		, primary key
			(
				  [LogDate]
				, [id]
			)
  
		, INDEX INDX_ID
			(
				[id]
			)
  
	)
  
	set @p1 = 0 -- current
	set @p2 = 1 -- error log
	set @p3 = 'Ckpt'
	set @p3 = 'Ckpt dbid'
	set @p4  = ''
  
	insert into @tblErrorLog
	(
		  [LogDate]
		, [ProcessInfo]
		, [Text]        
	)
	exec [sys].[sp_readerrorlog]
			 @p1   = @p1  
		   , @p2   = @p2
		   , @p3   = @p3
		   , @p4   = @p4
  
  
	select
			  tblSD.[name]
  
			, tblSD.log_reuse_wait_desc
  
			, [count] 
				= count(tblEL.LogDate)
  
			, [LogDateMin]
				= min(tblEL.LogDate)
  
			, [LogDateMax]
				= max(tblEL.LogDate)
   
	from  sys.databases tblSD
  
	left outer join @tblErrorLog tblEL
  
			on   tblEL.[Text]  like '%' + cast(tblSD.database_id as varchar(10)) + '%'
          
			and  tblEL.[Text] like 'Ckpt dbid ' + '%' + 'started'
 
	group by
  
			   tblSD.[name]
			 , tblSD.log_reuse_wait_desc
  
	order by
  
			   tblSD.log_reuse_wait_desc asc
			 , count(tblEL.LogDate) desc
			 , tblSD.[name]

end
go



 

Output

errorlogfile_checkpoints_transactionlogcheckpoint_20170207_1036am

Explanation

  1. Database
    • QA_rbpivr1
      • LogDateMax
        • From digging in the Transaction Log File, we can see that the last Transaction Log on 2017-02-06 20:34
        • The timeline is Yesterday, Monday Feb 6th, 2017 8:34 PM
      • LogDateMin
        • LogDateMin is 2017-01-15 04:00
        • In readable term Jan 15th, 2017 @ 4 AM

 

Source Control

GitHub

  1. DanielAdeniji/SQLServerTransactionLogMetrics
    Link

 

Summary

In summary, our transaction size is growing and not being pruned because unfortunately our scheduled Transaction backup job was incorrectly set to only occur on Sundays.

Please keep in mind this only affects databases set for FULL RECOVERY.

From the metrics above, we can see that our identified database Transaction Log Checkpoints are only occurring at the tail end of Full Backups.

And, as aforementioned on Sundays.

 

SQL Server – Database Management – Shrink Log files

Background

Received a ticket that we are running low on Storage on one of our Development Database Servers.

Traced the error back to the fact that though we have a Database Transaction Backup registered it is not scheduled to run.

If I run it right away, I will be backing up old unneeded transaction log data.

And, so let us change the recovery mode to Simple ( that dumps the transaction log), shrink the log files, change the Recovery mode back to it original state.

 

Script

Code


; with cteLogFile
(
	  database_id
	, [shrinkStatement] 
)
as
(

	select

		  tblSMF.database_id

		, [shrinkStatement] 
			= STUFF
			  (
				(
					select 
							 ', ' 
							 + 'dbcc shrinkfile(' 
							 + quotename(tblSMF_Inner.[name])
							 + ') ' 
							 + ' with no_infomsgs'
							 + ';'
					from   sys.master_files tblSMF_Inner
					where  tblSMF.database_id = tblSMF_Inner.database_id  
					and  tblSMF_Inner.[type_desc] = 'LOG'
					FOR XML PATH('')
				)
				, 1
				, 1
				, ''
			 ) 

	from   sys.master_files tblSMF

	group by

			tblSMF.database_id

)
select	
		  [database] = tblSD.[name]

		, tblSD.recovery_model_desc

		, tblSD.log_reuse_wait_desc

		, [sqlSimple]
			= 'ALTER DATABASE ' 
				+ quoteName(tblSD.[name])
				+ ' set recovery SIMPLE;'

		, [sqlShrink]
			= 'use '
				+ quoteName(tblSD.[name])
				+ '; '
				+ cteLF.shrinkStatement

		, [sqlRestate]
			= 'ALTER DATABASE ' 
				+ quoteName(tblSD.[name])
				+ ' set recovery '
				+ tblSD.recovery_model_desc	collate DATABASE_DEFAULT
				+ '; '

from   sys.databases tblSD

inner join cteLogFile cteLF

		on tblSD.[database_id] = cteLF.database_id

where  tblSD.recovery_model_desc != 'SIMPLE'



 

Output

 

logfilemanagement

 

Explanation

  1. Transaction Log
    • File Sizes
      • Can only be shrunk down to initial database file size
    • Can not assume that sys.master_files_id is 2 and so check for type_desc = ‘LOG’

Keep in Mind

Please keep in mind that the SQL above only scripts the steps, it does no execute it.

Copy and Paste to perform actual execution.