如何解读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

相关文章
相关标签/搜索