如何解讀SQL Server日誌(3/3)

如何查看被截斷的日誌

若是數據庫作了日誌備份操做,則日誌會被截斷,而後原來活動的VLF會被重用。使用sys.fn_dblog將會看不到任何被截斷的日誌。那如何查看日誌備份中的日誌呢?使用fn_dump_dblog讀取日誌備份的內容。它的輸出和sys.fn_dblog是同樣的,因此進行查詢過濾時也能夠跟其同樣。javascript

use master
go
backup log logtest to disk='d:\logtest.trn';
go
select [Current LSN], [Operation], [AllocUnitName], [Transaction Name]
    from fn_dump_dblog (
    NULL, NULL, 'DISK', 1, 'D:\logtest.trn',
    DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
    DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
    DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
    DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
    DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
    DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
    DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
    DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT,
    DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT, DEFAULT)
    where  [Transaction ID]='0000:00000367'
go

當[Lock Infomation]的內容無用時

前面咱們使用[Lock Infomation]的內容幫助咱們定位和分析日誌操做,可是若是數據操做沒有單獨鎖定某個行時(e.g.鎖升級和使用表提示鎖定表),則它的內容對咱們的幫助就不多了。java

delete top(1) from demotable with (tablockx);

select [Current LSN], [Operation], [Transaction ID],
    [AllocUnitName], [Page ID], [Slot ID], [Lock Information]
    from fn_dblog(null, null)
where [transaction id]='0000:0000036a'

DELETED

上面的刪除使用tablockx表提示,使得刪除是直接對錶使用X鎖,而不是行鎖。這樣在[Lock Information]就沒有包含鍵鎖的HASH值(Lockres)。如圖,咱們如今能獲取到Page ID、Slot ID和Object ID,可是不能定位到行。數據庫

可是日誌的有效工做負載仍是包含了全部的內容,所以能夠經過搜索[Log Record]或者 [RowLog Contents 0~5] 來找到具體的行。服務器

最小化日誌操做也會讓查找日誌變得更困難。最小化日誌操做的日誌內容只掃描了某個頁包含了最小華日誌操做,SQL Server必需保證它在事務提交前被刷新到磁盤。在相關日誌中只看到LOP_FORMAT_PAGE操做及其操做(最小化日誌操做)的Page ID。最小化日誌只有INSERT、blob .WRITE和WRITETEXT/UPDATETEXT操做,其它的操做都會完整記錄日誌,這樣分析日誌要分析的內容就少了不少。有一種狀況會增長操做的日誌量:更新事務複製中的發佈表的數據。markdown

實踐時的注意事項

本文的例子的日誌量很是少,搜索起來也很快。在真實環境中可能要透過數百萬行日誌才能找到所須要的日誌記錄,固然會很慢。最好將sys.fn_dblog返回的日誌行先存到表中,而後創建須要的索引,這樣查詢時會快不少。使用sys.fn_dblog時若是能傳入開始和結束的LSN,也會讓其它返回速度快一些。注意,若是傳入不正確的LSN給sys.fn_dblog,則會致使服務器內核轉儲( server core dump ),在生產環境這會致使SQL Server僵死一下子。async

DDL 修改

分析DDL修改的思路跟分析數據修改的同樣。數據庫對象是存儲於一個或多個系統表中的數據,全部DDL修改最終會經過修改系統表的數據而完成。這樣會讓全部的DDL修改在分析日誌時看起來差很少,例如LOP_INSER_ROWS操做插入數據到sys.syschhobjs,它多是CREATE TABLE,也多是CREATE VIEW或者CREATE PROC,甚至CREATE TABLE foo和CREATE TABLE bar的日誌看起來是同樣的。ide

DDL操做和DML操做二者修改數據時的主要區別在於使用不一樣鎖。DDL使用元數據鎖(Metedata Lock),通常狀況,DDL會以包含Object ID的SCH_M鎖開始。post

另外,分析日誌中DDL,要與特定的版本和更新相匹配。不一樣的版本、SP甚至CU,元數據表和元數據表結構可能會不一樣。ui

利用OBJECT ID

找出某個對象的DDL具體操做的最好方法是經過找出在對象上請求SCH_M鎖的事務。先經過OBJECT_ID()得對象的ID,而後在[Lock Information]列中匹配搜索模式N'%SCH%%'獲得事務。經過事務再找到全部相關的操做日誌。

--executed 2 DDLs: CREATE and ALTER
create table xx(id int ,val nchar(10));
insert into xx values(1,'A'),(2,'B')
alter table xx 
 alter column val nchar(20);
go
select OBJECT_ID('xx')
-- returned 293576084
go
select [Current LSN], Operation, [Lock Information], [Transaction ID], [Description] 
from sys.fn_dblog(null,null)
where [Lock Information] like N'%SCH%293576084%'
go

Current LSN              Operation             Lock Information                   Transaction ID      Description
-----------              ------------    ----------------------------------------------     --------------    -------------
00000023:000000a9:0002  LOP_LOCK_XACT   HoBt 0:ACQUIRE_LOCK_SCH_M OBJECT: 7:293576084:0    0000:0000036b                 
00000023:000000b7:0002  LOP_LOCK_XACT   HoBt 0:ACQUIRE_LOCK_SCH_M OBJECT: 7:293576084:0       0000:00000370

