1.3 日志文件不停增长

事务日志文件是一个SQL Server数据库的另一个重要组成部分。每个数据库都有事务日志，用于记录所有事务以及每个事务对数据库所做的修改。为了提高数据库的整体性能，SQL Server检索数据时，将数据页读入缓冲区高速缓存。数据修改不是直接在磁盘上进行，而是修改高速缓存中的页副本。直到数据库中出现检查点，或者必须将修改写入磁盘才能使用缓冲区来容纳新页时，才将修改写入磁盘。将修改后的数据页从高速缓冲存储器写入磁盘的操作称为刷新页。在高速缓存中修改但尚未写入磁盘的页称为“脏页”。

对缓冲区中的页进行修改时，会在日志高速缓存中生成一条日志记录。SQL Server具有防止在写入关联的日志记录前刷新脏页的逻辑。会确保日志记录在提交事务时，或者在此之前，一定已经被写入磁盘。

换句话说，SQL Server对数据页的插入、修改和删除，都是只在内存中完成后，就提交事务。这些修改并不立刻同步到硬盘的数据页上。而SQL Server又必须保证事务的一致性。哪怕发生了SQL Server异常终止（例如SQL Server服务崩溃，机器掉电），内存中的修改没有来得及写入硬盘，下次SQL Server重启的时候，要能够恢复到一个事务一致的时间点。已经提交的修改要在硬盘中的页面重新完成。为了做到这一点，SQL Server必须依赖于事务日志。

因此，任何一个数据库，哪怕是tempdb，都有日志文件。它和数据文件同等重要。如果日志文件缺失或者损坏，将等同于数据库损坏。

在SQL Server的使用过程中，会由于种种原因，出现日志文件大小不停增长的现象。当文件达到最大限值，或者是把硬盘空间全部占用后，数据库就无法再进行任何插入、修改、删除的工作。本节的主题，就是要探讨出现这种现象的原因，以及相应的解决办法。

1.3.1 日志文件里到底有什么

当日志文件大小超过预期的时候，数据库管理员自然会想去看看日志文件中到底存放了些什么信息。SQL Server有一条“DBCC LOG”命令可以帮助我们解释日志文件中的信息。它的语法是：

    DBCC LOG(<db_id>, <formart_id>)

<db_id>：目标数据库编号。可以用sp_helpdb得到。

<format_id>：DBCC LOG命令翻译和解释日志记录的方式。

一般来讲，使用“3”这个格式参数输出比较详细。

下面我们通过一个很简单的表格操作来看看SQL Server是怎么组织事务日志记录的。

首先，我们在范例数据库AdventureWorks里面创建一个只有一个int类型字段的表格。然后将数据库日志文件清空。接着运行DBCC LOG命令。找到这时日志文件的最后一条记录。

    use adventureworks
    go
    create table a (a int)
    go
    checkpoint
    go
    backup log adventureworks with truncate_only
    go dbcc log(5,3)
    -- 5是adventureworks数据库的编号，每个SQL Server可能都不同
    -- 可以用sp_helpdb来查到数据库编号
    go

接着，我们在表格里插入一条记录。

    insert into a values (1)
    go
    dbcc log(5,3)
    go

结果中（见图1-26）可以看到三条关于这个Insert的记录。

图1-26 DBCC LOG结果中3条和INSERT动作相关的记录

我们再插一条记录。

    insert into a values (100)
    go
    dbcc log(5,3)
    go

可以看到新的3条记录（见图1-27）。新的记录有不同的LSN编号。

图1-27 新的3条和INSERT动作相关的记录

从这些记录里，我们可以看到刚才做的INSERT的事务，它的起始时间，刚才连接的SPID，以及其他一些信息。SQL Server完全可以通过这些记录把INSERT重做，或者撤销。

我们把这两条记录都改成2。这次出现了6条记录（见图1-28）。

    update a set a = 2
    go

图1-28 和UPDATE动作相关的6条记录

从这些记录可以看出，虽然只是一条UPDATE语句，但是实际上SQL Server并没有记录语句本身。它记录的是两条被修改的数据原来的值和现在的值。

因此我们可以发现，SQL Server的日志记录有以下特点：

1.日志记录的是数据的变化，而不是记录用户发过来的操作。

在这一点上，日志记录的定位很清楚。它只是为了保证数据库一致性。所以它记录的信息对SQL Server来讲很有意义。但是如果想要通过它来倒推出用户刚才发过来的语句，可以说是不可能的。

2.每条记录都有它唯一的编号（LSN），并且记录了它属于的事务号。

这种设计便于事务的重新提交和回滚。

3.日志记录的行数和实际修改的数据量有关。

SQL Server会为每一条记录的修改保存日志记录。如果单个语句修改的行数非常多，那它所带来的日志行数也就会非常多。所以日志增长的速度不仅和事务的多少有关，还和事务所带来的数据的修改量有关。

4.日志记录了事务发生的时间，但是不保证记录下了发起这个事务的用户名，更不记录发起者的程序名称。

