Background

In the last few posts, we touched on measuring File IO utilization.

This is yet another post on that trail.

 

Transaction Log

What is Transaction Log?

Here is Microsoft’s definition of Transaction Log

Link
Every SQL Server database has a transaction log that records all transactions and the database
modifications made by each transaction.

What type of measurements are available

Here are some of the often used commands:

Granularity Command Reset  Database  dbcc sqlperf(logspace) dbcc sqlperf(‘sys.dm_os_wait_stats’,CLEAR); backup log Transaction Log Operation  fn_dblog

 

Reset Transaction Log

Here are some of the often used commands:

Command Explanation Checkpoint For performance reasons, the Database Engine performs modifications to database pages in memory—in the buffer cache—and does not write these pages to disk after every change. Rather, the Database Engine periodically issues a checkpoint on each database. A checkpoint writes the current in-memory modified pages (known as dirty pages) and transaction log information from memory to disk and, also, records information about the transaction log. The Database Engine supports several types of checkpoints: automatic, indirect, manual, and internal. Backup Log to NUL Backup Transaction Log

 

Process

The task that we will be undertaking is loading a staging table.

And, our primary interest is to measure the amount of Transaction Log that is expended.

 

Outline

1. Prepare Database for Transaction Log Profiling
   • Ensure that recovery mode is set for “full recovery”
   • Suspend any regular transaction level backup
   • Checkpoint
   • Perform a full database backup
2. Load Data
   • Actual Steps
     • Truncate staging table
     • Load data into staging table
     • Measure Transaction Log Metrics
       • Overall Transaction Log Usage
         • Get overall Transaction Log usage using”dbcc sqlperf(logspace)“
       • Get Transaction Log Usage at Operation & Context Level
         • Query fn_dblog to get current database log metrics
         • Group results by Operation and Context Level
   • Cleanup steps
     • Checkpoint database
     • Take Transaction level backup
3. Repeat loading data for each attempted load option
4. Cleanup
   • Revert back to original recovery mode
   • Re-enable any regularly scheduled transaction backup

 

Code

DBCC SQLPERF

SQLPERF – Create Tracking Table

declare @tblSQLPerf TABLE
(
	  [id]			int not null identity(1,1)

	, [databaseName]	sysname not null

	, [logsizeMB]		decimal(30, 4) not null

	, [logSpaceUsed%]	decimal(20, 8) not null

	, [logSpaceUsed]
				as (
					([logsizeMB] * [logSpaceUsed%])
					 / 100
				  )

	, [status]	    smallint	   not null

)

SQLPERF – Load Tracking Table

 

DBCC SQLPERF(logspace) gets the log size in MB for all databases in the SQL Instance

insert into @tblSQLPerf
(
	  [databaseName]
	, [logsizeMB]	
	, [logSpaceUsed%]	
	, [status]			
)
exec('dbcc sqlperf(logspace) with no_infomsgs')

 

SQLPERF – Review Tracking Table

Get stored “DBCC SQLPERF(logspace)” data for the specific databases that we are interested in.

--Review results of tracking table
select 
	      [src] = '@tblSQLPerf'
		, [rowNumber]
			= ROW_NUMBER() OVER 
				(
					ORDER BY tblSP.[id] ASC
				)
		, tblSP.databaseName
		, tblSP.logsizeMB
		, tblSP.logSpaceUsed
		, tblSP.[logSpaceUsed%]
		--, tblSP.*

from    @tblSQLPerf tblSP

where   (
			( tblSP.[databaseName]= @dbName)
		)
order by
		tblSP.[id] asc

fn_dblog – Create Tracking Table

We create a tracking table that will house fn_dbLog data.

declare @tblFNDBLog TABLE
(
	  [id]			int not null 
	, [operation]	        sysname not null
	, [context]		sysname not null
	, [count]		bigint     not null
	, [logSize]		bigint     not null
)

