近期總有開發同事過來抱怨說有寫執行超時，但是查看相關語句又沒有任何問題，統計正常，執行計劃合理，IO壓力較低，鎖也正常，正常5ms可以結束的SQL竟然超時，不可思議，但由于超時的時間和頻率不固定，我們很難捕捉到超時的時間點上服務器的狀態，肖磊同志明銳地發現該數據庫日志日志已暴漲至200+GB，于是慢慢折騰路開始。。。

--===========================================================

首先出場的是肖桑，我在旁圍觀，當我們發現日志暴漲這么大的時候，第一時間檢查日志的使用情況

首先查看日志的大小和使用情況

DBCC SQLPERF(LOGSPACE)

發現日志文件超過200GB,日志使用率為99%，也就是說大部分是活動日志

肖桑作為DBR,自然優先考慮

DBCC LOGINFO

DBCC LOGINFO顯示數據庫日志文件有1.6W，幾乎全部處于活躍狀態（status=2）（上圖只是示例）

不知道肖桑有沒有運行查看過日志等待狀態，反正我當時沒查

--查看日志等待狀態SELECT DB.name,DB.log_reuse_wait_desc FROM SYS.databases DB

由于我們經常遇到鏡像阻塞復制或者鏡像問題導致日志增大的情況，而問題數據庫恰好配置為鏡像，顯示狀態為正在同步，SO，我們做了一個艱難的決定--取消鏡像

這應該算一個輕率的決定，正常情況即使確定是鏡像問題，我們仍需要確定什么導致鏡像出現問題（如何檢查請參考http://www.cnblogs.com/TeyGao/p/3521677.html）以及尋找最佳解決辦法，或許是由于重做鏡像太過簡單，我們就輕易地選擇了移除鏡像。

鏡像移除后，我們查看復制情況

--=================================================--為每個發布數據庫返回有關滯后時間、吞吐量和事務計數的復制統計信息。 --此存儲過程在發布服務器的任何數據庫中執行。--http://msdn.microsoft.com/ZH-CN/library/ms190486.aspxEXEC SP_REPLCOUNTERS

結果我們驚奇地發現：

日志中等待傳送到分發數據庫的事務數（Replicated transactions）：12000W+

平均每秒傳送到分發數據庫的事務數(Replication rate trans/sec): 7000+

我們做了一個簡單的運算：SELECT 120000000.0/7000/60/60=5，考慮Replication rate trans/sec的值上下波動，我們將預估時間定位4到6個小時，這個時間還在我們接受范圍內，于是乎，我們選擇了等待。。。

隨著時間的飛逝（當年常用的可是白馬過隙）,Replication rate trans/sec的值逐漸從7000+減低到4000+再到700+然后到400+，我們的預估時間變成2-4天，很恐怖的一個數字??！

由于我們之前已經定位到vlf為數量過多，而我們潛在認為這既是影響復制的問題，所以我們沒有做過多的分析便坐等復制正常，直到預估時間超過我們接受范圍，此時時間距離問題發現已經過去一天多。

由于復制恢復時間超出我們預期，而且訂閱對整個業務的重要性很低，可以先移除再重做，為不影響業務，我們選擇移除訂閱，為謹慎起見，我們沒有直接刪除訂閱，而是選擇修改訂閱的存儲過程，我們認為注釋掉存儲過程中的代碼，也可以達到移除訂閱類似的目的，避免訂閱運行復制命令所產生的消耗，于是我們發動同事一起修改相關的付復制存儲過程。

當我們費了九牛二虎之力把存儲過程修改完以后，發現沒有任何幫助（好悲催的趕腳）

本著生命在于折騰的精神，我開始分析傳送事務越來越慢的原因，優先是檢查磁盤，由于發布分發和訂閱使用的都是IO卡，雖然在訂閱上能捕獲到一些寫日志等待，但是還在接受范圍內，于是我開始檢查是否因為大事務導致復制問題。

--===============================================================--在分發庫上查找大事務USE distributionGOSELECT xact_seqno, COUNT(*) AS [COUNT] INTO #MSrepl_commands FROM dbo.MSrepl_commandsGROUP BY xact_seqnoHAVING COUNT(*)>100SELECT t.xact_seqno,t.entry_time,c.[count] FROM MSrepl_Transactions t INNER JOIN#MSrepl_commands c ON t.xact_seqno=c.xact_seqnoORDER BY c.count DESC,t.entry_time

天佑我大中華，我順利抵捕獲到一個包含120w命令的大事務(另外一個發布庫上的發布，但是與問題發布庫使用相同的分發庫和訂閱庫)，于是乎，全世界的目光集中在這個大事務上，各種炮火對準，在確定相關影響后，我們快刀斬亂碼，直接將那個復制干掉了。

我們悲哀地發現，以上操作都對Replication rate trans/sec沒有任何影響，就好比北京到西藏的車流很慢，我們就把西藏到北京北京周邊的路修成十車道的高速路，結果悲催發現車都堵在三環路上一樣。

問題還在發布庫上，我們要解決日志過大問題，要么等復制相關事務從日志被讀取到分發庫，要么刪除復制，前者太慢不可取，只能選擇刪除復制，又是一個手起刀落，復制被干掉了。。。

正準備高唱“解放區的天是藍藍的天”的時候，心急的同事已經忙著備份日志收縮數據庫了，結果悲催地發現，備份收縮無效，使用EXEC SP_REPLCOUNTERS依然發現還有大量等待傳送的事務已經慢的可憐的傳說速度。。。

一定是我們打開方式不對，一定是的。。。

查看日志等待狀態，小伙伴們驚奇發現，日志等待狀態依然是復制，這是為什么呢？

經過仔細分析，CDC成為焦點，有業務需要依據CDC的變更記錄來同步數據到Oracle數據庫，ORACLE的同事很傲嬌地告訴我們，他們程序運行正常，沒有問題，數據已同步。。。

當我們差點要忽略CDC的時候，作死的我還是逼著同事檢查了一遍，因為復制和CDC是共用一個logreader,既然復制延遲了好幾天，沒道理CDC正常同步??！

果不其然，CDC大有問題，大概了解的結果是有個應用程序會讀取CDC相關的數據到ORACLE數據庫，其中一個表出了問題，導致程序沒有正常運行，然后就阻塞了CDC，EXEC SP_REPLCOUNTERS顯示的就是CDC的相關信息，只是被打上了復制的旗號，于是乎CSC成了擋在我們前面的絆腳石，帶著佛擋殺佛人擋殺人的氣勢，反正我們相繼滅殺了“鏡像”和“復制”這兩大令日志暴漲的罪惡之手，也不在乎在多滅殺一個CDC，果斷再次手起刀落，整個數據庫級別禁用CDC.

終于，世界清靜了，日志文件的使用率也有原來的99%降低到1%，在經過幾次日志備份和收縮，日志文件又恢復到正常大小，正義戰勝了邪惡，七個小矮人和白雪公主又過上了幸福美滿的生活，世界和平是如此的美好。。。

--========================================================

在整個處理過程中，我們急于求成到心理導致出現了很多問題，由于想著盡快解決問題，以及一定的自負心理（各位同事不要打我），讓我們將沒有經過太多的理論分析操作直接在生產服務器上運行，盡管我們在操作前已經評估這些操作帶來的影響，卻沒有仔細評估這些操作是否能帶來我們期望的結果，因此導致我們做了很多的無用功和浪費了很多寶貴時間，所幸所有影響都在可控和可接受范圍內

PS:以上總結值得很多DBA同仁的引以為戒

--=======================================================

夜深了，你看妹子都趴著想睡覺了