5.SQL Server能够从日志记录里面读到数据修改前的值和修改后的值。但是对管理者来讲，直接从日志记录里面是很难了解其修改过程的。

讨论这些的原因，是因为很多用户希望能从日志文件里倒推出数据库曾经发生的异常操作。比如，是谁恶意或不小心删掉了一些重要数据，或者是谁在某个时间段发起了一个庞大的事务。由于SQL Server日志定位不是做用户行为监视和记录，而是在对性能影响最小的前提下保证事务一致性，所以它记录的内容是面向数据库服务，而不是面向用户的。换句话说，它记录的东西只要SQL Server自己能读懂就可以了，而没有考虑要给用户去访问和理解。所以使用者很难用事务日志来达到倒推的目的。

市场上有一些第三方的工具宣称能从SQL Server的日志文件中完成一些推断工作。他们能够更进一步地解释日志记录，并且做一些自动化的工作（例如，帮助用户回滚一个误操作）。但是如果有什么内容DBCC LOG看不到，这些工具应该也很难看到。所以如果要监视用户的行为，还是要开启SQL Server自己的监视工具，比如SQL Trace或XEvents等。

1.3.2 日志文件增长的原因

前面已经谈到，SQL Server会为所有的修改记录日志，以便将来重新提交或者回滚时使用。那不停地记录，日志文件岂不会空间耗尽？为此，SQL Server设计了相对应的机制，能够定期清理日志文件中不再需要的日志记录。

那哪些日志记录是“不再需要”的呢？我们反过来看，什么是SQL Server“需要”的。SQL Server需要下面这几类日志记录：

1.所有没有经过“检查点”的日志记录。

SQL Server定期做检查点（Checkpoint），保证所有的“脏页”都被写入硬盘。未做检查点的修改，可能仅是内存中的修改。数据文件里还没有同步。SQL Server要硬盘上的日志文件里有一份记录，以便在异常重启后重新修改。

2.所有没有提交的事务所产生的日志记录，以及在它们之后的所有日志记录。

如果一个事务还没有提交，那它可以在任何时候回滚。SQL Server必须做好这种准备，以便能够从日志记录中找回修改前的数据内容，完成回滚。在SQL Server里面，所有的日志记录都有严格顺序，中间不可以有任何跳跃。所以如果某个数据库有没有提交的事务，SQL Server会标记所有从这个事务开始的日志记录（不管和这个事务有没有关系）为活动事务日志。这些日志记录都有可能“需要”被用来做回滚。

3.所有要做备份的日志记录。

如果数据库设的恢复模式不是简单模式，那SQL Server就假设用户是要去备份日志记录的。所有未被备份的记录，SQL Server都会为用户保留，哪怕这些记录对数据库本身已经没有其他用途了。

4.有其他需要读取日志的数据库功能模块。

除了数据库引擎，还有一些功能，比如说，事务型复制（Transactional Replication）和数据库镜像（Database Mirroring）也需要读取日志文件中的内容，完成它们的同步工作。在这些功能组件没有读取日志记录之前，SQL Server也会保留。

对所有“不需要”的日志记录，SQL Server会在每个检查点做一次截断的动作，把这些记录占用的空间标志成可重用。这样这些空间就被释放出来。因为日志文件是循环使用的，只要日志文件里有这样的空间，SQL Server都会去重用，所以不会报告空间已满，或者试图去做自动增长。SQL Server做检查点的频率取决于服务器属性“Recovery Interval”。默认大概一分钟左右做一次检查点。

如果日志文件里“需要”的记录越来越多，那就会出现日志文件不停增长的现象。通常的原因有下面几个。

1.数据库恢复模式不是简单模式，但是没有安排日志备份。

需要强调的是，对于非简单模式的数据库，只有做完日志备份后记录才会被截断。做完整备份和差异备份都不会起这个作用。

2.数据库上面有一个很长时间都没有提交的事务。

由于应用程序设计的问题，有些连接可能会遗留一个事务在SQL Server里面，而不是及时提交了它。SQL Server是不会干预用户的这种行为的。只要这个连接不退出，这个事务就会永远存在，直到客户端主动提交或者回滚它。而从这个事务开启的那个时间点开始的所有日志记录，SQL Server都会保留。（做过日志备份也没有用。）

3.数据库上有一个很大的事务正在运行。

例如，某个用户正在建立/重建索引，或者用DELETE/INSERT语句删除或插入大量数据等。或者用户端开了一个服务器端游标，但是没有把数据及时取走等。

4.数据库复制或者镜像出了异常。

要避免日志文件不停增长，其实就是要避免上面这些情况的发生。对于一个最近不会去做日志备份的数据库，设成简单恢复模式即可。如果数据库设成了完整恢复模式，那就一定要安排定期做日志备份。如复制或镜像任务出问题，要及时解决。如果没办法解决，就必须暂时拆除复制或镜像，以防止日志记录越积越多，最终造成数据库不可使用。在设计程序的时候，也要避免事务时间过长，一个事务做太多的操作。数据库晚上或周末会做一些维护工作，例如历史数据清洗整理，数据导入导出，索引重建等。这些操作都可能写许多日志，所以要为它们预留出足够的空间，并且在做完之后及时备份。

