1.3  日誌檔案不停增長

事務日誌檔案是一個SQL Server資料庫的另一個重要組成部分。每個資料庫都有事務日誌，用於記錄所有事務以及每個事務對資料庫所做的修改。為了提高資料庫的整體效能，SQL Server檢索資料時，將資料頁讀入緩衝區快取記憶體。資料修改不是直接在磁碟上進行，而是修改快取記憶體中的頁副本。直到資料庫中出現檢查點，或者必須將修改寫入磁碟才能使用緩衝區來容納新頁時，才將修改寫入磁碟。將修改後的資料頁從高速緩衝儲存器寫入磁碟的操作稱為重新整理頁。在快取記憶體中修改但尚未寫入磁碟的頁稱為"髒頁"。

對緩衝區中的頁進行修改時，會在日誌快取記憶體中生成一條日誌記錄。SQL Server具有防止在寫入關聯的日誌記錄前重新整理髒頁的邏輯。會確保日誌記錄在提交事務時，或者在此之前，一定已經被寫入磁碟。

換句話說，SQL Server對資料頁的插入、修改和刪除，都是隻在記憶體中完成後，就提交事務。這些修改並不立刻同步到硬碟的資料頁上。而SQL Server又必須保證事務的一致性。哪怕發生了SQL Server異常終止（例如SQL Server服務崩潰，機器掉電），記憶體中的修改沒有來得及寫入硬碟，下次SQL Server重啟的時候，要能夠恢復到一個事務一致的時間點。已經提交的修改要在硬碟中的頁面重新完成。為了做到這一點，SQL Server必須依賴於事務日誌。

因此，任何一個數據庫，哪怕是tempdb，都有日誌檔案。它和資料檔案同等重要。如果日誌檔案缺失或者損壞，將等同於資料庫損壞。

在SQL Server的使用過程中，會由於種種原因，出現日誌檔案大小不停增長的現象。當檔案達到最大限值，或者是把硬碟空間全部佔用後，資料庫就無法再進行任何插入、修改、刪除的工作。本節的主題，就是要探討出現這種現象的原因，以及相應的解決辦法。

當日志文件大小超過預期的時候，資料庫管理員自然會想去看看日誌檔案中到底存放了些什麼資訊。SQL Server有一條"DBCC LOG"命令可以幫助我們解釋日誌檔案中的資訊。它的語法是：

1. DBCC LOG(, ) 

：目標資料庫編號。可以用sp_helpdb得到。

：DBCC LOG命令翻譯和解釋日誌記錄的方式。

一般來講，使用"3"這個格式引數輸出比較詳細。

下面我們通過一個很簡單的表格操作來看看SQL Server是怎麼組織事務日誌記錄的。

首先，我們在範例資料庫AdventureWorks裡面建立一個只有一個int型別欄位的表格。然後將資料庫日誌檔案清空。接著執行DBCC LOG命令。找到這時日誌檔案的最後一條記錄。

1. use adventureworks  
2. go  
3. createtable a (a int)  
4. go  
5. checkpoint
6. go  
7. backup log adventureworks withtruncateonly
8. go  
9. dbcc log(5,3)  
10. -- 5是adventureworks資料庫的編號，每個SQL Server可能都不同
11. -- 可以用sp helpdb來查到資料庫編號
12. go  
13. 接著，我們在表格裡插入一條記錄。  
14. insertinto a values (1)  
15. go  
16. dbcc log(5,3)  
17. go 

結果中（見圖1-26）可以看到三條關於這個Insert的記錄。

圖1-26  DBCC LOG結果中3條和INSERT動作相關的記錄

我們再插一條記錄。

1. insertinto a values (100)  
2. go  
3. dbcc log(5,3)  
4. go 

可以看到新的3條記錄（見圖1-27）。新的記錄有不同的LSN編號。

圖1-27  新的3條和INSERT動作相關的記錄

從這些記錄裡，我們可以看到剛才做的INSERT的事務，它的起始時間，剛才連線的SPID，以及其他一些資訊。SQL Server完全可以通過這些記錄把INSERT重做，或者撤銷。

我們把這兩條記錄都改成2。這次出現了6條記錄（見圖1-28）。

1. update a set a = 2  
2. go 

圖1-28  和UPDATE動作相關的6條記錄

從這些記錄可以看出，雖然只是一條UPDATE語句，但是實際上SQL Server並沒有記錄語句本身。它記錄的是兩條被修改的資料原來的值和現在的值。

因此我們可以發現，SQL Server的日誌記錄有以下特點：

1. 日誌記錄的是資料的變化，而不是記錄使用者發過來的操作。

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）的可能狀態

檢查指令碼很簡單：

1. DBCC SQLPERF(LOGSPACE)  
2. GO  
3. SELECTname, recovery model desc, log reuse wait,log reuse wait desc
4. FROM sys.databases  
5. GO 

