如何读懂SQL Server的事务日志

本文将介绍SQL Server的事务日志中记录了哪一些信息，如何来读懂这些事务日志中信息。首先介绍一个微软没有公开的函数fn_dblog，在文章的接下来的部分主要用到这个函数来读取事务日志。

fn_dblog(@StartingLSN,@EndingLSN)

--@StartingLSN:表示起始的LSN号，如果为NULL值则表示从首日志记录开始查询。

--@EndingLSN:表示结束的LSN号，如果为NULL值则表示查询到尾日志记录。

--需要注意的是我们平时所看到的LSN都是十六进制的，而这边的参数需要转化为十进制，如00000021:00000077:0003在作为参数传给fn_dblog时需要转换为33:119:3

正文

--创建测试数据库

USE [master];

GO

CREATE DATABASE TestDB;

GO

-- 创建表

USE TestDB;

GO

CREATE TABLE [Location]
(

[Sr.No] INT IDENTITY,

[Date] DATETIME DEFAULT GETDATE
(),

[City] CHAR (25) DEFAULT 'xiamen');

通过上面的代码创建了一个名为TestDB的数据库，并创建了一个三个字段的表。接下看看事务日志的内容

USE TestDB;

GO

select [Current LSN],

[Operation],

[Transaction Name],

[Transaction ID],

[Transaction SID],

[SPID],

[Begin Time]

FROM fn_dblog(null,null)



从上图可以看出总共产生了195行日志记录，我截取了部分的结果，在Operation列中记录了对应的LSN所做的操作，其中LOP_BEGIN_XACT表示一个事务的开始，Transaction Name显示了创建的数据库的名称，而Trasaction ID则记录了所对应的事务ID。下面列出Operation几种比较常见而重要的值

LOP_BEGIN_XACT 事务的开始
LOP_LOCK_XACT 获取锁
LOP_MODIFY_ROW 修改行(具体修改的对象可以查看AllocUnitName)
LOP_COMMIT_XACT 提交事务
LOP_DELETE_ROWS 删除数据
LOP_INSERT_ROWS 插入数据

接下来向表中插入100行数据，并查看对应的事务日志，代码如下：

INSERT INTO Location DEFAULT VALUES

GO 100

GO

SELECT

[Current LSN],

[Transaction ID],

[Operation],

[Transaction Name],

[CONTEXT],

[AllocUnitName],

[Page ID],

[Slot ID],

[Begin Time],

[End Time],

[Number of Locks],

[Lock Information]

FROM sys.fn_dblog(NULL,NULL)

WHERE Operation
= 'LOP_INSERT_ROWS' AND AllocUnitName
= 'dbo.Location'



得到如上图所示的结果，返回的行数与我们insert的次数一致，接下来取其中的一个Trasaction ID来看看一次insert在事务日志中记录了哪些动作。

SELECT

[Current LSN],
[Transaction ID], [Operation], [Transaction Name],
[CONTEXT], [AllocUnitName], [Page ID], [Slot ID], [Begin Time],
[End Time],
[Number of Locks], [Lock Information]

FROM sys.fn_dblog(NULL,NULL)

WHERE [Transaction ID]
= '0000:000002fc'



从图中可以看出这个Transaction执行步骤的详细信息

在2014/05/25 18:35:39:197事务开始
在堆表dbo.Location的PAGEID为0001:0000004f插入数据
在2014/05/24 18:35:39:200提交事务

下面这一段是我从Lock Information栏位复制出的内容，来详细的看一下

HoBt 72057594039042048:ACQUIRE_LOCK_IX OBJECT: 6:245575913:0 ;ACQUIRE_LOCK_IX PAGE: 6:1:79 ;ACQUIRE_LOCK_X RID: 6:1:79:0

通过下面的代码我们来验证一下，这样一条INSERT语句所获得的锁信息

DBCC TRACEON(-1,3604)

DBCC TRACEON
(-1,1200)--查看当前Session的锁信息

BEGIN TRAN

INSERT INTO Location DEFAULT VALUES

ROLLBACK TRAN

DBCC TRACEOFF
( -1,1200)

DBCC TRACEOFF
( -1,3604)

/*

Process 57 acquiring IX lock on OBJECT: 6:245575913:0 (class bit2000000 ref1) result: OK

Process 57 acquiring IX lock on PAGE: 6:1:79 (class bit2000000 ref0) result: OK

Process 57 acquiring X lock on RID: 6:1:79:90 (class bit2000000 ref0) result: OK

*/

可以看到Lock Information栏位所记录的信息与1200跟踪标记锁输出的信息是一致的。

另外从事务日志中还可以看到SQL Server的一些内部操作，并看到这些操作一些具体信息，如开始的时间，进行的次数，操作的步骤等等。接下来看看页拆分的动作

--查找页拆分动作的Transaction

SELECT

[Current LSN],
[Transaction ID], [Operation], [Transaction Name],
[CONTEXT], [AllocUnitName], [Page ID], [Slot ID], [Begin Time],
[End Time],
[Number of Locks], [Lock Information]

FROM sys.fn_dblog(NULL,NULL)

WHERE [Transaction Name]
= 'SplitPage'

--查看具体Transaction中的动作

SELECT

[Current LSN],
[Transaction ID], [Operation], [Transaction Name],
[CONTEXT], [AllocUnitName], [Page ID], [Slot ID], [Begin Time],
[End Time],
[Number of Locks], [Lock Information]

FROM sys.fn_dblog(NULL,NULL)

WHERE [Transaction ID]
= '0000:000002f8'

结语

通过了解事务日志中所记录的内容，可以更方便我们去了解SQL Server所做的一些操作的执行过程