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 – 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.

 

SQLServer – BulkCopy – Optimization – Reviewing Impact of Block Size via the Transaction Log Monitoring – Take 2

Background

As a follow-up to SQLServer – BulkCopy – Optimization – Take 1 ( https://danieladeniji.wordpress.com/2015/06/05/sqlserver-bulkcopy-optimization-take-1/ ), let us see how much churn occurs in our Transaction Log as we vary our Bulk Copy Program ( BCP ) block sizes.

Assumption

Let us make the following assumptions

  • Database Recovery Model
    • Recovery Model – Simple or Bulk Logged
    • Recovery Model – If recovery mode is Full, all changes, row allocation and data changes, are logged
  • We can truncate the destination table
  • We can lock the destination table

Diagnostic Tool

There are a couple of barometers we can use to read Transaction Log Utilization:

  1. DBCC SQL Perf
  2. sys.dm_db_log_space_usage
  3. fn_dblog
    • Undocumented SQL Server Dynamic Management View
    • Takes two parameters; the beginning and ending LSN

DBCC SQL Perf and sys.dm_db_log_usage offers database level information.  Whereas, fn_dblog works at the detail level.

Table Definition

Table - DBLab.NumbersSource

set noexec off;
SET ANSI_NULLS ON
SET QUOTED_IDENTIFIER ON
GO

if schema_id('DBLab') is null
begin

    exec('create schema [DBLab] ')

end;

go

if object_id('[DBLab].[NumbersSource]') is not null
begin

    set noexec on;

end
go

CREATE TABLE [DBLab].[NumbersSource]
(
	[Number] [int] NOT NULL,

     CONSTRAINT [DBLab.PK_NumbersSource] PRIMARY KEY CLUSTERED
        (
	        [Number] ASC
        )

) ON [PRIMARY]

GO

set noexec off;
go


Table - DBLab.Numbers


set noexec off;
SET ANSI_NULLS ON
SET QUOTED_IDENTIFIER ON
GO

if schema_id('DBLab') is null
begin

    exec('create schema [DBLab] ')

end;

go

if object_id('[DBLab].[Numbers]') is not null
begin

    set noexec on;

end
go

CREATE TABLE [DBLab].[Numbers]
(
	[Number] [int] NOT NULL,

     CONSTRAINT [DBLab.PK_Numbers] PRIMARY KEY CLUSTERED
        (
	        [Number] ASC
        )

) ON [PRIMARY]

GO

set noexec off;
go

Populate Data


SET NOCOUNT ON
SET ANSI_NULLS ON
SET QUOTED_IDENTIFIER ON
set noexec off
go

if schema_id('dblab') is null
begin

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

end
go

set noexec off
go

if exists
(
	select 1
	from   [dblab].[NumbersSource]
)
begin

	set noexec on

end
go
--Create a simple table with 10,000 rows
--load Numbers table with 1,000,000 numbers
WITH t1 AS
(
        SELECT 0 AS n UNION ALL SELECT 0 UNION ALL SELECT 0 UNION ALL SELECT 0)
        ,t2 AS (SELECT 0 AS n FROM t1 t1a, t1 t1b, t1 t1c, t1 t1d)
        ,t3 AS (SELECT 0 AS n FROM t2 t2a, t2 t2b, t2 t2c)
        ,tblVarNumbers AS (SELECT ROW_NUMBER() OVER(ORDER BY n) - 1 AS number FROM t3
)
INSERT INTO [dblab].[NumbersSource] WITH (TABLOCKX)
([Number])
SELECT number
FROM   tblVarNumbers
GO

set noexec off
go

LAB

To make thing more palatable, let us use a small dataset; a thousand records or so.

Data Extract


SETLOCAL

	set "DBSourceServer=.\SQLEXPRESS_V2014"
	set "TEMP_SESSION=%TEMP%"

	echo TEMP_SESSION is %TEMP_SESSION%	

	rem If folder does not exists, then create folder
	if not exist %TEMP_SESSION% mkdir %TEMP_SESSION%

	Rem Remove existing files
	if exist  %TEMP_SESSION%\*.data del %TEMP_SESSION%\*.data /Q

	bcp "select top 1000 * from DBLAB.dblab.NumbersSource" queryout %TEMP_SESSION%\dbo.NumbersSmall.data -T -n -S%DBSourceServer%

ENDLOCAL

Clean up Transaction Log

Let us clean up our transaction Log by doing the following:

  1. Set Recovery Mode to “Bulk Logged”
  2. Perform a full database backup to the NUL Device
  3. Perform a transaction log backup to the NUL Device

     alter database [DBLAB] set recovery bulk_logged;
   
     backup database [DBLAB] to disk = 'NUL';

     print '--------------------------------------------------------'
     backup log [DBLAB] to disk = 'NUL';
     print '--------------------------------------------------------'

    go

Import in blocks

Let us import records, one at a time


SETLOCAL

   set "DBSourceServer=.\SQLEXPRESS_V2014"
   set "TEMP_SESSION=%TEMP%"
   set "BLOCK_SIZE=100"

   echo TEMP_SESSION is %TEMP_SESSION%

   rem If folder does not exists, then create folder
   if not exist %TEMP_SESSION% mkdir %TEMP_SESSION%

   sqlcmd -Q"truncate table DBLAB.DBLab.Numbers" -S%DBSourceServer%

   bcp DBLAB.DBLab.Numbers in %TEMP_SESSION%\dbo.NumbersSmall.data -T -n -S%DBSourceServer% -b%BLOCK_SIZE% -h "TABLOCK, ORDER (Number ASC)"

  ENDLOCAL

Command Shell Output

bcpDataInBatchesYes [Cmhshell]

SQL Transaction Log – Aggregate Contents

Here is the code we will use to aggregate our Transaction Log


declare @spid int

--set @spid = 60

select
          tblFNDBLog.AllocUnitName
        , tblFNDBLog.Operation
        , [NumberofRecords] = count(*)
        , [Log Record Fixed Length] = sum(tblFNDBLog.[Log Record Fixed Length])
        , [Log Record Length] = sum(tblFNDBLog.[Log Record Length])
from   fn_dblog(null, null) tblFNDBLog

--where  spid = @spid

where tblFNDBLog.AllocUnitName is not null

and   tblFNDBLog.AllocUnitName not in ('Unknown Alloc Unit')

and   tblFNDBLog.AllocUnitName not like 'sys.%'

group by
          tblFNDBLog.AllocUnitName
        , tblFNDBLog.Operation

SQL Transaction Log – Aggregate Contents – 100 records per block

bcpDataInBatches1E2

Import in blocks of 1 million

Go back and clean up the Transaction Log


   alter database [DBLAB] set recovery bulk_logged;

   backup database [DBLAB] to disk = 'NUL';  

   print '--------------------------------------------------------'
   backup log [DBLAB] to disk = 'NUL'; 
   print '--------------------------------------------------------'

   go

Code – 1 million records

Let us import a million records at a time.


SETLOCAL

set "DBSourceServer=.\SQLEXPRESS_V2014"
set "TEMP_SESSION=%TEMP%"
set "BLOCK_SIZE=1000000"

echo TEMP_SESSION is %TEMP_SESSION%

rem If folder does not exists, then create folder
if not exist %TEMP_SESSION% mkdir %TEMP_SESSION%

sqlcmd -Q"truncate table DBLAB.DBLab.Numbers" -S%DBSourceServer%

bcp DBLAB.DBLab.Numbers in %TEMP_SESSION%\dbo.NumbersSmall.data -T -n -S%DBSourceServer% -b%BLOCK_SIZE% -h "TABLOCK, ORDER (Number ASC)"

ENDLOCAL

Command Shell – Output

bcpDataInBatchesNo [Cmhshell]

Aggregate Transaction Log – 1 million records

bcpDataInBatches1Million

SQL Profiler

SQL Server Profiler is another popular tool for modeling system performance.

Batch Size of 100

Here is what we capture for Batch Sizes of 100.

bulkInsertInBatches

Batch Size of 1 Million

Here is what we capture for Batch Sizes of 1 Million.

bulkInsertInBatchesNo

Quick Comparison of SQL Profiler Result

  • It is obvious there is a lot more dialog when we have a batch size of 100
  • It is not so obvious that our writes is so little.  I think it is likely that the actual BCP Writes are not reflected in the captured profiler readings

fn_dblog

More on fn_dblog.

There are quite a few things one should consider when thinking of using fn_dblog.  Inclusive are:

  1. fn_dblog accesses and reads a database log file
    • It is very expensive as it is reading an actual physical file
    • Let us assume that the file does not have indexes and so it can be taxing on the system
  2. fn_dblog accepts two arguments
    • The starting LSN Number
    • The ending LSN Number
  3. Log files are database specific
    • And, so one needs to change to the specific database
  4. fn_dblog exposes a lot of detailed information

Code

Here is a sample script for accessing a couple of columns.


--use [database-name];
declare @iNumberofRecordsMax int

set @iNumberofRecordsMax = 50;

; with cteAllocationUnit
as
(
    select
              tblSAU.data_space_id
            , tblSAU.type_desc

            , tblSAU.allocation_unit_id

            , tblSDF.physical_name

    from   sys.allocation_units tblSAU

            inner join sys.database_files tblSDF

                on tblSAU.data_space_id = tblSDF.data_space_id
)

, ctePartitionObject
as
(
    select
              tblSP.partition_id
            , tblSP.partition_number
            , tblSP.data_compression_desc

            , tblSP.object_id
            , tblSO.schema_id
            , [schemaName] = schema_name(tblSO.schema_id)
            , objectName = tblSO.name

    from   sys.partitions tblSP

            inner join sys.objects tblSO

                on tblSP.object_id = tblSO.object_id
)
select top (@iNumberofRecordsMax)
          tblFNDBLog.spid
        , tblFNDBLog.AllocUnitName
        , tblFNDBLog.Operation
        , [Log Record Fixed Length] = (tblFNDBLog.[Log Record Fixed Length])
        , [Log Record Length] = (tblFNDBLog.[Log Record Length])
        , tblFNDBLog.Context

        , cteAU.physical_name

        , tblFNDBLog.PartitionId
        , ctePO.object_id
        , ctePO.partition_number
        , ctePO.data_compression_desc

        , [schemaName] = ctePO.schemaName
        , [tableName] = ctePO.objectName

        , tblFNDBLog.[Article ID]

from   fn_dblog(null, null) tblFNDBLog

        left outer join cteAllocationUnit cteAU

            on tblFNDBLog.AllocUnitId = cteAU.allocation_unit_id

        left outer join ctePartitionObject ctePO

            on tblFNDBLog.PartitionId = ctePO.[partition_id]

where tblFNDBLog.AllocUnitName is not null

and   tblFNDBLog.AllocUnitName not in ('Unknown Alloc Unit')

and   tblFNDBLog.AllocUnitName not like 'sys.%'

Summary

Conclusively, if we use a high enough block size, we do not incur as much Transaction Log, as we would otherwise have used.

Specifically, we shed the LOP_INSERT_ROWS Operation.

The reason is salient, but it is because each time bcp starts working on a new block, it revisits the underlying table and inspects whether it is empty.

When the block size is smaller that the number of records, this consideration occurs and tests negative, every other time besides the initial consideration.

For a very high block size, the decision tree only occurs during the first block and is not repeated, as it is a singleton operation.

References

Will love to say “Life is Hard, but really?

…What can be so hard, when you Google on things and led to pasture by Sunil Agarwal and Remus Rusanu.

  1. Bulk Import Optimizations (Minimal Logging) – Sunil Agarwal
    http://blogs.msdn.com/b/sqlserverstorageengine/archive/2008/02/05/bulk-logging-optimizations-minimal-logging.aspx
  2. How to read and Interpret the SQL Server Log – Remus Rusanu – ( I write database engines by day – I use databases by night ).
    http://rusanu.com/2014/03/10/how-to-read-and-interpret-the-sql-server-log/
  3. SSIS and Minimally Logged Inserts – Jakub K
    http://jakubka.blogspot.com/2014/06/ssis-and-minimally-logged-inserts.html

SQL Server – Referential Integrity – Foreign Key Workings – Tracking Through Transaction Log

Background

Quick follow-up to our earlier discussion on SQL Server Referential Integrity – “How is it done” (https://danieladeniji.wordpress.com/2014/04/30/technical-microsoft-sql-server-referential-integrity-review-query-plan/)

Transaction Log Reading

We will dig through the Transaction Log and see if we can see how SQL Server does its work.

 

Successful Transaction

Here is what a successful transaction looks like.


set nocount on
set xact_abort off
go

use [DBLAB]
go

delete from dbo.[order]
delete from dbo.[customer]
go

backup database [DBLAB] to disk = 'NUL:' with init
go
backup log [DBLAB] to disk = 'NUL:' with init
go

begin tran trnDeleteGood

insert into [dbo].[customer]
(
[Customer_ID]
, [CustomerName]
, [inceptionDate]
, [expiryDate]
, [active]
, [dateAdded]
, [addedBy]
)
values
(
-100
, 'Kirkland'
, getdate()
, null
, 1
, getdate()
, SYSTEM_USER
)

insert into [dbo].[order]
(
[Customer_ID]
, [dateAdded]
, [addedBy]
)
select
-100
, getdate()
, SYSTEM_USER

commit tran trnDeleteGood

go


select
tblLog.[Current LSN]
, tblLog.SPID
, tblLog.[Database Name]
, tblLog.Operation
, tblLog.Command
, tblLog.AllocUnitName
, tblLog.[Transaction ID]
, tblLog.[Transaction Name]
, tblLog.[Number of Locks]

from sys.fn_dblog(null, null) tblLog

INNER JOIN sys.allocation_units tblAllocationUnit

ON tblLog.AllocUnitId = tblAllocationUnit.allocation_unit_id

INNER JOIN sys.partitions tblPartition

ON tblAllocationUnit.container_id = tblPartition.partition_id

INNER JOIN sys.objects tblObject

ON tblPartition.object_id = tblObject.object_id
order by tblLog.[Current LSN] desc

Output:

TransactionGood

 

Explanation:

  • Raw Transaction Log data is accessible through querying the sys.fn_dblog.   For our current purpose, the most reliable column is the AllocUnitID.We can join that column to the sys.allocation_units.  And, from sys.allocation_units get allocation_unit_id.Join sys.allocation_units to sys.partitions using container_id.And, join sys.partitions to sys.objects using object_id.
  • In the screen above, we ordered with most recent first
  • The 3rd entry is our insert into dbo.customer (LOP_INSERT_RECORDS)
  • The 2nd entry is our LOP_SET_BITS
  • The 1st entry is our insert into dbo.order (LOP_INSERT_RECORDS)

 

 

Failed Transaction

Here is what a failed transaction looks like.


set nocount on
set xact_abort off
go

use [DBLAB]
go

while (@@trancount &gt; 0)
begin

print 'rollback'
rollback;

end
go
delete from dbo.[order]
delete from dbo.[customer]
go

backup database [DBLAB] to disk = 'NUL:' with init
go
backup log [DBLAB] to disk = 'NUL:' with init
go

begin tran trnDeleteFailed

insert into [dbo].[customer]
(
[Customer_ID]
, [CustomerName]
, [inceptionDate]
, [expiryDate]
, [active]
, [dateAdded]
, [addedBy]
)
values
(
-100
, 'Kirkland'
, getdate()
, null
, 1
, getdate()
, SYSTEM_USER
)

insert into [dbo].[order]
(
[Customer_ID]
, [dateAdded]
, [addedBy]
)
select
-1002 -- customer id does not exist
, getdate()
, SYSTEM_USER

commit tran trnDeleteFailed

go


select
tblLog.[Current LSN]
, tblLog.SPID
, tblLog.[Database Name]
, tblLog.Operation
, tblLog.Command
, tblLog.AllocUnitName
, tblLog.[Transaction ID]
, tblLog.[Transaction Name]
, tblLog.[Number of Locks]

from sys.fn_dblog(null, null) tblLog

INNER JOIN sys.allocation_units tblAllocationUnit

ON tblLog.AllocUnitId = tblAllocationUnit.allocation_unit_id

INNER JOIN sys.partitions tblPartition

ON tblAllocationUnit.container_id = tblPartition.partition_id

INNER JOIN sys.objects tblObject

ON tblPartition.object_id = tblObject.object_id
order by tblLog.[Current LSN] desc

Output:
FailedTransaction

 

Explanation:

  • In the screen above, we again ordered with most recent first
  • The 4th entry is our insert into dbo.customer (LOP_INSERT_RECORDS)
  • The 3rd entry is our LOP_SET_BITS
  • The 2nd entry is our insert into dbo.order (LOP_INSERT_RECORDS)
  • The 1st entry is our “forced” removal of the orphaned insert into dbo.order (LOP_DELETE_ROWS)

 

 

Listening

As previously hinted, like a bird digging through SQL Server’s Log looking for one man’s waste..

The Neville Brothers – Bird on a Wire

 

References

Microsoft – SQL Server – Virtual Log File (VLF)

What are Virtual Log Files?

Querying for Virtual Log Files offers an insight into the journal of Log file fragments creation and usage.

As log file fragments are created the system keeps a record of their creation. Also, as the system uses the fragment the status column is updated, with a non-zero value .

Get Virtual Log File

   dbcc loginfo()
   go

Any Issues?

If a SQL Server Instance is not well managed, numerous Virtual Log Files can be created. Over creation results in a bit of fragmentation.

How to determine Fragmentation?

There are no hard rules to determine fragmentation. But, a system with over 300 or more VLF entries is probably fragmented.

What are the effects of Fragmentation?

      • When SQL Server Instance is starting, the database recovery takes longer as the system reviews each VLF and its contents. Each content is examined and a determination is made about rollback, etc.

     

        • Data Manipulate Language (DML) statements such as insert, delete, and update can also take a bit longer as the system transverses the log searching for clean buffers.

      How To fix:

      1] Backup Transaction Log

      2] Identify Transaction Log

              select
      		  db_name(dbid) as databaseName
      		, fileid
      		, name as fileSymbolicName
      		, groupid
      		, cast((size * 8 / 1024) as sysname) 
                           + ' MB' as sizeInMB
              from   master.sys.sysaltfiles
              where  groupid = 0
              --replace <database-name> with actual db-name
              and    dbid = db_id(<database-name>)
              ;

      3] Shrink Transaction Log files

              use ;
      
              -- shrink transaction log file, passing in file-id from
              -- sys.sysaltfiles
              dbcc shrinkfile();

      4] If Transaction Log does not shrink

          Query sys.databases and review the log_reuse_wait_desc column for reason why the transaction log might currently be in-use.

      Changes that will help forestall future Fragmentation?

          Setting appropriate levels for database log file growth
          Set reasonable growth size for the model database transaction log. This will help with new database created on that instance
          Have database job or monitoring script that identifies sub-optimally configured databases.
          Regular Scheduled Transaction Backup
          Review Application Code and ETL jobs to ensure granularity in projected Number of Records Affected
          Review SQL Server Profiler Traces and identify queries that generate high IO
      /*
         Find The Number of VLFs For All Databases
         By Ken Simmons
      http://sqlserverpedia.com/blog/sql-server-bloggers/find-the-number-of-vlfs-for-all-databases/
      */
      if object_id('tempdb..#LogInfo') is not null
      begin
      	drop table #LogInfo
      end	
      
      if object_id('tempdb..#LogInfo2') is not null
      begin
      	drop table #LogInfo2
      end
      
      CREATE TABLE #LogInfo(
                      FileID BIGINT,
                      FileSize BIGINT,
                      StartOffset BIGINT,
                      FSeqNo BIGINT,
                      Status BIGINT,
                      Parity BIGINT,
                      CreateLSN VARCHAR(50))
      CREATE TABLE #LogInfo2(
                      DatabaseName SYSNAME,
                      FileID BIGINT,
                      FileSize BIGINT,
                      StartOffset BIGINT,
                      FSeqNo BIGINT,
                      Status BIGINT,
                      Parity BIGINT,
                      CreateLSN VARCHAR(50))
      EXEC master.dbo.sp_MSFOREACHDB
          'USE [?] INSERT INTO #LogInfo EXECUTE (''DBCC LOGINFO'');
                 INSERT INTO #LogInfo2 SELECT ''?'', * FROM #LogInfo;
                 DELETE FROM #LogInfo'
      
      SELECT DatabaseName,
             COUNT(*) AS VLFs
      from #LogInfo2
      group by DatabaseName
      order by count(*) desc  
      
      drop table #LogInfo
      drop table #LogInfo2

      Get Database file Sizes and Growth Pattern\Size

      /*
      Datafile Growth in SQL Server - Getting the Statistics Part I
      http://sqlserver.livejournal.com/73512.html
      */
      select
      	  db_name(dbid) as databaseName
      	, fileid
      	, name as fileSymbolicName
      	, groupid
      	, cast((size * 8 / 1024) as sysname) + ' MB' as sizeInMB
      	, growth = (
         		      case
      			(status & 0x100000) when 0x100000
      				then cast(growth as sysname) + '%'
      				  else cast((growth * 8 / 1024) as
                                 sysname) + ' MB'
      			end
      		)
      from   master.sys.sysaltfiles
      where  dbid = db_id()
      ;

      References:

      1. SQL 2000 – YES! LOTS OF VLF’S ARE BAD! IMPROVE THE PERFORMANCE OF YOUR TRIGGERS AND LOG BACKUPS ON 2000
        http://sqlblogcasts.com/blogs/tonyrogerson/archive/2007/07/25/sql-2000-yes-lots-of-vlf-s-are-bad-improve-the-performance-of-your-triggers-and-log-backups-on-2000.aspx
      2. Linchi Shea – Performance impact: a large number of virtual log files – Part I
        http://sqlblog.com/blogs/linchi_shea/archive/2009/02/09/performance-impact-a-large-number-of-virtual-log-files-part-i.aspx
      3. Kimberly L. Tripp – Transaction Log VLFs – too many or too few?
        http://www.sqlskills.com/BLOGS/KIMBERLY/post/Transaction-Log-VLFs-too-many-or-too-few.aspx
      4. Real World DBA – Virtual Log Files – VLF – And SQL Server Performance
         http://www.realworlddba.com/post/2011/06/07/Virtual-Log-Files-VLF-And-SQL-Server-Performance.aspx