When you execute a multi-statement user-defined function you may see an execution plan that looks something like this:

It appears as if the cost of the UDF is free. This is especially true if you use the UDF in a query with other objects, such as joining it to actual tables. Since the optimizer always assumes a multi-statement UDF has a single row for statistics estimates, it’ frequently displays a low cost.

But you know that there’s more going on there, right? It’s a multi-statement UDF because it’s doing a lot of work, but that is not reflected in the execution plan.. or is it?

What if we went after the cache? Let’s run this little query:

SELECT  deqp.query_plan,
dest.text,
SUBSTRING(dest.text, (deqs.statement_start_offset / 2) + 1,
(deqs.statement_end_offset – deqs.statement_start_offset)
/ 2 + 1) AS actualstatement
FROM    sys.dm_exec_query_stats AS deqs
CROSS APPLY sys.dm_exec_query_plan(deqs.plan_handle) AS deqp
CROSS APPLY sys.dm_exec_sql_text(deqs.sql_handle) AS dest
WHERE   deqp.objectid = OBJECT_ID(‘dbo.ufnGetContactInformation’);

This query doesn’t do anything really fancy. I’m using the sys.dm_exec_query_stats which holds aggregated performance metrics for any query currently in cache because it has the plan_handle that lets me look up execution plans in sys.dm_exec_query_plan. It just so happens that you also get the objectid there in the plan so we can look for the specific plan that corresponds to our UDF (I’m using an example from AdventureWorks2008R2). The results from the query look like this:

Each row represents a statement that has been executed from the UDF. There’s just a single plan for the UDF, and it looks like this:

Without even drilling down to all the details of what’s going on in the plan, I think we can agree, that this UDF is not zero cost, but may in fact be extremely expensive depending on what’s going on inside that execution plan.

Why is this useful? Because it lets you look behind that simplistic… lie, that is shown as a plan for the execution of a UDF to see what the UDF is actually doing. This may make it possible to improve the performance of the UDF since you’ll be able to identify missing indexes and other information thanks to your direct access to what’s going on inside the UDF.

I had demoed this during my 24 Hours of PASS presentation and was asked to put the code up on my blog, so here you go. I hope it’ proves helpful.

There’s a very old saying, “When you find yourself in a hole, stop digging.”

And my evidence today is:

That’s certainly not the hairiest execution plan I’ve seen. In some ways, it’s not all that horrible. But it sure is evidence that someone was down in a hole and they were working that shovel hard.

If you’re interested, most of the operators are scans against a table variable that’s 11 million rows deep. There are also table spools chugging away in there. And the select statement only returns 1500 rows.

Please, stop digging.

The question came up, what are the top 3-5 things that you look at in a query. I realized then that I hadn’t really written them down. There are some areas that let me know pretty much immediately where problems lie within a plan. You don’t necessarily know the answer from looking at these things, but you know you have a problem. Being me, I couldn’t stick to 5, so here are 6:

1. Immediately check the properties on the first operator (SELECT/DELETE/INSERT). There’s tons of information in here and people frequently just ignore it. You can see if the plan is based on full optimization or not. That immediately tells me if I’m working on the optimizer’s best estimate at a plan or I’m looking at a timeout. If it’s a timeout, I know I can’t count on this plan being good. Also I get the parameter compile time & run time values to help determine parameter sniffing issues in the properties.
2. Warnings. If you see no join predicate warnings, that should jump up and poke you in the eye like some jumping eye-poking little monster. Same goes with missing statistics. The new warnings in plans in 2012 are equally important to know about. These are quick pieces of information that should immediately point you in a direction of inquiry within the plan.
3. The most costly operations. Yes, I know you can’t trust these values because they are just estimates. Yes, the estimated operator cost is the same in both estimated and actual plans. No measurements of actual cost are taken by an execution plan. But these are the numbers available, so I use them. They’re accurate more often than not and quickly lead you to the possible source of the problem.
4. Fat pipes. Now really, these are usually just an indication of volume and knowing that you’re moving lots of rows helps you read a plan (umpty-million rows joining umpty-million rows through a Loop might be an issue). But the real alarm bells go off when you see big fat pipes going to little skinny ones or skinny ones to big fat ones or even skinny-fat-skinny. That’s a huge indicator of something
5. Extra operators. This is like that old statement about pornography “I can’t give you a precise definition, but I know it when I see it.” It’s looking for stuff that doesn’t belong. For example, you don’t have a single ORDER BY statement, but there sits a Sort operation. Why? That’s my “extra operator” indicator telling me to dig deeper.
6. Scans. Scans are not necessarily bad and Seeks are not necessarily good. In general terms, with smaller data sets, you usually would expect to see a Seek over a Scan. Scans can be the right, good, and best choice, especially for very large data sets and in other situations, but they are an indicator of potential issues.

