Identifying Details of Active Cursors

Recently, I was digging my way through a really nasty set of trace results from SQL Profiler when I ran across a series of commands that only provided insight into the fact that cursors were being employed:

exec sp_cursorfetch 180590305,2,1,6

Harumph! What the heck does this mean? At this point, all I know is that the application is employing a cursor yet I have no idea what this cursor is doing. In other words, I now don't know one more thing that before I started looking at activity from this trace. I'm no less ignorant than a second ago, but now I have the joy of feeling dumber than I did only a minute ago. Performance tuning is awesome!

Well, what can I do to gain insight into the code that was running under that cursor? Depending on when this trace was run I may not be able to dig in further. But what I want to do here is give you ammunition for the next time you're reviewing activity of this sort and run across what you may see as an sp_cursorfetch roadblock.

Dynamic Management Objects to the Rescue

When speaking on the general nature of the Dynamic Management Objects—particularly in discussions around my Periodic Table of Dynamic Management Objects—I tend to gloss over sys.dm_exec_cursors by simply stating that "it's a way to see what cursors are in use on your SQL Server instance," then I move on to some of the more glamourous DMOs. This performance tuning session gives me the opportunity to demonstrate one of the ways where sys.dm_exec_cursors is a valuable tool though without having to step into the "CURSORS ARE BAD v. CURSORS HAVE THEIR PLACE" arguement. Assigning labels such as "good", "bad", "right" or "wrong" to code constructs—and in most cases to anything—is more about passing judgement than identifying issues. Therefore, we'll sidestep this debate completely in order to show how one can use sys.dm_exec_cursors to get a better understanding of what is being run through the cursor construct rather than its legitimacy.

"Er, uh hey Tim, what does that little blinking pipe character have to do with SQL Server?"

 "What? Um, oh... ha ha ha... Not that kind of cursor. No, there is a code construct called a 'cursor' as well. It simply is a process that runs code in a row-by-row fashion, usually to collect value(s) for output variable(s) for subsequent row-by-row processing in a separate statement rather than performing code execution in a set-based fashion."

OK, now that we've level-set on what a cursor is, let's discuss how to identify what it's doing when all we know is what we see through an EXEC sp_cursorfetch command. Breaking down that sp_cursorfetch command above we see four separate parameters:

exec sp_cursorfetch 180590305,2,1,6

The first parameter corresponds to the cursor_id that uniquely identifies the cursor on the SQL Server instance and for the sake of this discussion that is the only parameter in which we're interested when answering the question of "what is the underlying SQL command of the cursor?"

We need one more bit of metadata to assist us in finding out what that statement is however and luckily we have it since we're discussing the results of a trace:  the session_id (aka SPID) that uniquely identifies the session running the cursor:

Matter of fact, considering that the second parameter for the exec sp_cursorfetch command is 2, the remaining parameter values are ignored as irrelevant. (A parameter value of 2 passed in as the fetchtype corresponds to the directive to return the next applicable value from the cursor.)

Given that information, we now have enough information to return the sql command associated with this cursor if we're looking at the results in real time (as we're relying on the session_id and activity is a beach of constantly-shifting sand.)

SELECT eST.text AS sql_cmd, SUBSTRING(eST.text, eC.statement_start_offset / 2,        (CASE WHEN eC.statement_end_offset = -1 THEN DATALENGTH(eST.text)ELSE eC.statement_end_offsetEND - eC.statement_start_offset ) / 2) AS statement_executing , eC.session_id    , eC.cursor_id    , eC.name    , eC.properties    , eC.statement_start_offset    , eC.statement_end_offset    , eC.creation_time    , eC.worker_time    , eC.reads    , eC.writes    , eC.dormant_duration FROM sys.dm_exec_cursors() AS eC CROSS APPLY sys.dm_exec_sql_text(ec.sql_handle) AS eSTORDER BY eC.session_id;

