Find Out What They're Doing with fn_get_sql

Monday Apr 14th 2003 by Andrew Novick
Share:

Learn how fn_get_sql makes it easier for DBAs, programmers, and diagnostic tools to retrieve the text of the SQL being executed by active SQL processes.

Don't miss the movie that accompanies this article!

Not only did SQL Server 2000 introduce the concept of user-defined functions (UDF) but also Microsoft's development team created several such functions as part of the database product. In addition to many undocumented system UDFs, used internally by SQL Server, the product release has nine documented UDFs that are part of a special schema in the master database named system_function_schema. These system UDFs provide information about the internal workings of SQL Server that isn't available elsewhere. SQL Server 2000 Service Pack 3 (SP3) includes a new system user-defined function, fn_get_sql. The function was included in an earlier hotfix but SP3 is the best way to get it. (See Microsoft Knowledge Base article 325607)

fn_get_sql makes it easier for DBAs, programmers, and diagnostic tools to retrieve the text of the SQL being executed by active SQL processes. This is a technique commonly used when diagnosing a deadlock or other blocking problem. Diagnostic tools that monitor activity inside the database engine can also use it.

The first step before using fn_get_sql is to get the documentation. There is an updated Books Online for SP3 that includes the new documentation for fn_get_sql. You can get it without installing SP3 at this link: http://www.microsoft.com/sql/techinfo/productdoc/2000/books.asp

If you're not installing SP3, be careful as you install the updated documentation. If you let it, the installer will overwrite your existing Books Online (BOL). However, if you make the right selection, it can be installed side-by-side with the old BOL, which you will want to keep around. You will know that you have the updated documentation because the title bar of the BOL window is updated as shown in Figure 1.

Figure 1 Updated BOL Title Bar

Prior to SP3, the way to get the SQL being used by a SQL process was from the DBCC INPUTBUFFER command. DBCC INPUTBUFFER takes a SPID as its argument. SPIDs are integers that uniquely identify a database connection. SPIDs below 53 are generally used by system connections. Fifty-three and over are used for user connections. A connection can get its own SPID with the @@SPID built-in function.

When invoked, DBCC INPUTBUFFER returns a rowset consisting of these columns:

Column Name

Data Type

Description

EventType

nvarchar(30)

Language Event
No Event

RPC

Parameters

int

0=text 1-n=parameters

EventInfo

nvarchar(255)

For an RPC (stored procedure) it contains the procedure name. For a Language Event it contains the text of the SQL being executed.

This query gives you the idea of how DBCC INPUTBUFFER works by showing you its own text:

DBCC INPUTBUFFER (@@SPID)
GO
(Results)
EventType      Parameters EventInfo                   
-------------- ---------- --------------------------- 
Language Event          0 DBCC INPUTBUFFER (@@SPID)
(End of results)

The data type of the EventInfo column is nvarchar(255). This has proven to be an annoying limitation because it restricts the results to the first 255 characters of any SQL statement. While that might be enough when the statement is executing a stored procedure, it is often insufficient when a complex SELECT or UPDATE is involved.

Calling system UDFs is different from calling your own functions. The documented system UDFs all return tables of information, so they are used in the FROM clause of SQL statements. A double colon precedes the name of the system UDF. Therefore the FROM clause that invokes fn_get_sql looks like this:

FROM ::fn_get_sql(@HandleVariable)

The system UDFs obey a short set of rules:

  • Their names begin with the characters fn_
  • Their names are all lower case characters
  • They are defined in the master database under the pseudo owner system_function_schema.

I have referred to system_function_schema as a pseudo owner because SQL Server creates it for the sole purpose of owning these functions but it does not correspond to a user in the master database.

fn_get_sql overcomes the length restriction on the size of the SQL statement returned by returning a text column. Here is the layout of its result set:

Column Name

Data Type

Description

dbid

smallint

Database ID

objectid

int

ID of the database object. NULL for ad hoc statements.

number

smallint

The number of the group, if the procedures are grouped.

encrypted

bit

1=Encrypted 0=Not encrypted

text

text

Text of the statement. NULL if the object is encrypted. Will only return 8000 characters.

In spite of the fact that the text column is of data type text, the design of SQL Server's internal cache limits what's in the cache. It does not include BULK operations and it can't include string literals that are over 8K.