檢查結果如圖1-29所示。

如果當前日誌的絕大部分都在使用中（Log Space Used (%)很高），那就要馬上定位是什麼原因導致了日誌記錄不能被SQL Server清除掉。如果當前日誌的大部分都已經處於空閒狀態了，那就說明觸發日誌增長的因素已經暫時消失。資料庫現在的狀態是正常的。如果問題反覆發生，可能就要想辦法跟蹤SQL Server內部執行的操作，直到抓住問題再次發生。

如果資料庫的日誌重用等待狀態是LOG_BACKUP，那就意味著SQL Server在等待著日誌備份。這時需要檢查備份計劃，是否需要做日誌備份。如果使用者並不期望做日誌備份，那就可以直接把恢復模式改成簡單。這樣SQL Server會在下一個檢查點的時候做日誌記錄截斷的工作。等到以後要安排日誌備份任務的時候，再把恢復模式改回來。

圖1-29  檢查資料庫日誌不能TRUNCATE的直接原因

步驟2：檢查最老的活動事務

如果日誌的大部分都在使用中，而且日誌重用等待狀態是ACTIVE_TRANSACTION，那麼就要看這個資料庫最久未提交的事務到底是由誰申請的。這就要用如下的命令。

1. DBCC OPENTRAN  
2. GO  
3. SELECT st.text,t2.*                                                           
4. FROM sys.dm exec sessions AS t2, sys.dm exec connections AS t1  
5. CROSS APPLY sys.dm exec sql text  
6.         (t1.most recent sql handle) AS st   
7. WHERE t1.session id = t2.session id  
8. AND t1.session id >50     
9. DBCC OPENTRAN返回的是當前資料庫最久未被提交的事務。  
10. Transaction information fordatabase'AdventureWorks'.  
11. Oldest active transaction:  
12.     SPID (server process ID): 52  
13.     UID (user ID) : -1  
14. Name          : usertransaction
15.     LSN           : (128:2474:11)  
16.     Start time    : Dec  7 2008  9:49:11:607PM  
17.     SID           :   
18.     0x010500000000000515000000bf093097412261f57d0f2a7ded030000  
19. DBCC execution completed. If DBCC printed error messages,   
20. 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會尊重它的執行而不去強行終止它。而如果需要終止的這個連線所開啟的事務非常龐大，比如，它正在做一個幾百萬條資料的修改或刪除動作，那麼取消掉這個動作而產生的回滾時間，可能不會比它的執行時間要短。有時候可能會等很久這個連線也終止不掉。所以這個方法只能在應急的時候嘗試使用。要從根本上解決問題，還是要改變客戶端的行為，避免這種事件的發生。

在這一點上，日誌記錄的定位很清楚。它只是為了保證資料庫一致性。所以它記錄的資訊對SQL Server來講很有意義。但是如果想要通過它來倒推出使用者剛才發過來的語句，可以說是不可能的。

2. 每條記錄都有它唯一的編號（LSN），並且記錄了它屬於的事務號。

這種設計便於事務的重新提交和回滾。

3. 日誌記錄的行數和實際修改的資料量有關。

SQL Server會為每一條記錄的修改儲存日誌記錄。如果單個語句修改的行數非常多，那它所帶來的日誌行數也就會非常多。所以日誌增長的速度不僅和事務的多少有關，還和事務所帶來的資料的修改量有關。

4. 日誌記錄了事務發生的時間，但是不保證記錄下了發起這個事務的使用者名稱，更不記錄發起者的程式名稱。

5. SQL Server能夠從日誌記錄裡面讀到資料修改前的值和修改後的值。但是對管理者來講，直接從日誌記錄裡面是很難了解其修改過程的。

討論這些的原因，是因為很多使用者希望能從日誌檔案裡倒推出資料庫曾經發生的異常操作。比如，是誰惡意或不小心刪掉了一些重要資料，或者是誰在某個時間段發起了一個龐大的事務。由於SQL Server日誌定位不是做使用者行為監視和記錄，而是在對效能影響最小的前提下保證事務一致性，所以它記錄的內容是面向資料庫服務，而不是面向使用者的。換句話說，它記錄的東西只要SQL Server自己能讀懂就可以了，而沒有考慮要給使用者去訪問和理解。所以使用者很難用事務日誌來達到倒推的目的。

市場上有一些第三方的工具宣稱能從SQL Server的日誌檔案中完成一些推斷工作。他們能夠更進一步地解釋日誌記錄，並且做一些自動化的工作（例如，幫助使用者回滾一個誤操作）。但是如果有什麼內容DBCC LOG看不到，這些工具應該也很難看到。所以如果要監視使用者的行為，還是要開啟SQL Server自己的監視工具，比如SQL Trace或XEvents等。