Please note that I've utilized a template parameter for the session_id. (Please refer to Introduction to Using the Template Explorer in SQL Server Management Studio for more information on how to use them.) You'll need to use the keystroke shortcut of Control+Shift+M in order to swap out the appropriate session_id for your particular situation.  In my case, by swapping out the session_id of 201 I return the following results (dropped into a mixture of Excel and notepad for easier review):

DECLARE @server nvarchar(256), @db_name nvarchar(256), @name nvarchar(256), @physical_name nvarchar(520), @type_desc nvarchar(60), @size_mb BIGINT, @avail_mb BIGINT, @date_stamp DATETIMEDECLARE file_cursor CURSOR FORWARD_ONLY STATIC READ_ONLY FOR SELECT SSIS.Alias  , DFH.DatabaseName  , DFH.Name  , DFH.Filename  , DFH.FileType  , DFH.Size_In_Mb  , DFH.Available_Space_In_Mb  , DFH.date_stamp FROM dbo.database_files_history DFH INNER JOIN dbo.ServerList_SSIS SSIS ON DFH.Server = SSIS.ServerWHERE date_stamp > '8/1/2013'AND SSIS.Alias IS NOT NULL AND SSIS.Connect = 1ORDER BY SSIS.Alias, DFH.DatabaseName, DFH.FileType DESC, DFH.[FileName], DFH.date_stamp DESC;OPEN file_cursorFETCH NEXT FROM file_cursor INTO @server, @db_name, @name, @physical_name, @type_desc, @size_mb, @avail_mb, @date_stampWHILE @@FETCH_STATUS = 0BEGIN    SELECT @server, @db_name, @name, @physical_name, @type_desc, @size_mb, @avail_mb, @date_stampPRINT GETDATE()FETCH NEXT FROM file_cursor INTO @server, @db_name, @name, @physical_name, @type_desc, @size_mb, @avail_mb, @date_stampEND CLOSE file_cursor;DEALLOCATE file_cursor;

DECLARE file_cursor CURSOR FORWARD_ONLY STATIC READ_ONLY FOR SELECT SSIS.Alias  , DFH.DatabaseName  , DFH.Name  , DFH.Filename  , DFH.FileType  , DFH.Size_In_Mb  , DFH.Available_Space_In_Mb  , DFH.date_stamp FROM dbo.database_files_history DFH INNER JOIN dbo.ServerList_SSIS SSIS ON DFH.Server = SSIS.ServerWHERE date_stamp > '8/1/2013'AND SSIS.Alias IS NOT NULL AND SSIS.Connect = 1ORDER BY SSIS.Alias, DFH.DatabaseName, DFH.FileType DESC, DFH.[FileName], DFH.date_stamp DESC;OPEN file_cursorFETCH NEXT FROM file_cursor INTO @server, @db_name, @name, @physical_name, @type_desc, @size_mb, @avail_mb, @date_stampWHILE @@FETCH_STATUS = 0BEGIN    SELECT @server, @db_name, @name, @physical_name, @type_desc, @size_mb, @avail_mb, @date_stampPRINT GETDATE()FETCH NEXT FROM file_cursor INTO @server, @db_name, @name, @physical_name, @type_desc, @size_mb, @avail_mb, @date_stampEND CLOSE file_cursor;DEALLOCATE file_cursor;

The remainder of the results:

What sys.dm_exec_cursors gives us is insight into the command text associated with any running/active cursor along with the cursor settings

as well as active portion of the command via the statement_start_offset and statement_end_offset columns (these are unicode values so you need to divide the returned value by 2 as you'll see in the query I've provided above). The start_offset_value denotes that this is really at the 192nd character of the full batch; -1 denotes that the end of the active statement corresponds to the end of the full batch text.  You're also able to see when the cursor was created and the amount of CPU and IO time that has been incurred through the use of the cursor. Finally, the dormant_duration column refers to the the duration in milliseconds since the last fetch operation from the cursor was performed (or since the cursor was opened should no records yet be fetched).

More Info at Your Disposal

At this point, you have more information to go on other than "code was running through a cursor;" you have insight into what that code was and the overhead incurred. Now set forth and tune!