fn_dblog – Load Tracking Table

Issue dn_dblog against current database.

We get a journal of all transaction log operations since last checkpoint.

insert into @tblFNDBLog
(
	  [id]
	, [operation]
	, [context]
	, [count]	
	, [logSize]	
)
select 
	          @id
		, [Operation]
		, [Context]
		, [cnt] = count(*)
		, LogSize
                   = sum([log record length]) as LogSize

from fn_dblog (NULL, NULL)

group by
	    [Operation]
	  , [Context]

 

 

fn_dbLog – Review Tracking Table – Count

Get stored “fn_dbLog” data.

Aggregated by Operation and Context.

First dataset that we project is count.

The number of times recorded for each grouping ( Operation and Context).

Data was captured in rows and we have to use pivot to display as columns.

 

select 
		  [src] = 'fn_dblog//Count]'
		, [operation]
		, [context]
		, [0]
		, [1]
		, [2]
		, [3]

from 
(

	SELECT [operation], [context], [id], [count]
	FROM   @tblFNDBLog

) AS SourceTable

PIVOT
(
	AVG([count])
	FOR [id] IN 
		(
			[0], [1], [2], [3]
		)

) AS pvt

order by

	isNull
	(
		  [0]
		, 0
	) 
	+ isNull
	(
		  [1]
		, 0
	) 
	+ isNull
	(
		  [2]
		, 0
	) 
	+ isNull
	(
		  [3]
		, 0
	) 

	desc

 

fn_dbLog – Review Tracking Table – Size

Get stored “fn_dbLog” data.

Aggregated by Operation and Context.

Second dataset that we project is size.

We sum up the size of transaction log uptake per Operation & Context.

Again, data was captured in rows and we have to use pivot to display as columns.

 

select 
		  [src] = 'fn_dblog//logSize]'
		, [operation]
		, [context]
		, [0]
		, [1]
		, [2]
		, [3]

from 
(

	SELECT [operation], [context], [id], [logSize]
	FROM   @tblFNDBLog

) AS SourceTable

PIVOT
(
	sum([logSize])
	FOR [id] IN 
		(
			[0], [1], [2], [3]
		)

) AS pvt

order by

	isNull
	(
		  [0]
		, 0
	) 
	+ isNull
	(
		  [1]
		, 0
	) 
	+ isNull
	(
		  [2]
		, 0
	) 
	+ isNull
	(
		  [3]
		, 0
	) 

	desc

 

Database Backup

Database Backup – Transaction Log

Here we review the transaction log backup metrics.

After each trial run we took a transaction log backup.

SELECT

		 [database]
			= tblBS.database_name  

	   , [TSStart]
			= tblBS.backup_start_date  

	   , [TSEnd]
			= tblBS.backup_finish_date

		, [durationInSec]
			= datediff
				(
					  second
					, tblBS.backup_start_date 
					, tblBS.backup_finish_date
				)

	   , [backupSizeInBytes]
			= tblBS.backup_size  

	   , [backupSizeInMegaBytes]
			= ( tblBS.backup_size / 1E6)

	   , [compressedBackupSizeInBytes]
			= tblBS.compressed_backup_size

	   , [compressedBackupSizeInMegaBytes]
			= (
				tblBS.compressed_backup_size
				/ 1E6
			  )	

		, [compressionRatio]
				= cast
					(
						(
						tblBS.compressed_backup_size
							/ NULLIF(tblBS.backup_size, 0)
						)
						as decimal(10, 4)
					)

	   , tblBMF.logical_device_name  

	   , tblBMF.physical_device_name   

FROM  msdb.dbo.backupset tblBS

left outer join msdb.dbo.backupmediafamily tblBMF

		ON tblBS.media_set_id  = tblBMF.media_set_id 

where  tblBS.[database_name] = db_name()

and    tblBS.[type] = 'L' 

--and    tblBS.backup_start_date > @dateStartedPostFullBackup

