Undocumented Virtual Column: %%lockres%

March 18, 2010 at 8:43 am (SQL Server 2005, SQL Server 2008, TSQL) (, , , , , , , )

One of my development teams needed a mechanism for identifying the value of a key that was part of a lock (don’t ask). I’d never tried doing that before. Obviously if you hit the DMV sys.dm_os_tran_locks you can see the hash of the key in the resource_description column. But how to pull the value back. After some research, I first found this excellent article by the late, great, Ken Henderson (I really wish he was still around). The article outlined, among other things, the use of an undocumented “virtual” column called %%lockres%%. Some more searching then uncovered this great article by James Rowland-Jones, AKA Claypole. He described how, in a very high volume system, he used %%lockres%% to identify the source of a deadlock as the internal mechanisms that SQL Server uses to manage locks, the hash of the key. Oh, and he opened an incident on Connect, which seems to be closed, but vote on it anyway, I did. %%lockres%% is also covered in Kalen Delaney’s excellent book on SQL Server 2008 Internals and even warrants a bit of discussion in Professional SQL Server 2008, but that was written by James Rowland-Jones, so I’m not sure it counts.

In the meantime, while I was investigating this stuff, evidently the development team was looking into it on their own. They came to the same set of resources and decided to use the virtual column as part of their real-time, transactional application. Yeah, an undocumented “virtual” column going into a major application. Since I would probably be unable to do anything about this, I decided to at least look into how this thing behaves so I can be aware of what types of problems I might run into.

First, a simple query:

SELECTa.City
–,%%lockres%%
FROM Person.Address AS a
WHERE a.AddressID = 432

If you run this query and take a look at the execution plan you’ll see a nice clean clustered index seek, just as you would suspect. If you take away the comment and run it again, the execution plan is identical. On the version of AdventureWorks2008 currently installed on my machine, I get two page reads, regardless of whether or not I include %%lockres%% or not. With the comments removed, it returns the hash of the primary key: (b0004e040bc2). This looks pretty painless, free even.

If we want to see %%lockres%% in action, it’s not too difficult:

BEGIN TRAN
UPDATE Person.Address
SET City = ‘dude’
WHERE AddressID = 432;
–ROLLBACK TRAN

Obviously this will put a key lock on that row in the table. If I just select against sys.dm_os_tran_locks, the data returned looks like this:

resource_type   resource_description   resource_associated_entity_id   request_mode
KEY                       (b0004e040bc2)            72057594043564032                      X 

The original request from the development team was for a way to get the key value back when you know that a table is locked, such as the case here. I wrote this simple query to make that happen:

SELECT a.AddressID
FROM person.address(NOLOCK) AS a
JOIN sys.dm_tran_locks AS dtl
ON a.%%lockres%% = dtl.resource_description
WHERE dtl.resource_type = ‘KEY’

This query works and returns our key value of 432 just as you would want. But, take a look at the execution plan:

Yes, that’s a clustered index (or table, same thing) scan followed by a Sort followed by a merge join, processing 19614 rows to return one. But hey, it was only 341 reads. To say the least, I’m not excited about seeing this in a production system. This was explicitly cautioned in Kalen Delaney’s book. While it appears that the remote scan operator, which is how the DMV is accessed in this case, is 59% of the operation, that’s the estimated cost and has been pointed out before, isn’t the best measure of real cost in the system.

The development team went off and developed their own query, they had said they were looking for the key value, but evidently they were looking for who was holding the lock on a particular key value:

SELECT s.nt_user_name
FROM sys.dm_tran_locks l
INNER JOIN sys.dm_exec_sessions s
on l.request_session_id = s.session_id
inner join sys.partitions p on l.resource_associated_entity_id = p.hobt_id
where OBJECT_NAME(p.object_id) = ‘Address’ and
l.resource_description in (select %%lockres%%
from person.Address(NOLOCK) a WHERE a.AddressID = 432)

I actually had to adjust their query just a bit to get it to work correctly, but basically they had the right idea. Here’s the final execution plan:

This was still not terribly inspiring a thing to think about running in a production system although it only had one scan and seven reads. Whether or not putting this in a transactional system is a good idea, it certainly adds yet another tool, albeit an undocumented one, to the tool belt.

Permalink 3 Comments

Characters

October 21, 2009 at 2:42 pm (SCOM, SQL Server 2005, SQL Server 2008, SQLServerPedia Syndication, TSQL) (, , , , )

