出自: http://blogs.msdn.com/b/apgcdsd/archive/2011/11/21/ring-buffer-sql-server-2008.aspx
SQL Server 2008 中包含一個新功能,旨在幫助解決特別棘手的連接問題。這個新功能是 Connectivity Ring Buffer ,它可以捕捉每一個由服務器發起的連接關閉記錄 (server-initiated connection closure) ,包括每一個 session 或登錄失敗事件。為了進行有效的故障排除, Ring Buffer 會嘗試提供客戶端的故障和服務器的關閉動作之間的關系信息。只要服務器在線 ,? 最高 1K 的 Ring Buffer 就會被保存, 1000 條記錄后, Buffer 開始循環覆蓋,即從最老的記錄開始覆蓋。 Connectivity Ring Buffer 的記錄是能夠使用 DMV 查詢的:
?
SELECT
?
CAST
(
record?
AS
?
XML
)
?
FROM
?
sys
.
dm_os_ring_buffers
WHERE
?ring_buffer_type
?
=
?
'RING_BUFFER_CONNECTIVITY'
?
上述指令會選擇所有記錄為 XML 類型 ; 在 Management Studio 中 , 你可以單擊記錄 , 從而獲得更具可讀性的版本。如果你想使用 SQL 查詢 XML 記錄從而找到相應的問題 , 你可以使用 SQL server 的 XML? 支持 , 將之變為一個臨時的表 , 從而查詢記錄。
?
一個基本的Buffer entry:Killed SPID
一個導致服務器發起的連接關閉的簡單方法是打開兩個 SQL 服務器的連接,找到一個連接的 SPID ,然后從另一個連接中將該 SPID 殺死。
C:\>osql -E
1> SELECT @@spid
2> go
------
51
(1 row affected)
C:\>osql -E
1> kill 51
2> go
1>
如果你做了上述工作,然后查詢
Ring Buffer
,你會得到和如下類似的結果:
< Record ? id = " 2 " ? type = " RING_BUFFER_CONNECTIVITY " ? time = " 110448275 " >
< ConnectivityTraceRecord >
< RecordType > ConnectionClose </ RecordType >
< RecordSource > Tds </ RecordSource >
< Spid > 55 </ Spid >
< SniConnectionId > B7882F3C-3BA9-45A7-8D23-3C5C05F9BDF9 </ SniConnectionId >
< SniProvider > 4 </ SniProvider >
< RemoteHost > < local ?machine > ; </ RemoteHost >
< RemotePort > 0 </ RemotePort >
< LocalHost ?/>
< LocalPort > 0 </ LocalPort >
< RecordTime > 5/6/2008 22:47:35.880 </ RecordTime >
< TdsBuffersInformation >
< TdsInputBufferError > 0 </ TdsInputBufferError >
< TdsOutputBufferError > 0 </ TdsOutputBufferError >
< TdsInputBufferBytes > 60 </ TdsInputBufferBytes >
</ TdsBuffersInformation >
< TdsDisconnectFlags >
< PhysicalConnectionIsKilled > 0 </ PhysicalConnectionIsKilled >
< DisconnectDueToReadError > 0 </ DisconnectDueToReadError >
< NetworkErrorFoundInInputStream > 0 </ NetworkErrorFoundInInputStream >
< ErrorFoundBeforeLogin > 0 </ ErrorFoundBeforeLogin >
< SessionIsKilled > 1 </ SessionIsKilled >
< NormalDisconnect > 0 </ NormalDisconnect >
< NormalLogout > 0 </ NormalLogout >
</ TdsDisconnectFlags >
</ ConnectivityTraceRecord >
< Stack >
< frame ? id = " 0 " > 0X01CA0B00 </ frame >
< frame ? id = " 1 " > 0X01CA0DB1 </ frame >
< frame ? id = " 2 " > 0X01DF6162 </ frame >
< frame ? id = " 3 " > 0X02E53C98 </ frame >
< frame ? id = " 4 " > 0X02E54845 </ frame >
< frame ? id = " 5 " > 0X02E57BE9 </ frame >
< frame ? id = " 6 " > 0X02E38F57 </ frame >
< frame ? id = " 7 " > 0X02E3B2C0 </ frame >
< frame ? id = " 8 " > 0X02E3C832 </ frame >
< frame ? id = " 9 " > 0X02E3D55E </ frame >
< frame ? id = " 10 " > 0X781329BB </ frame >
< frame ? id = " 11 " > 0X78132A47 </ frame >
</ Stack >
</ Record >
不同的記錄類型包括不同的信息。 Connectivity Ring Buffer? 記錄的三種記錄類型分別是: ConnectionClose , Error ,和 LoginTimers 。上面的結果是一個 ConnectionClose ,因為這不是一個登陸時超時,或者其它的登陸失敗的場景:
<
RecordType
>
ConnectionClose
</
RecordType
>
我們可以看出,
SPID??55
的連接關閉了:
<![endif]>
< Spid > 55 </ Spid >
我們可以看到連接是本地的(
<local machine>
表明其是一個本地的,
shared memory
類型的連接)。
<![endif]>
< RemoteHost > < local ?machine > ; </ RemoteHost >
?
當使用 TCP 協議進行連接時,可以獲得更多的相關信息 - 例如,本地 IP 地址,端口,以及遠程 IP 地址和端口,從而允許你唯一的確定客戶機及其應用。另外, Ring Buffer 包括了一個時間戳以及與之相對應的 SPID (如果有的話),這樣才能形成一個完整的對應關系。(因為隨著時間的推移 SPID 會被不同的連接所重用)。
我們同樣可以看到客戶發的 TDS 包中有多少 bytes ,并且可以知道是否在 TDS 中有任何的錯誤:
<
TdsInputBufferError
>
0
</
TdsInputBufferError
>
<
TdsOutputBufferError
>
0
</
TdsOutputBufferError
>
<
TdsInputBufferBytes
>
60
</
TdsInputBufferBytes
>
?
最相關的,最易于分析的信息記錄在 TdsDisconnectFlags 中,有一系列的值,記錄了關閉連接的狀態。這里,我們看到沒有發現錯誤,但是這里記錄了這也不是一個正常的斷開或者一個正常的登出。從如下的 flag 中,這個 session 是被殺死的:
<
SessionIsKilled
>
1
</
SessionIsKilled
>
一個更有意思的例子:DC ?連接性問題
跟蹤被殺死的 SPID 看起來很 cool 。但是 Connectivity Ring Buffer 更重要的最用 是幫助我們可以在不使用 network monitor 的情況下來解決棘手的問題。以下是一個 Connectivity Ring Buffer 中 Login Time 記錄的例子,如果沒有代價高昂的問題重現過程并且分析網絡抓獲的包,這個問題很難查明:
< Record ? id = " 3 " ? type = " RING_BUFFER_CONNECTIVITY " ? time = " 112254962 " >
< ConnectivityTraceRecord >
< RecordType > LoginTimers </ RecordType >
< Spid > 0 </ Spid >
< SniConnectionId > B401B045-3C82-4AAC-A459-DB0520925431 </ SniConnectionId >
< SniConsumerError > 17830 </ SniConsumerError >
< SniProvider > 4 </ SniProvider >
< State > 102 </ State >
< RemoteHost > < local ?machine > ; </ RemoteHost >
< RemotePort > 0 </ RemotePort >
< LocalHost ?/>
< LocalPort > 0 </ LocalPort >
< RecordTime > 5/6/2008 23:17:42.556 </ RecordTime >
< TdsBuffersInformation >
< TdsInputBufferError > 0 </ TdsInputBufferError >
< TdsOutputBufferError > 232 </ TdsOutputBufferError >
< TdsInputBufferBytes > 198 </ TdsInputBufferBytes >
</ TdsBuffersInformation >
< LoginTimers >
< TotalLoginTimeInMilliseconds > 21837 </ TotalLoginTimeInMilliseconds >
< LoginTaskEnqueuedInMilliseconds > 0 </ LoginTaskEnqueuedInMilliseconds >
< NetworkWritesInMilliseconds > 2 </ NetworkWritesInMilliseconds >
< NetworkReadsInMilliseconds > 77 </ NetworkReadsInMilliseconds >
< SslProcessingInMilliseconds > 3 </ SslProcessingInMilliseconds >
< SspiProcessingInMilliseconds > 21756 </ SspiProcessingInMilliseconds >
< LoginTriggerAndResourceGovernorProcessingInMilliseconds > 0 </ LoginTriggerAndResourceGovernorProcessingInMilliseconds >
</ LoginTimers >
</ ConnectivityTraceRecord >
< Stack >
< frame ? id = " 0 " > 0X01CA0B00 </ frame >
…
< frame ? id = " 15 " > 0X02E3C832 </ frame >
</ Stack >
</ Record >
在這個情況下,在客戶端,我們可以看到:
[SQL Server Native Client 10.0]Shared Memory Provider: Timeout error [258].
[SQL Server Native Client 10.0]Login timeout?expired
[SQL Server Native Client 10.0]Unable to complete login process due to delay in login response
獲得操作系統的錯誤消息,不能說明任何問題:
C:\>net?helpmsg
?258
The?wait operation timed out.
在服務器的 errorlogs 里面,什么都沒有。然而 Ring Buffer 中的記錄非常有意思。 LoginTimers 中記錄了整體處理時間( overall processing time ):
<
TotalLoginTimeInMilliseconds
>
21837
</
TotalLoginTimeInMilliseconds
>
在整個登陸過程中,根據不同階段所做的工作的不同,
TotalLoginTimeInMilliseconds
被分解為一個個子項(由于取整的操作,這些數字最終加起來不會等于總體的時間。在上面所舉的例子中他們相差
1
)。在這種情況下,
SspiProcessingInMilliseconds
?
看起來很有趣,它用了近
22
秒:
<![endif]>
< SspiProcessingInMilliseconds > 21756 </ SspiProcessingInMilliseconds >
SSPI ( Security Support Provider Interface ),是一個 SQL Server 使用 Windows Authentication 的接口。當 Windows login 是一個 domain account , SQL Server 使用 SSPI 和 Domain Controller 交互,從而驗證用戶身份。記錄中可以看到, SSPI 過程占用了大量的時間,這表明和 Domain Controller 交互時有延時,很有可能是 SQL 服務器和 DC 之間的物理連接有問題,或者 DC 上的一些軟件問題。可以看到,我們沒有進行網絡抓包,也沒有重現問題,我們就已經把問題縮小到 SQL Server 和 Domain Controller 之間的交互上面來了。( Connectivity Ring Buffer 默認是打開的)
Trace Flags
Connectivity Ring Buffer? 默認是打開的,它默認跟蹤所有的由服務器發起的連接關閉。如果你在客戶端看到一個錯誤,但是在 Ring Buffer 中沒有記錄,這就表明服務器看到的是一種“重置”類型的連接關閉,這種連接關閉類似于客戶端正常關閉連接的行為,或者是由于服務器外部因素所造成的連接關閉;(例如,一個網絡硬件的故障)。如果是這種情況,你就需要關注潛在的網絡互聯問題。如果你在 Ring Buffer 中看到了一個條目它可以指出為什么服務器要關閉這個鏈接,那么這個條目就很可能可以極大的幫助我們進行故障排查。例如,如果你看到一個連接關閉是由于 TDS 包中的信息不合法,那么你就可以去檢查那些可能會損壞網絡包的設備,包括網卡,路由和集線器等。下面你會看到,通過使用一個 trace flag ,你可以讓 Connectivity Ring Buffer 記錄所有連接關閉事件。這樣你就能觀察到客戶端發起的連接關閉的情形和潛在的錯誤。
有兩個 trace flag ,可以用于改變 Connectivity Ring Buffer? 的行為。
完全關閉 Connectivity Ring Buffer ,可以開啟 trace flag 7826 :
DBCC ?TRACEON ? ( 7826 , ? - 1 )
默認情況下客戶端發起的連接關閉是不被記錄的(因為這是正常的情況,而不是一個錯誤);當一個客戶結束的它的 session ,它就斷開。一般來說,我們建議不要去跟蹤客戶端發起的連接關閉,因為真正有用的 Buffer 記錄會被覆蓋(當你有很多正常表現的連接時,這種情況發生可能性會很大),或者會被隱藏在一個堆正常情況的記錄中。這會使你錯過真正的錯誤問題。如果你真的想要觀察客戶端的連接關閉,你可以使用 trace flag 7827 來開啟這個功能:
DBCC ?TRACEON ? ( 7827 , ? - 1 )
<Frame>tags 是什么?
通過 sys.dm_os_ring_buffers ?DMV? 可以訪問一系列內部信息,它包含了但不僅限于 Connectivity Ring Buffer 。作為 DMV 基礎的一部分,大多數的 Ring Buffers? 提供了事件發生時的棧蹤跡( stack trace ),每一個 <frame> 提供了一個十六進制的函數地址。這些都可以分解為函數名,并 dump Sqlservr.exe 進程,在 WinDbg 打開 dump ,并采用基于函數的地址的 LM 命令。
更多文章、技術交流、商務合作、聯系博主
微信掃碼或搜索:z360901061

微信掃一掃加我為好友
QQ號聯系: 360901061
您的支持是博主寫作最大的動力,如果您喜歡我的文章,感覺我的文章對您有幫助,請用微信掃描下面二維碼支持博主2元、5元、10元、20元等您想捐的金額吧,狠狠點擊下面給點支持吧,站長非常感激您!手機微信長按不能支付解決辦法:請將微信支付二維碼保存到相冊,切換到微信,然后點擊微信右上角掃一掃功能,選擇支付二維碼完成支付。
【本文對您有幫助就好】元