order by 
		tblBS.backup_start_date asc

Table Sizes

sp_spaceused – Create tracking table

declare @tblSpaceUsed TABLE
(
	  [id]				int not null identity(1,1)

	, [tableName]		sysname not null

	, [numberofRecords]	bigint  not null

	, [reservedKB]		varchar(100) not null
	, [reservedMB]		as 
						cast
						(
							(
								cast
								(
									replace
									(
										ltrim(rtrim([reservedKB]))
										, 'KB'
										, ''
									) 
									as decimal(30, 6)
								)
							) / (1024.00)
								as decimal(30, 6)
						)

						
	, [dataKB]			varchar(100) not null
	, [dataMB]		as 
					cast
						(
							(
								cast
								(
									replace
									(
										ltrim(rtrim([dataKB]))
										, 'KB'
										, ''
									) 
									as decimal(30, 6)
								)
							) / (1024.00)
								as decimal(30, 6)
						)

	, [indexKB]			varchar(100) not null
	, [indexMB]		
					as 
					cast
						(
							(
								cast
								(
									replace
									(
										ltrim(rtrim([indexKB]))
										, 'KB'
										, ''
									) 
									as decimal(30, 6)
								)
							) / (1024.00)
								as decimal(30, 6)
						)


	, [unusedKB]		varchar(100) not null
	, [unusedMB]		as 
						cast
						(
							(
								cast
								(
									replace
									(
										ltrim(rtrim([unusedKB]))
										, 'KB'
										, ''
									) 
									as decimal(30, 6)
								)
							) / (1024.00)
								as decimal(30, 6)
						)



)

sp_spaceused – Get table space used

We issued sp_spaceused against each table.

insert into @tblSpaceUsed
(

	  [tableName]
	, [numberofRecords]

	, [reservedKB]		
	, [dataKB]	
	, [indexKB]	
	, [unusedKB]	

)
exec sp_spaceused @objectName

 

Results

SQLPerf

fn_dbLog // Count

Explanation

1. LOP_INSERT_ROWS & LCX_TEXT_MIX
   • Operation :- LOP_INSERT_ROWS
   • Context :- LCX_TEXT_MIX
   • Explanation
     • Insert Rows into LOB column ( LCX_TEXT_MIX )
     • Data written to Log file
2. LOP_MODIFY_ROWS & LCX_TEXT_MIX
   • Operation :- LOP_MODIFY_ROWS
   • Context :- LCX_TEXT_MIX
   • Explanation
     • Insert Rows into LOB column ( LCX_TEXT_MIX )
     • Data read from Log file and written to datafile
3. LOP_SET_FREE_SPACE & LCX_PFS
   • Operation :- LOP_SET_FREE_SPACE
   • Context :- LCX_PFS
   • Explanation
     • LOP_SET_FREE_SPACE
       • Looking for free Space
     • LCK_PFS
       • Page marked as deallocated in PFS
4. LOP_MODIFY_ROW & LCK_PFS
   • LOP_MODIFY_ROW
     • Modify existing data
   • LCK_PFS
     • Update PFS Pages
5. LOP_FORMAT_PAGE & LCK_TEXT_MIX
   • LOP_FORMAT_PAGE
     • Data is being loaded into a Heap
     • We are truncating data before loading
     • LOC_FORMAT_PAGE seems to indicate the zeroing out of pages from previous usage and in preparation for re-use
   •  LCX_TEXT_MIX
     • LCX_TEXT_MIX indicates LOB data pages
6. LOP_MODIFY_ROW & LCK_TEXT_TREE
   • LOP_MODIFY_ROW
     • Modify existing data
   • LCK_TEXT_TREE
     • ???
7. LOP_INSERT_ROWS & LCX_HEAP
   • LOP_INSERT_ROWS
     • Insert data
   • LCX_HEAP
     • Heap
   • Number of entries
     • Matches number of records inserted into table