After that, you have a whole slew of things you can get worked up about. Table Spools in SELECT statements are usually not good. Look for indications of multi-statement UDF’s (Scan’s with zero cost). Loop joins when a Merge makes more sense, Merges where you ought to see a Hash, missing index information, mismatch between estimated & actual, blah, blah, blah… You get the point. There’s just tons & tons of information within execution plans. But that list of six are usually the first things I look for.

I’ve been working with execution plans quite a lot in SQL Server 2012. There are a number of changes, most of them associated with new or different functionality. I had not noticed anything really fundamental until recently. I’ve become a huge proponent of always checking the properties of the SELECT statement. There’s so much useful information in there about what’s happened with the plan generation in the optimizer (not low level stuff, but the big picture items) that you should always be checking it first as a fundamental part of your plan examinations. Here’s an example from SQL Server 2008R2:

You can see cool stuff like the size of the plan, the time it took to compile, the optimization level, the reason for early termination. Many of the properties on this page are useful for determining information about this plan and how the optimizer dealt with it.

Here’s the property sheet from SQL Server 2012 from an identical query against an almost identical database (AdventureWorks2008R2):

Oh yeah, we’ve got some meat on this bone to chew on. All the good stuff from the original is still in place. But we have more added. Working from the top, we see MemoryGrantInfo. I’ll have to do some more research and testing to validate this, but I’m pretty sure that’s a measure of temporary data storage assigned for expenseive join and sort operations, and now it’s built right into the execution plan. That’s going to be a very useful tool. Note that this plan, while marginally complex, doesn’t need any of the memory grant.

Next is the OptimizerHardwareDependentProperties which very much explains itself don’t you think.But how cool to know that for this plan the optimizer thought it could get 2 processors to work. Also that the optimizer takes memory and pages into account as part of its internal processes, probably as part of determining parallelism as well.

Next is RetrievedFromCache. At first I about did a backflip to know that this information, whether or not a query was pulled out of the cache, was on the execution plan, but I saw it set to true for the first execution of the query. Out comes DBCC FREEPROCCACHE()… nope, still retrieving it from cache, whatever that means. OK, how about a CHECKPOINT, DBCC DROPCLEANBUFFERS(), DBCC FREEPROCCACHE()… no change. More work is needed to understand this one (and yes, before you ask, I looked it up in Books Online. Nothing).

And at the bottom is some of what I was told is coming, new warnings about things that can affect plans. In this case, a conversion that’s occurring within a calculated column that will prevent good cardinality estimates, possibly leading to scans. We’re just retrieving the data here, so it doesn’t affect us, but it could. This is also excellent information that is going to be extremely useful. The only shortcoming with this one is, that there’s no indication where the problem is occurring. I had to do a quick search in the XML to identify which operation had the questionable column.

I’m pretty excited about these little additions to the SELECT operator.

One of the greatest things about all the DMOs is how you can combine the information they present to you with execution plans. It allows you to see what a query is doing, even as it’s executing, because the plan is created first. I couldn’t possibly emphasize enough how important that’s going to be in your day-to-day troubleshooting.

Even better is the fact that you’re going to be able to make use of XQuery to pull useful information out of the execution plans that are in cache.

Or are you?

Here’s a query to pull some information out of the procedure cache:

SELECT  deps.type_desc,
deps.last_execution_time,
deps.execution_count,
deps.total_logical_reads,
dest.encrypted AS EncryptedText,
dest.text,
deqp.query_plan,
deqp.encrypted AS EncryptedPlan
FROM    sys.dm_exec_procedure_stats AS deps
CROSS APPLY sys.dm_exec_sql_text(deps.sql_handle) AS dest
CROSS APPLY sys.dm_exec_query_plan(deps.plan_handle) AS deqp
WHERE   dest.text LIKE 'CREATE PROCEDURE dbo.GetSalesDetails%' ;

