The SQL Dude!

I like SQL Server Ring Buffers. They are very handy in troubleshooting specific issues like out-of-memory conditions, login failures and connectivity related errors. Yet, they remain a much under utilized part of a DBA’s repertoire or toolkit. This might be due to the fact that ring buffer output is stored in XML format and it takes a bit of T-SQL work to get them into a readable format. In this post, I will provide you with some of queries which I use to pull out information from certain ring buffer types. FYI – the DMV for ring buffers is sys.dm_os_ring_buffers

Like I always say, One Ring to find them and in the darkness bind them.

1. Security Ring Buffer

Starting with SQL Server 2005 SP2 a Security ring buffer for error logging has been added called ‘RING_BUFFER_SECURITY_ERROR’. This was specifically added to aid the DBA in finding more information regarding login failures and similar errors. On an active server, you might find multiple entries in the DMV if you filter on this ring buffer type, and an entry does not necessarily mean a failure. Let me show you how to use this with an example.

I have a user who is not able to login to SQL Server. This is the error from SSMS.

I used the following query filtering on RING_BUFFER_SECURITY_ERROR,

SELECT 
    CONVERT (varchar(30), GETDATE(), 121) as [RunTime],
    DATEADD (ms, rbf.[timestamp] - tme.ms_ticks, GETDATE()) as [Notification_Time],
    CAST(record as xml).value('(//SPID)[1]', 'bigint') as SPID,
    CAST(record as xml).value('(//ErrorCode)[1]', 'varchar(255)') as Error_Code,
    CAST(record as xml).value('(//CallingAPIName)[1]', 'varchar(255)') as [CallingAPIName],
    CAST(record as xml).value('(//APIName)[1]', 'varchar(255)') as [APIName],
    CAST(record as xml).value('(//Record/@id)[1]', 'bigint') AS [Record Id],
    CAST(record as xml).value('(//Record/@type)[1]', 'varchar(30)') AS [Type],
    CAST(record as xml).value('(//Record/@time)[1]', 'bigint') AS [Record Time],
    tme.ms_ticks as [Current Time]
from sys.dm_os_ring_buffers rbf
cross join sys.dm_os_sys_info tme
where rbf.ring_buffer_type = 'RING_BUFFER_SECURITY_ERROR' --and cast(record as xml).value('(//SPID)[1]', 'int') = XspidNo
ORDER BY rbf.timestamp ASC

Output

 
Once you have this you can look at the SPID number and correlate this with the login failed event in the errorlog and get the Error code which is a Win32 error and translate that using net helpmsg or using http://msdn2.microsoft.com/en-us/library/ms681381.aspx. The error “0x89B” is in Hex and translates to Win32 Error 2203, which means – “The password parameter is invalid”.

This is true, since I did provide an incorrect password when logging in. Quite a simple example, but you can see the wealth of information available with the ring buffers. The security ring buffer provides the following information:-