No, I’m not talking about a Dickens novel. I’m talking about the number of characters in a string. I had a painful time recently because of the word “characters.” 

If you take a look at the dynamic management view sys.dm_exec_sql_text you can get the queries that have been run on your system that are still in the cache. It’s a great utility. Better still, you can get specific statements from the code that are actively running through sys.dm_exec_requests or ones that have run through sys.dm_exec_query_stats. To do this is very simple. Each of these DMV’s has a pair of columns, statement_start_offset and statement_end_offset. These columns, and I’m quoting directly from books online measure the “number of character” offset from the beginning of the SQL string and from the end of the SQL string. Using these values you can retrieve an individual statement out of a stored procedure that has multiple statements.

But… Here’s where things get tricky. Try this on your machine:

SELECT SUBSTRING(dest.text, (der.statement_start_offset ) + 1,
(der.statement_end_offset - der.statement_start_offset) + 1)
,LEN(dest.text) AS CharLength,
der.statement_start_offset,
der.statement_end_offset
FROM sys.dm_exec_query_stats AS der
CROSS APPLY sys.dm_exec_sql_text(der.sql_handle) AS dest
WHERE der.statement_end_offset > -1

You might get an error or you might get a bunch of really odd looking statements in the first column, starting part way into TSQL and cutting off after they’re done or before they’re over. It’ll look odd. But what’s the deal? The SUBSTRING function should work. Logically it’s configured correctly. Here’s the problem.

The [text] column in sys.dm_exec_sql_text is of the datatype NVARCHAR(MAX). Unicode. If you look at the length of the text, it’ll tell you exactly how many characters you see in the string that called to your server. But, the statement_start_offset and statement_end_offset are measuring something different. They’re not measuring characters, they’re measuring unicode characters. Try this query instead:

SELECT SUBSTRING(dest.text, (der.statement_start_offset / 2) + 1,
(der.statement_end_offset - der.statement_start_offset) / 2+ 1),
LEN(dest.text) AS CharLength,
DATALENGTH(dest.text) AS DLength,
DATALENGTH(dest.text) / 2 AS HalfDLength,
der.statement_start_offset,
der.statement_end_offset
FROM sys.dm_exec_query_stats AS der
CROSS APPLY sys.dm_exec_sql_text(der.sql_handle) AS dest
WHERE der.statement_end_offset > -1

You can see that the character length is, whatever it’s supposed to be, but the DATALENGTH is twice that much. Unicode, as we all know, includes a byte to identify the character set. That’s included in the character count in statement_start_offset and statement_end_offset.  You need to take that into account when dealing with these “characters.”

Permalink 1 Comment

When did this statement start?

July 28, 2009 at 10:19 am (SQL Server 2005, SQL Server 2008, SQLServerPedia Syndication, TSQL) (, , , )

UPDATE: This post is incorrect. Adam nailed it in the comments. I explain my mistake here.

A question came up over at SQL Server Central where someone was wondering if it was possible to know when a given statement within a batch started. Immediately I thought, oh yeah, that’s easy, use the sys.dm_exec_requests dynamic management view (DMV). Done.

Wrong. The original poster pointed out that I had assumed that the values present in the DMV represented statement level values, but they show the batch. While the DMV shows a start_time, that time is the start of the current batch, not the statement within the batch. Now the question was, where else might I get this data? I next tried sys.dm_exec_sessions because it has the last_request_start_time value. Sure enough this worked.

Don’t believe me? This time I tested it. First, I set up a batch that ran a few longish queries:

BACKUP DATABASE AdventureWorks
TO DISK = 'c:\bu\ad.bak'
WITH INIT;
DBCC CHECKALLOC(AdventureWorks);
DBCC CHECKDB(AdventureWorks);
DBCC CHECKCATALOG(AdventureWorks);
BACKUP DATABASE AdventureWorks
TO DISK = 'c:\bu\ad.bak'
WITH INIT; 

Then I wrote a little loop that would insert data from both DMV’s, once every second for a minute:

SET NOCOUNT ON;
TRUNCATE TABLE dbo.dmR;
TRUNCATE TABLE dbo.dmS;
DECLARE @CheckTime DATETIME = DATEADD(ss,60,GETDATE())
 ,@CurrTime DATETIME = GETDATE();
WHILE @CurrTime < @CheckTime
BEGIN
INSERT INTO ... SELECT ... FROM sys.dm_exec_sessions
INSERT INTO ... SELECT ... FROM sys.dm_exec_requests
WAITFOR DELAY '00:00:01';
SET @CurrTime = GETDATE();
END