When I run this, it has just two (2) reads and completes in about 38ms on my system. It works great. But what if I were interested in seeing the operators in this plan and the costs associated? Very straight forward. This would do it.:

SELECT  Xplan.p.value('declare default element namespace "<a href="http://schemas.microsoft.com/sqlserver/2004/07/showplan";">http://schemas.microsoft.com/sqlserver/2004/07/showplan";</a>
@NodeId', 'int') AS NodeID,
Xplan.p.value('declare default element namespace "<a href="http://schemas.microsoft.com/sqlserver/2004/07/showplan";">http://schemas.microsoft.com/sqlserver/2004/07/showplan";</a>
@PhysicalOp','varchar(50)') AS PhysicalOp,
Xplan.p.value('declare default element namespace "<a href="http://schemas.microsoft.com/sqlserver/2004/07/showplan";">http://schemas.microsoft.com/sqlserver/2004/07/showplan";</a>
@EstimatedIO','decimal(7,6)') AS EstimatedIO,
Xplan.p.value('declare default element namespace "<a href="http://schemas.microsoft.com/sqlserver/2004/07/showplan";">http://schemas.microsoft.com/sqlserver/2004/07/showplan";</a>
@EstimatedCPU','decimal(7,6)') AS EstimatedCPU,
dest.text,
deqp.query_plan
FROM    sys.dm_exec_procedure_stats AS deps
CROSS APPLY sys.dm_exec_sql_text(deps.sql_handle) AS dest
CROSS APPLY sys.dm_exec_query_plan(deps.plan_handle) AS deqp
CROSS APPLY deqp.query_plan.nodes('declare default element namespace
"<a href="http://schemas.microsoft.com/sqlserver/2004/07/showplan";">http://schemas.microsoft.com/sqlserver/2004/07/showplan";</a>
//RelOp') XPlan (p)
WHERE   dest.text LIKE 'CREATE PROCEDURE dbo.GetSalesDetails%' ;

Here’s where it gets fun though. First, this doesn’t show me the reads & stuff. But it does show me that it’s taking 160ms to return five rows (five operators, five rows). Which seems like an extraordinary long time until you look at one little part of the XQuery: ‘//RelOp’

The // is basically like putting % into a LIKE clause (see this post and the discussion). It’s a wild card search. Go through the whole structure and find the operators, RelOp. That’s a very time consuming and expensive mechanism for retrieving XML data. Unfortunately, because of how the XML is structured, sort of mirroring how the plans operate, the operators are nested inside of each other. Which means you can’t know the exact path to the operators unless you already knew the plan. This means you’re going to be doing wild card searches against your XML.

You might think to yourself, “Fine. No biggie, it just takes a little longer.” And that would be true, except, I’m looking at a plan with five operators. Examine your plans. How many of the problematic ones, the ones you’re going to want to query contain just five operators? And now you begin to see the issue. As the plans get bigger and/or, you’re unable to filter as many as possible from the query, the queries get slower and slower. They can, and probably will, affect your production server and it’s performance.

What to do? Ah, well, that’ll have to wait for the next blog post on this topic. I’m working on a good solution now.

I write quite frequently about SQL Server Execution Plans. I started in that area just because that’s how you figure out what a query is doing and sooner or later, we all have to tune a query. I found I was doing it sooner and more frequently. When the opportunity came up to write a book , I jumped on it. Now I find myself presenting, rather frequently, on execution plans.

One of the people I’ve learned from over the last several years is Gail Shaw (blog|twitter). I first saw Gail on stage at the PASS Summit, I think it was 2007. A co-worker of mine was picked, along with Gail, to go on stage for the Quiz Bowl. Gail was answering all the questions. If you go over to SQL Server Central, Gail doesn’t answer all the questions, but she’s involved most of the important discussions. If you read her blog and articles, Gail has also been deeply involved in query tuning and execution plans for a long time.

Why am I telling you all this?

In just a little over three weeks, Gail and I will be presenting an all day seminar on SQL Server Execution Plans. We’re going to cover the optimizer and the plan cache and we’re going to show you how to read a ton of execution plans. We’re going to go over how to spot problems and how to fix them. We’ll be examining plans from people in the audience (yeah, bring your problem plans) live on stage. You’ll get the chance not just to hear us talk, but to ask us questions, to get clarification on topics and meet other people who are learning the same stuff you are.

In short, we’re going to be having a really good time and talking a lot about Execution Plans. This is your chance. Register for the Summit and, please, register for our pre-conference seminar. You won’t be disappointed.

I was presenting on execution plans when another question came up that I didn’t know the answer to immediately. Yes, I know you’ve seen that phrase before on this blog. I love presenting because you get exactly the kinds of questions that make you think and make you learn. I’m presenting, in part, to learn, just as much as I am to teach. It was the same with kenpo. The more I taught, the better I learned the art. Wait, this isn’t supposed to be a blog post about learning. This one is about statistics.

The question was, does the execution plan have the statistics that were used by the optimizer to decide on the execution plan. And no, what was meant, was not does it show the estimated rows, which come from the statistics, but specifically does it show that it used a set of statistics named X? The answer to that is yes & no. Or, to be more DBAish about it, it depends.

Let’s take a really simple query run against a freshly installed copy of AdventureWorks2008R2:

SELECT p.BusinessEntityID,
p.FirstName
FROM Person.Person AS p
WHERE p.FirstName LIKE 'Toni%';

This query generates this execution plan:

Yes, a very sophisticated and hard to understand execution plan. Now, here’s the deal, there were two sets of statistics used to make this plan, but only one of them can be seen in the plan. See any statistics there? Sure you do. IX_Person_LastName_FirstName_MiddleName. That is one of the two sets of statistics that were used to make this execution plan. Where’s the second set? Not in the execution plan.

[sourcecode language=”sql”]sp_helpstats N’Person.Person’, ‘ALL’;[/sourcecode]

The results are here:

There is the second set of statistics used for this query, right at the top. Because I was searching the FirstName column, the optimizer found that it did not have the statistics it needed, so they were created, on the fly, and then, were not a part of the execution plan. Further, I probably looked at other statistics such as the PK_Person_BusinessEntityID because that’s the clustered index for the table. It could have scanned that to get the list of values just as easily as the other index. But, that other index is probably smaller, which means fewer pages scanned.

So, back to the question, can you see the statistics used by the optimizer inside the execution plan? Some of them, yes, but not all of them.

Please, if I’m presenting, ask questions. I’ll know a few of the answers, right off the top of my head. Others will make me go and learn so that I can answer the next person who asks the same question. I don’t mind losing at a game of Stump the Chump, so let’s play.

I have to say, I only recently noticed this on a tool tip:

and this in the property sheet:

The bad news is, I noticed them while presenting. The worse news is, I said them out loud and then, inevitably, someone in the audience, I forget who it was, might have been Neil Hambly (blog|twitter) said, “What’s that?” Which left me standing there with a slack-jawed expression (one that comes naturally from years & years of practice). I didn’t know. I couldn’t remember having seen one before.

Here’s a query that you can run in AdventureWorks2008R2 to get a look at this critter:

SELECT  soh.PurchaseOrderNumber,
soh.AccountNumber,
p.Name,
sod.OrderQty,
sod.LineTotal,
cc.CardNumber
FROM    Sales.SalesOrderHeader AS soh
JOIN Sales.SalesOrderDetail AS sod
ON soh.SalesOrderID = sod.SalesOrderID
JOIN Production.Product AS p
ON sod.ProductID = p.ProductID
JOIN Sales.CreditCard AS cc
ON soh.CreditCardID = cc.CreditCardID;

The entire execution plan looks like this:

We’re focused on the Hash Match join at the top. For logical processing it would be the first operation. For physical operations it would be the last.

The way a Hash Match works is by creating a hash table (in tempdb by the way) and making a hash value. Then, it makes a hash value of the stuff being compared and tries to find matches in the hash table. That’s it.

The residual is if there are additional predicates that also must be matched in order to fully satisfy the query. That’s all. It’s actually quite simple.

What are the implications? Well, this is where it gets fun. You see, the first match, in the hash has to take place, and then, it also has to do the residual probe. The first match is part of the process. The second match is additional work. That’s not good. You can see it in this example plan because the Hash Match operation is estimated as the most costly and that’s probably true.

The key is, drill down to understand what your execution plans are up to.

How do you define an expert? My personal definition: An expert is the person that is a chapter ahead of you in the book.

Why am I talking about this? Just that I’m feeling more stupid than usual lately. In the last two weeks I’ve had people bring up through various discussions, documents, what have you, four different SQL Server trace flags that will affect how SQL Server builds execution plans and I’ve never heard of any of them before.

I’ve never, ever, thought of myself as an expert in execution plans, despite having written a book about them. I just thought I had a good grasp on how they worked and I was willing to share. I didn’t know everything and never pretended to, but I thought I knew a lot. Then, in two weeks I find four different trace flags that I’ve never heard of, addressing interesting issues that maybe I should have known about. Holy cow!

I’ll try to put up a blog post on some of these trace flags that I’ve found. I’m also doing a little searching to see how many others I’ve missed. Here are the four:

2861: Includes zero cost plans in the cache.

2335: Extra memory messes up execution plans (by extra they mean >512GB)

2389: Ascending values stats cheat (pretty cool)

2390: A second, complimentary, ascending values stats cheat

I’ve talk about other trace flags in the past (and the fact that I was discovering them for the first time too). Microsoft’s “official” list is pretty small and only includes a single one relating to execution plans. Although, to be fair, that one is actually huge. But there are lots of others documented in various Knowledge Base articles but not listed as such in the core documentation.

More to learn, more to learn. That is a great, cool and humbling thing.

By the way, if you’ve ever been in the room when I got introduced as an “expert” and you saw me laugh at the introduction, this is why. I’m not an expert.

Oh, and worth mentioning, you should be very, very cautious when using trace flags. Check out this short blog post from Paul Randal (blog|twitter) on just that topic.

Ever looked at an execution plan? If you answered no, you can’t possibly have ever tried to tune a query, or, you’re doing it wrong. For every one else, no doubt you’ve looked at the tool tips or the property sheets of an operator and you’ve seen the Rebind & Rewind properties and wondered what the heck they mean. Me too.

I learned as much as I could for the book on execution plans and I spent two pages describing it. Then, a little while ago, on the SQL Cruise, someone asked me to describe them and I was flummoxed. Specifically they said the explanation in the book was insufficiently clear, so I promised to put together a blog post on the topic, both to attempt to clarify my explanation and to reacquaint myself with the topic.

These properties reflect the number of times an operator was initialized, or started. It’s that easy for the initial definition. But it gets complicated quickly. Rebind & Rewind are only applicable when dealing with a loop join. They don’t apply to other situations, which is why they’re mostly zero when you see them. They are only applicable to the inner side of the loop.

Not only are Rebind and Rewind only involved with loop joins, but they only apply to certain operators: Nonclustered Index Spool, Remote Query, Row Count Spool, Sort, Table Spool, and Table-valued Function.

The difference between a rebind and rewind has to do with the values that are part of the loop join itself. As those values change, as different data is accessed in the outer part of the loop, you see rebinds. When those values aren’t changed then you’ll see a rewind. You’ll also see that the aggregation of these values is equal to the number of rows in the outer join.

Here’s an example query:

SELECT  sod.SalesOrderDetailID
FROM    Sales.SalesOrderDetail AS sod
WHERE   LineTotal < (SELECT AVG(dos.LineTotal)
FROM   Sales.SalesOrderDetail AS dos
WHERE  dos.ModifiedDate < sod.ModifiedDate
)

It puts out an execution plan that’s pretty ugly, but at least it shoes a table spool in a loop join as you can see:

If you look at the properties then we can see the values showing multiple rebinds and rewinds that total up to the number of rows in the outer part of the loop.

That’s it in a nutshell. Hopefully I was able to clarify some from the original book. The book is actively undergoing an update and I’ll try to clarify that section further. For more on this topic, I recommend you look at this article by Fabiano Amorim (blog|twitter).