1.3.3 案例：日志增长原因定位

当日志文件增长到很大时，可以采取一些临时手段，比如把有未关闭事务的连接强制取消，或者截断数据库的事务。但是，管理者必须找到日志增长的原因，从而从根本上解决问题。

让我们来练习一下如何定位日志增长的原因。

步骤1：检查日志现在使用情况和数据库状态

首先要检查当前日志的使用百分比、数据库恢复模式和日志重用等待状态。和SQL Server 2000不同的是，SQL Server 2005在管理视图sys.databases里面加入了一列log_reuse_wait（log_reuse_wait_desc）以反映SQL Server认为的，不能截断日志的原因。可能的状态如表1-6所示。

表1-6 log_reuse_wait（log_reuse_wait_desc）的可能状态

检查脚本很简单：

    DBCC SQLPERF(LOGSPACE)
    GO
    SELECT name, recovery_model_desc, log_reuse_wait,log_reuse_wait_desc
    FROM sys.databases
    GO

检查结果如图1-29所示。

如果当前日志的绝大部分都在使用中（Log Space Used (%)很高），那就要马上定位是什么原因导致了日志记录不能被SQL Server清除掉。如果当前日志的大部分都已经处于空闲状态了，那就说明触发日志增长的因素已经暂时消失。数据库现在的状态是正常的。如果问题反复发生，可能就要想办法跟踪SQL Server内部运行的操作，直到抓住问题再次发生。

如果数据库的日志重用等待状态是LOG_BACKUP，那就意味着SQL Server在等待着日志备份。这时需要检查备份计划，是否需要做日志备份。如果用户并不期望做日志备份，那就可以直接把恢复模式改成简单。这样SQL Server会在下一个检查点的时候做日志记录截断的工作。等到以后要安排日志备份任务的时候，再把恢复模式改回来。

图1-29 检查数据库日志不能TRUNCATE的直接原因

步骤2：检查最老的活动事务

如果日志的大部分都在使用中，而且日志重用等待状态是ACTIVE_TRANSACTION，那么就要看这个数据库最久未提交的事务到底是由谁申请的。这就要用如下的命令。

    DBCC OPENTRAN
    GO
    SELECT st.text,t2.*
    FROM sys.dm_exec_sessions AS t2, sys.dm_exec_connections AS t1
    CROSS APPLY sys.dm_exec_sql_text(t1.most_recent_sql_handle) AS st
    WHERE t1.session_id = t2.session_id
    AND t1.session_id >50

DBCC OPENTRAN返回的是当前数据库最久未被提交的事务。

    Transaction information for database 'AdventureWorks'.
    Oldest active transaction:
    SPID (server process ID): 52
    UID (user ID) : -1
    Name         : user_transaction
    LSN          : (128:2474:11)
    Start time   : Dec  7 2008  9:49:11:607PM
    SID          : 0x010500000000000515000000bf093097412261f57d0f2a7ded030000
    DBCC execution completed. If DBCC printed error messages, contact your system
    administrator.

从上面的结果可以知道，这个事务是在Dec 7 2008 9:49:11:607PM开始的，是被SPID 52这个连接申请的。

从第二个查询的结果（如图1-30所示）可以知道这个连接是由什么程序建立的，以及这个连接最后发过来的一句命令的内容。

图1-30 第二句查询的结果

知道了连接是谁建立的，也知道了它正在跑什么，管理员就可以联系连接所属应用程序的拥有者，了解为何事务没能及时提交，以及是否现在可以暂时终止这个事务。比较安全的方法是找到那个程序，从客户端提交或取消这个事务（比如，暂时终止这个用户正在进行的操作）。如果来不及或者一时找不到，可以在SQL Server端用KILL命令尝试关闭这个连接。例如：

    KILL 52

如果52这个连接还想运行任何命令，它会收到类似于下面的这个报错。告知连接已经被断掉了。

    Msg 233, Level 20, State 0, Line 0
    A transport-level error has occurred when sending the request to the server.
    (provider: Shared Memory Provider, error: 0 - No process is on the other end of
    the pipe.)

这时如果再运行DBCC OPENTRAN，命令会返回下一个最久未提交的事务，直到所有的事务都被提交或回滚完毕为止。

需要说明的是，KILL命令并不是百试不爽的。如果一个连接正处于提交或者回滚的过程中，SQL Server会尊重它的执行而不去强行终止它。而如果需要终止的这个连接所开启的事务非常庞大，比如，它正在做一个几百万条数据的修改或删除动作，那么取消掉这个动作而产生的回滚时间，可能不会比它的运行时间要短。有时候可能会等很久这个连接也终止不掉。所以这个方法只能在应急的时候尝试使用。要从根本上解决问题，还是要改变客户端的行为，避免这种事件的发生。