Unlike DBCC INPUTBUFFER, which takes a SPID, fn_get_sql takes a sql_handle as its parameter. sql_handle is a new BINARY(20) column in the sysprocesses table that resides in master. This field and two more, stmt_start and stmt_end, were added to sysprocesses to support fn_get_sql. The sql_handle can be retrieved using the SPID as this script:

-- Retrieve the sql of this connection 
DECLARE @handle binary(20)

SELECT @handle = sql_handle
    FROM master..sysprocesses
    WHERE spid = @@SPID

SELECT [text] 
    FROM ::fn_get_sql(@handle)
GO
(Results)
text   
---------------------------------------------------------------
-- Retrieve the sql of this connection
DECLARE @handle binary(20)

SELECT @handle = sql_handle
    FROM master..sysprocesses
    WHERE spid = @@SPID

SELECT [text] 
    FROM ::fn_get_sql(@handle)

Don't get confused by the fact that the output is identical to the query. It is supposed to be the same. It even includes the comment line that starts the batch.

Handles expire very quickly and should be used immediately. If you pass in the handle that is no longer in the cache, fn_get_sql returns an empty result set. That was happening to me often and I couldn't explain the empty results. It turns out that when the plan for a SQL Statement has zero cost it isn't cached at all.

Microsoft has added a remedy to this situation in the form of a new trace flag, 2861. Once it is turned on, zero cost plans are cached and they show up as the result of fn_get_sql. Trace flags are turned on with the DBCC TRACEON statement such as:

DBCC TRACEON (2861)

You can turn it back off with TRACEOFF as in:

DBCC TRACEOFF (2861)

A truly real world example of using fn_get_sql might involve creating a deadlock, using sp_lock to find out which processes are blocked, and then using fn_get_sql to retrieve the text of the SQL that the blocked and blocking processes were executing. The thought of publishing code that deliberately created a deadlock some how struck me as overly risky so I've decided to use a slightly simpler example, a case of simple blocking due to a long running transaction.

The example below uses two Query Analyzer windows to run Script A and Script B. Both should be run in the Pubs sample database. The scripts include six batches. The batches should be run in numeric order. You can get the scripts from the links if you want to run them yourself. In the text that follows, I execute each batch in order and show you the results.

Start with Script A Batch A-1. It turns on trace 2861 and moves the connection into the Pubs database.

-- Batch A-1   Moves to the Pubs sample database
PRINT 'Batch A-1  Script A''s SPID = ' + CAST (@@SPID as varchar)
DBCC TRACEON(2861)
Use Pubs
go 
(Results)
Batch A-1  Script A's SPID = 53
DBCC execution completed. If DBCC printed error messages, contact your system administrator.	

Next run Script A Batch A-2. This batch begins a transaction and deletes a row in the Authors table. I have deliberately chosen an author that has not written any books so there are no referential integrity issues. Don't worry about loosing the row. We will rollback the transaction in Batch A-6. Here is Batch A-2:

-- Batch A-2
PRINT 'Batch A-2 Begin a transaction and create the blockage'
BEGIN TRAN -- the transaction will cause 
    DELETE FROM authors WHERE au_id = '527-72-3246'
GO
-- Stop Batch A-2 here
(Results)
Batch A-2 Begin a transaction and create the blockage

(1 row(s) affected)

Batch A-2 leaves open a transaction, which we will not close until Batch A-6. In Script A‑5, we'll see that the open transaction causes the SPID to hold several locks, including an exclusive lock on the row being deleted.

The next step is to open a new Query Analyzer connection using the menu item File/Connect and load Script B. The first batch in script B is B-3, which prints the SPID of the connection for Script B. We will use that SPID in batch A-5. Here is Batch B-3 with the results of running it on my system:

-- Batch B-3   Moves to the Pubs sample database
--             And prints the SPID
PRINT 'Batch B-3 Printing the SPID and Using Pubs'
PRINT 'Script B -- Has SPID ' + CAST(@@SPID as varchar)
Use Pubs
GO
(Results)
Batch B-3 Printing the SPID and Using Pubs
Script B -- Has SPID 55

You will probably get a different number for the SPID. Once again, take note of the SPID because it is needed later in Batch A-6.

Batch B-4 selects from the Authors table. Here is the batch:

-- Batch B-4 
PRINT 'Batch B-4 SELECT a blocked resource.'
select * from authors
GO