8. LOP_HOBT_DELTA & LCX_NULL
   • LOP_HOBT_DELTA
     • HOBT stands for “Heap or B-Tree“
   • LCX_NULL
     • ???
9. LOP_FORMAT_PAGE & LCX_HEAP
   • LOP_FORMAT_PAGE
     • LOP_FORMAT_PAGE is a type of log record that does a full or partial page format
   • LCX_HEAP
     • Heap is targeted
10. LOP_INSERT_ROWS & LCX_INDEX_LEAF
    • LOP_INSERT_ROWS
      • Insert data
    • LCX_INDEX_LEAF
      • Index Leaf page
    • Number of entries
      • Depends on how records are inserted
11. LOP_SET_BITS & LCX_IAM
    • LOP_SET_BITS
      • Set the bit for IAM Pages
    • LCX_IAM
      • SQL Server uses index allocation maps to track which pages have been allocated to which allocation unit. They are stored in special IAM pages. ( Link )
12. LOP_SET_BITS & LCX_GAM
    • LOP_SET_BITS
      • Set the bit for GAM Pages
    • LCX_GAM
      • Global Allocation Map (GAM) page
13. LOP_LOCK_XACT,  LCX_NULL
    • LOP_LOCK_XACT
      • Transaction Lock
14. LOP_COMMIT_XACT,  LCX_NULL
    • LOP_COMMIT_XACT
      • Transaction Commit
15. LOP_BEGIN_XACT,  LCX_NULL
    • LOP_BEGIN_XACT
      • Transaction Begin
16. LOP_SET_BITS & LCX_DIFF_MAP
    • LOP_SET_BITS
      • Set the bit
    • LCX_DIFF_MAP
      • Likely Differential Map
      • ???
17. LOP_FORMAT_PAGE  & LCX_TEXT_TREE
    • LOP_FORMAT_PAGE
      • ??
    • LCX_TEXT_TREE
      • ???
18. LOP_INSERT_ROWS & LCX_TEXT_TREE
    • LOP_INSERT_ROWS
      • Insert Rows
    • LCX_TEXT_TREE
      • ???
19. LOP_INSYSXACT & LCX_INDEX_LEAF
    • LOP_INSYSXACT
      • Internal System Table Insert
        • Likely due to table create statement
    • LCX_INDEX_LEAF
      • Index Leaf Operation
20. LOP_BUF_WRITE  & LCX_NULL
    • LOP_BUF_WRITE
      • Write to Buffer
    • LCX_NULL
      • ???
21. LOP_INSYSXACT & LCX_INDEX_INTERIOR
    • LOP_INSYSXACT
    • Internal System Table Insert
      • Likely due to table create statement
    • LCX_INDEX_INTERIOR
      • Interior = Non-Leaf Page
22. LOP_COMPRESSION_INFO  & LCX_INDEX_LEAF
    • LOP_COMPRESSION_INFO
      • Compression Info
    • LCX_INDEX_LEAF
      • Index Leaf
23. LOP_FORMAT_PAGE & LCX_BULK_OPERATION_PAGE
    • LOP_FORMAT_PAGE
    • LCX_BULK_OPERATION_PAGE
      • Bulk Insert
24. LOP_MODIFY_HEADER & LCX_BULK_OPERATION_PAGE
    • LOP_MODIFY_HEADER
      • Header Page
    • LCX_BULK_OPERATION_PAGE
      • Bulk Insert
25. LOP_EXPUNGE_ROWS & LCX_INDEX_LEAF
    • LOP_EXPUNGE_ROWS
      • Ghost Cleanup
    • LCX_INDEX_LEAF
      • Leaf Node

 

Others

1.  LOP_END_CKPT
   • LOP_END_CKPT
     • CheckPoint – End
2. LOP_BEGIN_CKPT
   • LOP_BEGIN_CKPT
     • Checkpoint – Begin
