Novick Software
SQL Server Consulting Design Programming Tuning

  andy novick is a sql server mvp

 

 

SQL Server T-SQL User-Defined Function of the Week

Volume 1 Number 27         May 20, 2003

Digging into your Log with fn_dblog

Visit the T-SQL UDF of the Week at:
http://www.NovickSoftware.com/UdfOfWeek/UDFofWeek.htm

Check out the UDF Frequently Asked Questions at:
http://www.novicksoftware.com/UdfOfWeek/UDF_FAQ.htm

To ask a UDF related question or to contribute a UDF,
send e-mail to udf@NovickSoftware.com

Sign up for this newsletter at:
http://www.novicksoftware.com/UdfOfWeek/UDFofWeekSignup.htm

If you're on a few SQL e-mail lists then no doubt that you've
received a bunch of s pa m   from Lumigent the purveyors of 
Log Explorer.  I attended a presentation by them recently and
it's an interesting product that captures the SQL Server 
log and stores it in a database.

You can also look at the log with the system UDF fn_dblog.  This
issue takes a look at fn_dblog.

fn_dblog returns a table of records from the transaction log.
The syntax of the call is:

    ::fn_dblog(@StartingLSN, @EndingLSN)
    
@StartingLSN and @EndingLSN are the start and ending
Log Sequence Numbers, also known as an LSN.  A NULL argument for
the Starting LSN requests log records from the beginning of the
transaction log. A NULL value for the ending LSN requests
information to the end of the transaction log.  

To get an idea of what goes into the database log, I backed up 
my Pubs database to clear out the log.  Actually there were a few
records left in, I suppose from open transactions.  Then I ran
a simple update statement that changed one field in one row of 
the Authors table.  Then I ran fn_dblog with NULL arguments 
to see the entire log.  The script and it's results follow:

/------ Start copying below this line --------------------------\
-- Before running this script backup Pubs 
-- Use the Pubs sample database.
USE pubs
GO

-- make a minor change to the database
UPDATE Authors
    SET phone = '978-555-1212' -- New Information line!
    WHERE au_id = '238-95-7766'
GO

SELECT * FROM ::fn_dblog(null, null)
GO
\-------- Stop copying from above this line --------------------/
(Results - 1st group of columns)
Current LSN            Operation              Context            
---------------------- ---------------------- -------------------
0000001b:000001aa:0001 LOP_BEGIN_XACT         LCX_NULL           
0000001b:000001aa:0002 LOP_BEGIN_CKPT         LCX_NULL           
0000001b:000001ab:0001 LOP_XACT_CKPT          LCX_NULL           
0000001b:000001ab:0002 LOP_END_CKPT           LCX_NULL           
0000001b:000001ac:0001 LOP_MODIFY_ROW         LCX_BOOT_PAGE_CKPT 
0000001b:000001ac:0002 LOP_MODIFY_ROW         LCX_BOOT_PAGE_CKPT 
0000001b:000001ac:0003 LOP_FILE_HDR_MODIFY    LCX_FILE_HEADER    
0000001b:000001ae:0001 LOP_COMMIT_XACT        LCX_NULL           
0000001b:000001af:0001 LOP_BEGIN_XACT         LCX_NULL           
0000001b:000001af:0002 LOP_SET_BITS           LCX_DIFF_MAP       
0000001b:000001af:0003 LOP_MODIFY_ROW         LCX_CLUSTERED      
0000001b:000001af:0004 LOP_COMMIT_XACT        LCX_NULL       

(Results - 2nd Group of columns)
Transaction ID Tag Bits Log Record Length Previous LSN          
-------------- -------- ----------------- ----------------------
0000:00000b4e  0x0000                  84 00000000:00000000:0000
0000:00000000  0x0000                  96 0000001b:000001a5:0002
0000:00000000  0x0000                  88 00000000:00000000:0000
0000:00000000  0x0000                 136 0000001b:000001aa:0002
0000:00000000  0x0000                  84 00000000:00000000:0000
0000:00000000  0x0000                  92 00000000:00000000:0000
0000:00000000  0x0000                 448 00000000:00000000:0000
0000:00000b4e  0x0000                  52 0000001b:000001aa:0001
0000:00000b4f  0x0000                  60 00000000:00000000:0000
0000:00000000  0x0000                  56 00000000:00000000:0000
0000:00000b4f  0x0000                 104 0000001b:000001af:0001
0000:00000b4f  0x0000                  52 0000001b:000001af:0001
            
(Results - 3rd Group of Columns with some headers abridged)
 Flag... Object Name              Index... Page ID       Slot ID 
 ------- ------------------------ -------- ------------- ------- 
 0x0200  NULL                     NULL     NULL          NULL    
 0x0000  NULL                     NULL     NULL          NULL    
 0x0000  NULL                     NULL     NULL          NULL    
 0x0000  NULL                     NULL     NULL          NULL    
 0x0000  dbo.ALLOCATION (99)      (0)      0001:00000009       0 
 0x0000  dbo.ALLOCATION (99)      (0)      0001:00000009       0 
 0x0000  dbo.ALLOCATION (99)      (0)      0001:00000000       0 
 0x0200  NULL                     NULL     NULL          NULL    
 0x0200  NULL                     NULL     NULL          NULL    
 0x0000  dbo.ALLOCATION (99)      (0)      0001:00000006       1 
 0x0200  dbo.authors (1977058079) (0)      0001:0000007f       2 
 0x0200  NULL                     NULL     NULL          NULL    

Additional columns have been left out of this newsletter.  The 
entire output of the query is in the file Vol1Num27_fn_dblog.txt
that you can find in the web version of this newsletter. It 
includes all columns and rows shown above.

There's no documentation of the format of a log record in the 
Books-OnLine (BOL) and I haven't been able to locate it anywhere 
else.  However, there are a few obvious items of information in 
the log.  LOP_BEGIN_XACT and LOP_COMMIT_XACT mark the beginning 
and ending of the implicit transaction that surrounds the 
UPDATE statement. The LOP_MODIFY_ROW operation on the object 
dbo.Authors is an update to a single row.  Beyond that, you're
pretty much on your own.  

Now that you know how to use fn_dblog, why would you?  It could
be used to analyze the patters of updates, or the frequency.  
Or you could use it to go back and check on all the updates that
happened to a particular table.  

Most of the issues that I envision resolving with fn_dblog can 
also be resolved with the SQL Profiler.  The difference is that
fn_dblog can look back into the log whereas SQL Profiler can
only capture data while it's running.

That's just the starting point on the functionality that could be
created with this information. From their presentation it 
sounded like Log Explorer takes the opportunity to examine
log information pretty far.  If you're interested, don't worry
you'll be getting e-mail from them pretty soon.  But I didn't
sell your name or address.  I don't do that.

Please share this newsletter with anyone interested in
SQL Server.

+--------------------------------------------------------------+
Do you have a great UDF that you'd like to share?  Or maybe you
have a T-SQL problem that you think could be solved by a UDF
but you don't know how? Send them to:

UDF@NovickSoftware.com 

and they might be published in this newsletter.  I try and 
respond to every request that I get.  

Thanks,  
Andrew Novick
+--------------------------------------------------------------+


RSS as HTML

Personal Blog

 
New Tips:

Use dsinit to set the SQL Server instance for Windows Azure dev storage

Upcoming
Presentations:

SQL PASS
Nov 7, '12
Biggest
Loser: DB
Edition


Full Schedule