如何讀懂SQL Server的事務日志

2024-08-31 00:55:41

字體：大中小

來源：轉載

供稿：網友

如何讀懂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
CREATEDATABASE TestDB;
GO
-- 創建表
USE TestDB;
GO
CREATETABLE [Location] (
????[Sr.No] INTIDENTITY,
????[Date] DATETIMEDEFAULT GETDATE (),
????[City] CHAR (25) DEFAULT 'xiamen');

通過上面的代碼創建了一個名為TestDB的數據庫，并創建了一個三個字段的表。接下看看事務日志的內容

USE TestDB;
GO
select [Current LSN],
???????[Operation],
???????[Transaction Name],
???????[Transaction ID],
???????[Transaction SID],
???????[SPID],
???????[BeginTime]
FROMfn_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行數據，并查看對應的事務日志，代碼如下：

INSERTINTO Location DEFAULTVALUES
GO 100
GO
?
SELECT
?[Current LSN],
?[Transaction ID],
?[Operation],
??[Transaction Name],
?[CONTEXT],
?[AllocUnitName],
?[Page ID],
?[Slot ID],
?[BeginTime],
?[EndTime],
?[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], [BeginTime], [EndTime], [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的鎖信息
BEGINTRAN
INSERTINTO Location DEFAULTVALUES
ROLLBACKTRAN
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], [BeginTime], [EndTime], [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], [BeginTime], [EndTime], [Number of Locks], [Lock Information]
FROM sys.fn_dblog(NULL,NULL)
WHERE [Transaction ID] = '0000:000002f8'