日志备份问题一例

前几天, 有个朋友问我一个问题.

他那里有台SQL Server 2005的数据库服务器, 其中一个用户数据库上部署了log shipping, 每半个小时备份一次日志, shipping到另一个服务器上去.

今天他偶然发现这个数据库的日志文件很大, 有40多G, 而且通过 DBCC SQLPERF(LOGSPACE) 看到日志文件的使用率是99%左右. 于是问我, 现在每半小时就备份一次日志,为什么日志文件的使用率还是这么高, 日志文件还是这么大?

我想了想, 有两种可能, 一个是数据库的业务非常繁忙, 每半个小时就要产生40G的日志, 但问了问朋友, 这不太可能, 实际上没有这么多的业务. 另一个原因可能是某个操作使得日志文件中大部分的日志是活动的, 因而不能被备份出来, 导致日志文件很大而且利用率很高.

于是让朋友执行

DBCC OPENTRAN

看看是否有长时间未提交的事务,再执行 

select log_reuse_wait from sys.databases

看看是否有其他的应用阻碍了日志的备份

执行了DBCC OPENTRAN, 果然发现有一个7天前开始的INSERT的事务现在还没有提交, 于是推测极有可能就是这个未提交的事务导致日志的大部分没有备份下来. 他把这个事务kill之后, 下次事务日志的备份文件就很大了, 备份完再查看日志的使用率, 就只有百分之几了.

通过这个例子可以证明, 日志备份的时候, 只会备份那些被标记为'非活动'的日志.  那些未提交的事务的日志是不会备份的, 并且由于事务日志是顺序的写入磁盘文件的, 因此在某个事务开始之后提交之前, 在这段时间内, 日志文件中顺序记录的已提交的事务日志, 也是不会被备份的.

以下通过一个简单的实验验证一下:

--创建一个测试用的数据库
CREATE DATABASE test_log;
USE test_log;
--查看数据库的恢复模式是否是FULL
SELECT DATABASEPROPERTYex('test_log','recovery')
--先做一次完全备份,作为事务备份的基准
BACKUP DATABASE test_log TO DISK = 'c:\test_log.bak'
--创建测试表
CREATE TABLE table1
(col1 INT NOT NULL,
col2 VARCHAR(10))
--查看日志文件
DBCC loginfo 

从结果看出, 现在日志文件有2个VLF, 其中一个是活动的(Status=2), 也就是说如果有日志需要记录的话, 首先会写到这个VLF上, 写满了再写下一个, 再写满了就可能扩展日志文件,生成更多的VLF.

关于DBCC loginfo的返回结果的详细解释,请参考 

http://sqlblog.com/blogs/kalen_delaney/archive/2009/12/21/exploring-the-transaction-log-structure.aspx

接下来插入一些数据, 再看一下日志文件的情况

--插入测试
INSERT INTO table1
SELECT 1,'abcdefg'
go 2000
--再查看日志文件
DBCC loginfo 

可以看到产生了5个VLF, 且Status都是2, 说明这些VLF都是活动的. 也就是说这些VLF上记录的事务日志还没有备份.

--查看日志文件的空间利用率
DBCC SQLPERF(LOGSPACE)

可以看到日志文件中有95%的空间已经被使用

--备份日志
BACKUP  LOG test_log TO DISK = 'c:\log_1.trn'
--再查看日志文件
DBCC loginfo

做过日志备份之后, 可以看到有4个VLF的status是0, 是非活动,可重用状态. 也就是说这4个VLF中的日志内容,已经被写到了日志的备份文件中了.

以上就是正常情况下日志的备份情况, 以下测试一下有长时间未提交的事务的情况.

--在另一个进程中执行以下语句, 只开始事务, 不提交事务
BEGIN TRAN 
INSERT INTO table1
SELECT 1,'abcdefg'

--在当前的进程中执行以下语句,插入数据
INSERT INTO table1
SELECT 1,'abcdefg'
go 2000
--查看日志文件
DBCC loginfo 

--备份日志
BACKUP  LOG test_log TO DISK = 'c:\log_1.trn'

--再查看日志文件
DBCC loginfo 

可以看到结果和刚才没有什么变化,  虽然做了日志备份, 但是还是有4个VLF的status是2, 也就是其中的日志没有备份出来. 

--查看开启最久的事务			
DBCC OPENTRAN

可以看到是SPID 58

DBCC INPUTBUFFER(58)

从返回的结果可以看到, 是刚才在另一个进程中未提交的事务.

将另一个进程中的事务提交,再备份日志, 看一下结果如何:

BACKUP  LOG test_log TO DISK = 'c:\log_1.trn'
DBCC loginfo

可以看到其中有4个VLF的status是0了, 也就是其中的日志记录已经被备份了,且被标记为可重用.

未提交的事务之后的的事务日志不能备份, 是为了让这个未提交的事务可以回滚. 设想如果这些日志可以被备份的话, 那么未提交的事务在回滚的时候, 就很有可能在当前的事务日志文件中找不到需要的日志.