Then it was a question of hitting the go button. The results are pretty clear. If you look at sys.dm_exec_requests data, you’ll see the start_time doesn’t change, but, the work being performed, visible in the command and plan_handle columns changes. You can also see the statement_start_offset and statement_end_offset changing. These values will allow you to pull data in combination with the sys.dm_exec_sql_text() dynamic management function.

 start_time             command         statement_start_offset statement_end_offset plan_handle
2009-07-28 10:42:09.447 BACKUP DATABASE 0                      138                  0x060001007D931719B8C0BF0D000000000000000000000000
2009-07-28 10:42:09.447 DBCC            140                    206                  0x060001007D931719B8C0BF0D000000000000000000000000
2009-07-28 10:42:09.447 DBCC            140                    206                  0x06000F00AF16F10FB8C04D0D000000000000000000000000
2009-07-28 10:42:09.447 DBCC            208                    268                  0x060001007D931719B8C0BF0D000000000000000000000000

But, as you can see, the start_time stays the same. Looking at the last_request_start_time and last_request_end_time in the sys.dm_exec_sessions DMV, you can see these values changing in conjunction with the changing values in sys.dm_exec_requests.

last_request_start_time last_request_end_time
2009-07-28 10:35:21.500 2009-07-28 10:35:51.170
2009-07-28 10:42:09.447 2009-07-28 10:35:51.170 

I’ll leave at as an excercise for the reader (or for another post for myself) to put together the DMV’s and DMF’s that would allow you to combine this data and show exactly which statement was being executed at which moment. The point, it is possible to determine exactly which statement is currently being executed within a batch process, and when that statement started.

Permalink 5 Comments

MS Field Engineer’s on Performance Troubleshooting

July 20, 2009 at 7:01 am (SQL Server 2005, SQL Server 2008, TSQL) (, , , )

Do you want to get a glimpse into how the Microsoft Field Engineers would go about troubleshooting performance issues on your server? Then go and read this blog entry by Denzil Ribeiro. Not only is this an excellent how-to on troubleshooting performance problems, but Mr. Ribeiro provides multiple links that describe the concepts he’s dealing with further, making it a great piece of documentation.

The MS Field Engineer blog is not terribly active, but what gets posted there is worth reading. If you don’t have it on your feed list, you should.

Permalink Leave a Comment

Missing Index Information and Query Stats

February 12, 2009 at 3:49 pm (SQL Server 2005, SQL Server 2008, SQLServerPedia Syndication, TSQL) (, , , , )

So the goal was to find a way to pull information from sys.dm_exec_query_stats so that we could identify poor performing procedures that were in cache at the moment and combine it with missing index information from sys.dm_db_missing_index_details. We’re combining these because we’re working with a Microsoft Dynamics CRM database that is almost all ad hoc queries and lots of them are against tables with missing indexes. The hope was to identify necessary indexes merely by looking at the longest running queries.

Unfortunately there is no way to combine data from the missing indexes set of DMV’s and all the execution DMV’s that show query stats, execution plan, etc. None of the missing index tables has a plan handle or a plan hash column that would allow you to combine that data with the query data to identify which queries would directly benefit from the index if it were created.

But, if you look at the query plans in sys.dm_exec_query_plan, you can see the missing index information there. What to do? XQuery.

Since the query_plan is stored as XML, simply writing a small XQuery exist() function will do the trick:

SELECT  TOP 10 *
FROM sys.dm_exec_query_stats s
   CROSS APPLY sys.dm_exec_query_plan(s.plan_handle) AS p