1. SPID
2. API Name
3. Error Code returned by the failing API (step #2).

2. Connectivity Ring Buffer

The connectivity ring buffer was introduced starting with SQL Server 2008 and is called called ‘RING_BUFFER_CONNECTIVITY’. This will automatically capture server-side initiated connection closures, if you see nothing in the dmv, then most likely the client reset/closed the connection. You can enable any connection closure (client or server) logging with trace flag 7827 (caution advised with this trace flag). When I say server initiated closures, it also includes things like Session killed or Login Failed. More details on this is given in this blog.

Lets look at an example,

1. I opened a connection to SQL Server using sqlcmd from a remote machine.

2.  I went ahead and killed this session 55 from another connection. KILL 55

3. Here is the the T-SQL query to pull out information from the connectivity ring buffer,

    SELECT CONVERT (varchar(30), GETDATE(), 121) as [RunTime],
    dateadd (ms, (rbf.[timestamp] - tme.ms_ticks), GETDATE()) as Time_Stamp,
    cast(record as xml).value('(//Record/ConnectivityTraceRecord/RecordType)[1]', 'varchar(50)') AS [Action], 
    cast(record as xml).value('(//Record/ConnectivityTraceRecord/RecordSource)[1]', 'varchar(50)') AS [Source], 
    cast(record as xml).value('(//Record/ConnectivityTraceRecord/Spid)[1]', 'int') AS [SPID],
    cast(record as xml).value('(//Record/ConnectivityTraceRecord/RemoteHost)[1]', 'varchar(100)') AS [RemoteHost],
    cast(record as xml).value('(//Record/ConnectivityTraceRecord/RemotePort)[1]', 'varchar(25)') AS [RemotePort],
    cast(record as xml).value('(//Record/ConnectivityTraceRecord/LocalPort)[1]', 'varchar(25)') AS [LocalPort],
    cast(record as xml).value('(//Record/ConnectivityTraceRecord/TdsBuffersInformation/TdsInputBufferError)[1]', 'varchar(25)') AS [TdsInputBufferError],
    cast(record as xml).value('(//Record/ConnectivityTraceRecord/TdsBuffersInformation/TdsOutputBufferError)[1]', 'varchar(25)') AS [TdsOutputBufferError],
    cast(record as xml).value('(//Record/ConnectivityTraceRecord/TdsBuffersInformation/TdsInputBufferBytes)[1]', 'varchar(25)') AS [TdsInputBufferBytes],
    cast(record as xml).value('(//Record/ConnectivityTraceRecord/TdsDisconnectFlags/PhysicalConnectionIsKilled)[1]', 'int') AS [isPhysConnKilled], 
    cast(record as xml).value('(//Record/ConnectivityTraceRecord/TdsDisconnectFlags/DisconnectDueToReadError)[1]', 'int') AS [DisconnectDueToReadError],
    cast(record as xml).value('(//Record/ConnectivityTraceRecord/TdsDisconnectFlags/NetworkErrorFoundInInputStream)[1]', 'int') AS [NetworkErrorFound],
    cast(record as xml).value('(//Record/ConnectivityTraceRecord/TdsDisconnectFlags/ErrorFoundBeforeLogin)[1]', 'int') AS [ErrorBeforeLogin],
    cast(record as xml).value('(//Record/ConnectivityTraceRecord/TdsDisconnectFlags/SessionIsKilled)[1]', 'int') AS [isSessionKilled],
    cast(record as xml).value('(//Record/ConnectivityTraceRecord/TdsDisconnectFlags/NormalDisconnect)[1]', 'int') AS [NormalDisconnect],
    cast(record as xml).value('(//Record/ConnectivityTraceRecord/TdsDisconnectFlags/NormalLogout)[1]', 'int') AS [NormalLogout],
    cast(record as xml).value('(//Record/@id)[1]', 'bigint') AS [Record Id], 
    cast(record as xml).value('(//Record/@type)[1]', 'varchar(30)') AS [Type], 
    cast(record as xml).value('(//Record/@time)[1]', 'bigint') AS [Record Time],
    tme.ms_ticks as [Current Time]
FROM sys.dm_os_ring_buffers rbf
cross join sys.dm_os_sys_info tme
where rbf.ring_buffer_type = 'RING_BUFFER_CONNECTIVITY' and cast(record as xml).value('(//Record/ConnectivityTraceRecord/Spid)[1]', 'int') <> 0
ORDER BY rbf.timestamp ASC

Here is what I find in the ring buffer,

Again you can see the good amount of diagnostic information available to get more information on why this connection was closed. Some things available are :-

1. SPID
2. Remote Host Machine IP and Port number
3. Network Error (True/False)
4. Session Killed (True/False)

In this example, since the session was killed, that 4th flag is set to True. There are other scenarios like this you can troubleshoot like Login Timeout due to delay in login process, DC errors when authenticating a Windows login etc. If you don’t find the SPID in the above connectivity ring buffer output this means that the server has seen a connection closure (reset) similar to normal connection closure from the client (e.g. sp_reset_connection). Client side connectivity errors can also be made to log in the ring buffer using DBCC TRACEON (7827, -1). Again, caution advised before enabling this since it is a global trace flag applicable for the entire instance.

3. Exception Ring Buffer

This is a generic ring buffer type that records internal errors and any exceptions in SQL Server. SQL itself uses this ring buffer internally for errors, so this is most likely to always contain some information. Any errors in SQL Server are put into this generic ring buffer. TDS errors, memory errors etc. I didn’t even attempt a repro and just queried it using this T-SQL,

SELECT CONVERT (varchar(30), GETDATE(), 121) as [RunTime],
    dateadd (ms, (rbf.[timestamp] - tme.ms_ticks), GETDATE()) as Time_Stamp,
    cast(record as xml).value('(//Exception//Error)[1]', 'varchar(255)') as [Error],
    cast(record as xml).value('(//Exception/Severity)[1]', 'varchar(255)') as [Severity],
    cast(record as xml).value('(//Exception/State)[1]', 'varchar(255)') as [State],
    msg.description,
    cast(record as xml).value('(//Exception/UserDefined)[1]', 'int') AS [isUserDefinedError],
    cast(record as xml).value('(//Record/@id)[1]', 'bigint') AS [Record Id],
    cast(record as xml).value('(//Record/@type)[1]', 'varchar(30)') AS [Type], 
    cast(record as xml).value('(//Record/@time)[1]', 'bigint') AS [Record Time],
    tme.ms_ticks as [Current Time]
from sys.dm_os_ring_buffers rbf
cross join sys.dm_os_sys_info tme
cross join sys.sysmessages msg
where rbf.ring_buffer_type = 'RING_BUFFER_EXCEPTION' --and cast(record as xml).value('(//SPID)[1]', 'int') <> 0--in (122,90,161,179)
and msg.error = cast(record as xml).value('(//Exception//Error)[1]', 'varchar(500)') and msg.msglangid = 1033 --and [Error] = 4002
ORDER BY rbf.timestamp ASC

4. Resource Monitor Ring Buffer

This ring buffer type stores information about system health conditions like memory pressure including physical and virtual. We can use ‘RING_BUFFER_RESOURCE_MONITOR’ to extract information about the condition of OS memory and SQL memory using a query like the following. Looking at this query, you will be able to easily determine the various indicators that would have triggered the Windows to page various processes including SQL Server and also get to know if there is a system memory pressure going on and how much memory SQL was consuming at a particular point in time.

SELECT CONVERT (varchar(30), GETDATE(), 121) as [RunTime],
    dateadd (ms, (rbf.[timestamp] - tme.ms_ticks), GETDATE()) as [Notification_Time], 
    cast(record as xml).value('(//Record/ResourceMonitor/Notification)[1]', 'varchar(30)') AS [Notification_type], 
    cast(record as xml).value('(//Record/MemoryRecord/MemoryUtilization)[1]', 'bigint') AS [MemoryUtilization %], 
    cast(record as xml).value('(//Record/MemoryNode/@id)[1]', 'bigint') AS [Node Id], 
    cast(record as xml).value('(//Record/ResourceMonitor/IndicatorsProcess)[1]', 'int') AS [Process_Indicator],
    cast(record as xml).value('(//Record/ResourceMonitor/IndicatorsSystem)[1]', 'int') AS [System_Indicator],
    cast(record as xml).value('(//Record/MemoryNode/ReservedMemory)[1]', 'bigint') AS [SQL_ReservedMemory_KB], 
    cast(record as xml).value('(//Record/MemoryNode/CommittedMemory)[1]', 'bigint') AS [SQL_CommittedMemory_KB], 
    cast(record as xml).value('(//Record/MemoryNode/AWEMemory)[1]', 'bigint') AS [SQL_AWEMemory], 
    cast(record as xml).value('(//Record/MemoryNode/SinglePagesMemory)[1]', 'bigint') AS [SinglePagesMemory], 
    cast(record as xml).value('(//Record/MemoryNode/MultiplePagesMemory)[1]', 'bigint') AS [MultiplePagesMemory], 
    cast(record as xml).value('(//Record/MemoryRecord/TotalPhysicalMemory)[1]', 'bigint') AS [TotalPhysicalMemory_KB], 
    cast(record as xml).value('(//Record/MemoryRecord/AvailablePhysicalMemory)[1]', 'bigint') AS [AvailablePhysicalMemory_KB], 
    cast(record as xml).value('(//Record/MemoryRecord/TotalPageFile)[1]', 'bigint') AS [TotalPageFile_KB], 
    cast(record as xml).value('(//Record/MemoryRecord/AvailablePageFile)[1]', 'bigint') AS [AvailablePageFile_KB], 
    cast(record as xml).value('(//Record/MemoryRecord/TotalVirtualAddressSpace)[1]', 'bigint') AS [TotalVirtualAddressSpace_KB], 
    cast(record as xml).value('(//Record/MemoryRecord/AvailableVirtualAddressSpace)[1]', 'bigint') AS [AvailableVirtualAddressSpace_KB], 
    cast(record as xml).value('(//Record/@id)[1]', 'bigint') AS [Record Id], 
    cast(record as xml).value('(//Record/@type)[1]', 'varchar(30)') AS [Type],
    cast(record as xml).value('(//Record/@time)[1]', 'bigint') AS [Record Time],
    tme.ms_ticks as [Current Time]
FROM sys.dm_os_ring_buffers rbf
cross join sys.dm_os_sys_info tme
where rbf.ring_buffer_type = 'RING_BUFFER_RESOURCE_MONITOR' --and cast(record as xml).value('(//Record/ResourceMonitor/Notification)[1]', 'varchar(30)') = 'RESOURCE_MEMPHYSICAL_LOW'
ORDER BY rbf.timestamp ASC

The best thing about ring buffers is that they are fast and stored on the fly. Even during low memory conditions you can still login to SQL Server using the DAC connection and query these ring buffers. Think how much faster it is as compared to collection traces or perfmon logs etc.

That’s all for now folks. You can start playing with ring buffers to understand more. Have fun!