There are no results, because the batch cannot run due to the open transaction left by Batch A-2. Figure 2 shows what my Query Analyzer window looks like after I execute B-4.

Figure 2 Script B Batch B-4 is Blocked and Show It's Results

I have circled the red execution flag in purple to highlight the fact that the batch is running. If you look down in the information bar near the bottom of the figure, you will see that it had been running for one minute and 11 seconds by the time that I took the screen shot.

Leave Batch B-4 running and switch back to the connection with Script A. Batch A-5 uses the sp_lock system stored procedure to show the locks being held by the system. The exclusive locks (Mode = X) held by Script A are highlighted in red and the wait for a shared lock (Mode = S) is highlighted in blue.

-- Batch A-5  sp_lock shows who's waiting and who's locking
PRINT 'Batch A-5 -- Output of sp_lock'
exec sp_lock
GO
(Results)
Batch A-5 -- Output of sp_lock
spid   dbid   ObjId       IndId  Type Resource         Mode     Status 
------ ------ ----------- ------ ---- ---------------- -------- ------ 
    53      5  1977058079      0 TAB                   IX       GRANT
    53      5  1977058079      1 PAG  1:127            IX       GRANT
    53      5  1977058079      1 KEY  (0801c4f7a625)   X        GRANT
    53      5           0      0 DB                    S        GRANT
    53      5  1977058079      1 PAG  1:239            IX       GRANT
    53      5  1977058079      2 KEY  (1f048d178a34)   X        GRANT
    53      1    85575343      0 TAB                   IS       GRANT
    54     14           0      0 DB                    S        GRANT
    55      5  1977058079      1 PAG  1:127            IS       GRANT
    55      5           0      0 DB                    S        GRANT
    55      5  1977058079      0 TAB                   IS       GRANT
    55      5  1977058079      1 KEY  (0801c4f7a625)   S        WAIT

The explanation of what is happening is that SPID 55, which is running Batch B-4, is waiting for a shared lock on Key 0801c4f7a625. However, SPID 53 has been granted an exclusive lock on that key. Had we set the transaction isolation level in Batch B-4 to READ UNCOMMITTED, Batch B-4 would not have requested the shared lock and would not have to wait.

Finally, it is time to use fn_get_sql to examine the SQL that Batch B-4 is running. This is done with Batch A-6. Before you can run A-6, you must change the line "WHERE spid=55" to replace the 55 with the SPID that was printed by Batch B-3. Here is Batch A-6 with its results:

-- Batch A-6  You must change the SPID number in this batch
--           before executing this step!
PRINT 'Batch A-6 -- Get the text of the blocked connection'
DECLARE @Handle binary(20)
SELECT @handle=sql_handle 
     FROM master..sysprocesses 
     WHERE spid= 55 -- <<<<<< Change 55 to the SPID of Script B

SELECT * FROM ::fn_get_sql(@handle)

ROLLBACK TRAN -- Releases the lock on authors
GO 
(Results)
Batch A-6 -- Get the text of the blocked connection

------ ----------- ------ --------- ------------------
NULL   NULL        NULL           0 -- Batch B-4 
PRINT 'Batch B-4 SELECT a blocked resource.'
select * from authors

(1 row(s) affected)

The [text] column has carriage returns in it and they show up in the output. To make it easier to see the results, I have highlighted the output of the text column in blue. Since there were three lines in the batch, it wraps onto a second and third line of output.

The last line of A-6 is a ROLLBACK TRAN statement. This undoes the effect of the DELETE done earlier. It also has the effect of releasing the exclusive locks that are held by Script A's connection. If you flip back to Script B, you'll see that it has run and sent its output to the results window.

fn_get_sql is a new function to aid the DBA and programmer in the diagnosis of blocking problems. It can also be put to use by diagnostic or performance monitoring tools to monitor the SQL being run by any process in the system. That would be done by continually sampling the SQL of all processes to discover the statements that are executed most often. I am aware of at least one tool on the market that is using it in this way. However, you don't need an expensive tool to put fn_get_sql to good use. A simple script, like the one in batch A-6 that gets a sql_handle and uses it is all you need.


You've read the article, now watch the movie!

» See All Articles by Columnist Andrew Novick

Share:
Home
Mobile Site | Full Site
Copyright 2017 © QuinStreet Inc. All Rights Reserved