THE SQL Server Blog Spot on the Web

Welcome to SQLblog.com - The SQL Server blog spot on the web Sign in | |
in Search

The Rambling DBA: Jonathan Kehayias

The random ramblings and rantings of frazzled SQL Server DBA

Using Extended Events in SQL Server Denali CTP1 to Map out the TransactionLog SQL Trace Event EventSubClass Values

John Sansom (Blog|Twitter) asked on the MSDN Forums about the meaning/description for the numeric values returned by the EventSubClass column of the TransactionLog SQL Trace Event.  John pointed out that this information is not available for this Event like it is for the other events in the Books Online Topic (TransactionLog Event Class), or in the sys.trace_subclass_values DMV.  John wanted to know if there was a way to determine this information.  I did some looking and found an old SQL Server 2000 BOL topic, Transactions Data Columns gave more information about what the EventSubClass means and defined the column as:

Type of transaction log event, such as BEGINXACT(null).

After seeing this, I knew it would be possible to map this out using the new sqlserver.transaction_log Event in Extended Events, which I blogged about last month in my blog post, An XEvent a Day (22 of 31) – The Future – fn_dblog() No More? Tracking Transaction Log Activity in Denali.  To start with I created a database with database_id = 5 on my VM that I would run a number of test workloads against.  Then I created a filtered Extended Events Session for the sqlserver.transaction_log Event in Extended Events in a SQL Server Denali CTP1 VM on my laptop for the sqlserver.transaction_log Event with a Predicate on database_id = 5 for the Event. 

CREATE EVENT SESSION tranlog
ON SERVER
ADD EVENT sqlserver.transaction_log
(    ACTION (sqlserver.event_sequence)
    WHERE database_id = 5)
ADD target package0.ring_buffer
WITH (MAX_DISPATCH_LATENCY = 5SECONDS, EVENT_RETENTION_MODE=NO_EVENT_LOSS)
GO
ALTER EVENT SESSION tranlog
ON SERVER
STATE=START
GO

I then created a SQL Trace in Profiler that also captured the TransactionLog Event with all of the available columns into a Trace Table named TranLogTrace in the master database that also had a filter on DatabaseID = 5.  Then I ran a couple of workload samples against the demo database (Note: These tests do not necessarily represent a complete workload.)

CREATE TABLE Test (rowid INT IDENTITY PRIMARY KEY)
GO
BEGIN TRANSACTION
GO
INSERT INTO Test DEFAULT VALUES;
GO 100
ROLLBACK
GO
BEGIN TRANSACTION
GO
INSERT INTO Test DEFAULT VALUES;
GO 100
COMMIT
GO

Based on this admittedly, overly simplistic test, the following mappings to of the EventSubClass of the SQL Trace TransactionLog using the following the parsing of the Extended Event Session Data as a comparison against the SQL Trace TransactionLog Event Data can be made:

EventSubClass operation context
257 LOP_FORMAT_PAGE HEAP
266 LOP_FORMAT_PAGE IAM
514 LOP_INSERT_ROWS CLUSTERED
515 LOP_INSERT_ROWS INDEX_LEAF
787 LOP_DELETE_ROWS MARK_AS_GHOST
1026 LOP_MODIFY_ROW CLUSTERED
1034 LOP_MODIFY_ROW IAM
1035 LOP_MODIFY_ROW PFS
1044 LOP_MODIFY_ROW BOOT_PAGE
4866 LOP_ROOT_CHANGE CLUSTERED
32768 LOP_BEGIN_XACT NULL
33024 LOP_COMMIT_XACT NULL
33280 LOP_ABORT_XACT NULL
35072 LOP_HOBT_DDL NULL
35840 LOP_HOBT_DELTA NULL
36096 LOP_LOCK_XACT NULL
45056 LOP_CREATE_ALLOCCHAIN NULL
56576 LOP_INVALIDATE_CACHE NULL

This is no way a complete mapping of the to entire subset of EventSubClass value’s of the SQL Trace Event, but it shows that there is a mechanism available through Extended Events that can map this kind of information out. 

While I was playing with this, I did some testing along the lines of the original question of the MSDN Forums post, and there is nothing in the TransactionLog Event that you could key on to know the log truncated.  No Transaction Log record is generated that specifically says the log truncated, it opens a transaction, writes to the boot_page, and closes the transaction all in different log records.  Keep in mind that the boot page gets written to by a number of other operations in SQL Server, so keying on it is not the answer.  For example, if the log is failing to truncate because there is an open transaction and it has to grow, the growth would trigger a write to the boot page.  Attempting to key in on TransactionLog Events in SQL Trace that write to the Boot Page alone would be short sighted, and incorrect in this type of analysis alone.

Published Monday, January 03, 2011 2:39 AM by Jonathan Kehayias

Comments

 

John Sansom said:

Brilliant! Thanks Jonathan.

This is impressive stuff. Not only does it scratch my/our curiosity itch but it also again demonstrates just how powerful and versatile a feature Extended Events are.

Thanks again, I appreciate it.

January 3, 2011 3:46 AM
 

Kirby L. Wallace said:

John is such a nice guy.  You really oughta edit and spell his name right.  ;-)

January 5, 2011 2:37 PM
 

Jonathan Kehayias said:

Kirby,

Thank you for pointing that out.  Its been corrected.

January 5, 2011 3:59 PM
Anonymous comments are disabled

This Blog

Syndication

Powered by Community Server (Commercial Edition), by Telligent Systems
  Privacy Statement