WHERE  p.query_plan.exist(
‘declare default element namespace “http://schemas.microsoft.com/sqlserver/2004/07/showplan&#8221;;
/ShowPlanXML/BatchSequence/Batch/Statements/StmtSimple/QueryPlan//MissingIndexes’) = 1
ORDER BY s.total_elapsed_time DESC

This is a pretty simple example, and yes, in reality you would not want to use SELECT *.  You would want to specify those columns that you were really interested in. Also, this allows you to get performance information from queries that show a MissingIndexes element in the XML of the showplan,  but I haven’t pulled the Missing Index data out and displayed it. That can be done, but I’ll leave it as homework for you for now (and because I’m still having a hard time with XQuery).

A quick nod to Tim Ford for the advice on the DMV’s. Please finish that book soon.

Permalink 10 Comments

2008 Index Fragmentation

December 18, 2008 at 1:26 pm (SQL Server 2008) (, , , , , , , )

I forgot all about this, but a script I wrote on using all the new functionality of dynamic management views & functions to do index defragmentation and rebuilds got published over at SQL Server Central.

It could stand a bit of tweaking, but gets the job done on several of the systems I’ve tested it on so far.

Permalink Leave a Comment

Dynamic Management Views Put to Work on Blocking

December 3, 2008 at 6:53 pm (SQL Server 2005, SQL Server 2008, TSQL) (, , , , , )

This is my first pass at a modern (2005/2008) blocking monitoring script. I think it’s a decent blocking script to capture information about blocks as they are occurring. Filters can be applied and it wouldn’t be hard at all to add on other information such as execution plans, plan hash, etc.

SELECT  tl.request_session_id AS WaitingSessionID

       ,wt.blocking_session_id AS BlockingSessionID

       ,wt.resource_description

       ,wt.wait_type

       ,wt.wait_duration_ms

       ,DB_NAME(tl.resource_database_id) AS DatabaseName

       ,tl.resource_associated_entity_id AS WaitingAssociatedEntity

       ,tl.resource_type AS WaitingResourceType

       ,tl.request_type AS WaitingRequestType

       ,wrt.[text] AS WaitingTSql

       ,btl.request_type BlockingRequestType

       ,brt.[text] AS BlockingTsql

FROM    sys.dm_tran_locks tl

        JOIN sys.dm_os_waiting_tasks wt

        ON tl.lock_owner_address = wt.resource_address

        JOIN sys.dm_exec_requests wr

        ON wr.session_id = tl.request_session_id

        CROSS APPLY sys.dm_exec_sql_text(wr.sql_handle) AS wrt

        LEFT JOIN sys.dm_exec_requests br

        ON br.session_id = wt.blocking_session_id

        OUTER APPLY sys.dm_exec_sql_text(br.sql_handle) AS brt

        LEFT JOIN sys.dm_tran_locks AS btl

        ON br.session_id = btl.request_session_id;

Permalink 3 Comments

More Dynamic Management Views: sys.dm_tran_locks

December 2, 2008 at 9:05 am (SQL Server 2005, SQL Server 2008, TSQL) (, , , , , , , )

I’m working on the chapter on blocking in the new book. Explaining blocking of course means explaining locks. Prior to 2005, to understand locks, you went to sp_lock. Not anymore. Now you can query sys.dm_tran_locks. It’s so much more sophisticated than the old system procedure.  Best of all, the information within it is simply a view into the internal locking infrastructure, so you’re not placing extra load or extra processing on the system to marshal this data. A simple query to get basic locking information would look like this:

  SELECT tl.request_session_id

            ,tl.resource_database_id

            ,tl.resource_associated_entity_id

            ,tl.resource_type

            ,tl.resource_description

            ,tl.request_mode

            ,tl.request_status

  FROM sys.dm_tran_locks tl

That just outputs roughly the same information as sp_lock. Lots more detail, not available in sp_lock, is available if you need it. Things like resource_lock_partition to identify which partition a lock is on or  request_reference_count which shows how often the same lock has been requested by a given resource. Then, armed with this data, you can go after other dmv’s. Take, for a GLARING example, sys.dm_os_waiting_tasks. Hmmm if we were to combine something that showed locks with something that showed tasks that were waiting, what might you arrive at? BLOCKING!

The BOL shows a neat little query for just such an occasion:

SELECT
        t1.resource_type,
        t1.resource_database_id,
        t1.resource_associated_entity_id,
        t1.request_mode,
        t1.request_session_id,
        t2.blocking_session_id
    FROM sys.dm_tran_locks as t1
    INNER JOIN sys.dm_os_waiting_tasks as t2
        ON t1.lock_owner_address = t2.resource_address;

Clearly there is more here to explore. You can even go on to combine these dmv’s with the one’s that show the procedure cache so you can capture the execution plan of queries that are blocking or being blocked. I know dmv’s have been featured in a lot of articles and presentations lately, but I still think lots of people are unaware of just how useful they are. You need to examine this resource further if you’re working in SQL Server 2005/2008. More to come on sys.dm_os_waiting_tasks.

UPDATE: Typo corrected in the first paragraph. Thanks Jack.
ANOTHER UPDATE: More Typo’s corrected in the first paragraph. Thanks Gail

Permalink 6 Comments