3. LOP_XACT_CKPT
   • LOP_XACT_CKPT
     • Checkpoint – Transaction

 

 

Terminologies

PFS

1. Paul Randal – Under the covers: GAM, SGAM, and PFS pages
   • PFS stands for Page Free Space, but the PFS page tracks much more than that. As well as GAM intervals, every database file is also split (conceptually) into PFS intervals. A PFS interval is 8088 pages, or about 64MB. A PFS page doesn’t have a bitmap – it has a byte-map, with one byte for each page in the PFS interval (not including itself).
   • Free space is only tracked for pages storing LOB values (i.e. text/image in SQL Server 2000, plus varchar(max)/varbinary(max)/XML and row-overflow data in SQL Server 2005) and heap data pages. This is because these are the only pages that store unordered data and so insertions can occur anywhere there’s space. For indexes, there’s an explicit ordering so there’s no choice in the insertion point.

LCK_PFS

1. SQL Server: Curious Case of Logging in Online and Offline Index Rebuild in Full Recovery Model
   Link
   • Page that was being locked and context column show LCK_PFS which means for this page just it is marked as de-allocated in PFS page.

 

IAM

1. sqlity.com
   • Home » Blog » The Index Allocation Map (IAM)
     • The Index Allocation Map (IAM)
       Link

LOB

1. sqlity.com
   • Home » Blog » LOB Data Pages
     • Page Type 3 – LOB Data Pages explained
       Link
       • sys.dm_db_database_page_allocations

Background Tasks

1. Ghost Cleanup
   • Tracking
     • SELECT * FROM master.dbo.sysprocesses WHERE cmd LIKE ‘%ghost%’

Summary

Intentionally leaving out any advisory.

Just wanted to point at reviewing Transaction Log contents and size as one way to profile Database Applications.

Transaction Backup Sizes present one option to review overall sizes.

fn_dblog querying through aggregating the Operation and Context columns allows one to follow the trail of SQL Statements.

 

References

1. Server & Tools Blogs > Data Platform Blogs > SQL Server Database Engine Blog
   • Paul Randal – Under the covers: GAM, SGAM, and PFS pages
     Link
2. Wiki > TechNet Articles > SQL Server: Curious Case of Logging in Online and Offline Index Rebuild in Full Recovery Model
   • SQL Server: Curious Case of Logging in Online and Offline Index Rebuild in Full Recovery Model
     Link
3. sqlFascination
   • Andrew Hong
     • A Strange Case of a Very Large LOP_FORMAT_PAGE
       Link
     • Decoding a Simple Update Statement Within the Transaction Log
       Link
     • How Do You Decode A Simple Entry in the Transaction Log? (Part 1)
       Link
4. Simple Talk
   • Uwe Ricken
     • DELETE Operation in SQL Server HEAPs
       Link
5. Akash Gautam
   • sqlservergeeks.com
     • SQL Server Recovery Model Deep Dives
       Link
6.  WikiDBA
   •  Virendra Yaduvanshi
     • Finding user who ran insert on SQL Server
       Link
7. SqlShack
   • Jefferson Elias
     • How to take advantage of SQL Server Transaction Log
       Link
8. SQLSkills
   • Paul Randle
     • LOP_FORMAT_PAGE is a type of log record that does a full or partial page format
       Link
     • Tracking page splits using the transaction log
       Link
     • Inside the Storage Engine: Ghost cleanup in depth
       Link
9. Martin Smith
   • stackoverflow
     • Why does DELETE leave a lingering effect on performance?
       Link
10. Paul White
    • Paul White & DiamondBeezer
      • SQL Server High Availability and Sharepoint – log file grows when no database activity
        Link
11. raresql.com
    • SQL Server – How to find Who Deleted What records at What Time
      Link
12. EfficientSQL
    1. OPTIMIZING TRANSACTION LOG PERFORMANCE
       Link