返回兩個事務,咱們逐一查看。

select [Current LSN], Operation, [AllocUnitName], [Lock Information], [Transaction ID], 
    [Description], [Begin Time], [Transaction Name], [Transaction SID]
from fn_dblog(null, null) 
    where [Transaction ID] = N'0000:0000036b';

DDL1

從第一行LOP_BEGIN_XACT事務開始,在Description和Transaction Name看到CREATE TABLE,還有Begin Time,而後還有Transaction SID。由這些信息咱們能夠知道:誰何時建立了這個表。

餘下的行結合System Base Tables能夠解讀出其含義:

  • LOP_INSERT_ROWS 插入 sys.sysschobjs
    這個操做是向sys.objects插入數據行。有4個LOP_INSERT_ROWS操做是由於sys.sysschobjs表有1個彙集索引和3個非彙集索引。

  • LOP_INSERT_ROWS 插入 sys.syscolpars
    這個操做向sys.columns插入2行數據。每個插入操做有2條記錄,分別爲sys.syscolpars上的彙集索引和非彙集索引。

  • LOP_INSERT_ROWS 插入 sys.sysidxstats
    插入數據到sys.indexes。

  • LOP_INSERT_ROWS 插入 sys.sysiscols
    插入數據到sys.index_columns。

經過上面的分析,雖然沒有獲得具體的DDL語句,可是咱們知道一些很是有用的信息:在2016/08/22 17:13:47:667 建立的表,表中有2列。若是咱們進一步解析rowlog contents和log content還能知道列名。例子中的CREATE語句很是簡單,若是是複雜的CREATE語句,會生成不少的日誌記錄。好比對錶進行分區,則會增長不少LOP_INSERT_ROWS記錄,由於每一個分區必須往sys.sysrowstes添加行,分區上的每個列和索引都必須被記錄在sys.sysrscols中。而這些操做都須要在低級別的HoBT元數被插入前完成。

再來看看另外一個事務:

select [Current LSN], Operation, [AllocUnitName],[Lock Information], [Transaction ID], 
    [Description], [Begin Time], [Transaction Name], [Transaction SID]
from fn_dblog(null, null) 
    where [Transaction ID] = N'0000:00000370'

DDL2

從上面的日誌能夠看到這是個ALTER TABLE操做,而且操做是一個堆表,也能知道操做時間和SID。經過LOP_MODIFY_COLUMNS操做,知道這是修改列屬性的操做。

查找被刪除對象的OBJECT ID

對象被刪除後,就沒有辦法根據OBEJCT ID去找相關日誌了。可是咱們知道刪除對象本質上從sys.sysschobjs刪除數據,因此搜索sys.sysschobjs的LOP_DELETE_ROWS操做。咱們還知道操做的分配單元是sys.sysschobjs.clst。同時,被刪除對象的名字確定存在於Log Contents中的。

drop table xx;
go
select [Current LSN], Operation, [AllocUnitName], [Lock Information], [Transaction ID], 
    [Description], [Begin Time], [Transaction Name], [Transaction SID]
from fn_dblog(null, null) 
    where [Operation] = N'LOP_DELETE_ROWS'
    and [AllocUnitName] = N'sys.sysschobjs.clst'
    and CHARINDEX(cast(N'xx' as varbinary(4000)), [Log Record]) > 0;

DDL3

根據找到的事務ID,去找到相關的日誌記錄:

select [Current LSN], Operation, [AllocUnitName], [Lock Information], [Transaction ID], 
    [Description], [Begin Time], [Transaction Name], [Transaction SID]
from fn_dblog(null, null) 
    where [Transaction ID] = N'0000:00000371';

DDL4

從上在的日誌很容易就知道誰何時刪除的。注意在LOP_BEGIN_XACT後的LOP_LOCK_XACT,在它的鎖信息裏有被刪除對象的OBJECT ID。有了OBJECT ID,咱們就能夠利它進一步的分析日誌。
注意,OBJECT ID是可以被重用的。 因此在使用OBJECT ID分析日誌時,要分辨出它是否被重用了。在日誌中,LSN嚴格按照時間排序的,因此能夠利用之來區分OBEJCT ID的重用。

還要注意CHARINDEX(cast(N'xx' as varbinary(4000)), [Log Record]) > 0,它可能會返回名字中包含‘xx’的其它對象。

分析日誌不是一種常規的和經常使用的技術。同時,它的難度高,也很容易被海量的日誌誤導,因此分析時最好從多個角度,使用多種方法去定位相關的日誌。

文中的例子,我用的SQL Server 2012 - 11.0.5343.0,同時dbo.xx表,我用是一個堆表。這兩個地方致使與原文有較大差別。 BY Joe . TJ

posted @ 2016-08-23 15:22  Joe.TJ 閱讀( ...) 評論( ...) 編輯 收藏
google

相關文章
相關標籤/搜索