Transcript

A quick reminder: we defined our index with three key columns. It’s keyed first on LastName / primarily sorted by LastName. Then it is sorted by FirstName and then by EmployeeKey.

We have three included columns which are MiddleName, EmergencyContactName and Status.

Let’s look at an example query

I’m going to turn on actual execution plans using this button so that after I run my queries, SQL Server will tell me how it ran the query.

I’m going to run this query which says: find any rows you have where the LastName is ‘Czernek’ in the DimEmployee table, and I want to know the FirstName, MiddleName and LastName. Those are all key columns. Then I also want the EmergencyContactName and the Status, which are included columns.

When I execute this query, I find there is one row. There is only one employee with this LastName.

Finding the operation and number of logical reads from the execution plan

If I look at my execution plan, I can see that I only needed to use my nonclustered index. We only have two indexes on the table, ix_DimEmployee. This is my nonclustered index. I didn’t have to go look in the clustered index at the table for anything at all. Everything I needed was in that nonclustered index and I was able to do a seek.

Well, what kind of seek did I do? If I hover over that and look at the tooltip for my operator I can see that there is a seek predicate there.

I did a seek predicate on the LastName equals the operator I provided

My index has three key columns and, because I didn’t give it all three in my query, but I did give it the first one, the thing that everything is primarily sorted by, it said, “Well, I will go find all those rows for you.” I didn’t have any additional criteria, I don’t have any predicates other than my seek predicate. You will see in the future, sometimes up here we’ll see something that says ‘predicate’, without the word seek in front of it. That is just not there. So we had a seek.

How many pages did it have to read for this?

If I look at my properties, I’m going to right click and say properties, and I have my operator highlighted there. I’m looking at the properties for my nonclustered index. What I’m going to do is expand where it says ‘Actual IO Statistics’ here, to say: okay, tell me a lot more about the IO that you did, the pages that you read.

It says for this nonclustered index seek, you only did two logical reads. You only had to read two pages.

Now we know in theory from having examined this index that’s it a two level index, there’s a root page and then there’s four pages and the leaf. So we hypothesize: we read the root page and then we did a seek to one of leaf pages. That seems legit, but we can prove it with a trace.

I’m going to run an Extended Events trace using what’s called a debug event

This is in the debug category of Extended Events, meaning this isn’t something you would normally run. This can produce a large amount of data and it’s not something you would run against production. This is just for, in my case, learning. I’m going to check out what my session id is, I’m session id 52, and I’m going to plug it into this trace definition.

This says: I want to create an Extended Event session looking at the buffer latch acquired; I’m naming this buf_latch_acquired. I’m adding the events SQL Server latch_acquired. These are latches on pages in memory that are data pages in my buffer pool for a query. And when – I already ran this query that pulled the data into memory– when I run the query again, I’m going to need shared buffer latches on those pages to say, “While I’m looking at these pages, don’t let anyone else destroy them. Please protect them.”

What we are going to trace are this buffer latches, and we’re going to say, “Okay, what pages are you doing logical reads from, that you’re getting shared buffer latches on, just for my session.” So that I don’t get a bunch of gibberish from everyone else. I’ve set MAX_DISPATCH_LATENCY to three seconds, just to get it speedily.

I am the only one using this little test instance running this debug session.

I have created my trace, and I’m going to go ahead and start my events session, then re-run my query.

I get the same execution plan. Just for fun making sure, yes, once again in the one that we traced we did get two logical reads there.

I’m going to stop the trace and lets look at the results in Object Explorer

Going into the Management folder, expanding out under Extended Events sessions, and it’s always good to refresh. My trace has been stopped, but what I’m going to do is double click on the event file. I told this to write the results of the trace to a file on my file system. Then, I open it up, and I have run this trace a few times before so I’m going to sort the data descending by timestamp to see my most recent data.

Here are the latches that I’m looking for

I specifically, I even get latches from when I am doing things like stopping the trace– I do have to get some buffer latches then. I’m looking here at the rows for my select statement in my session, and I have two pages that I read.

I read page 158584, and let’s take a look at that page first. I’m going to copy out the page id, and now we’ll go back, and what we’re going to do is we’re going to plug this in to DBCC PAGE. Looking at this page: what are you really, page?

Just like we hypothesized, this is the root page for the DimEmployees table that we were looking at, and it knows who the child pages were

We’re looking for the LastName = ‘Czernek’. Based on these guideposts here, Cz is after Ch, and it’s before Gr, so this should be on page 158552. If we look at 158552 in DBCC PAGE and we scroll down, sure enough, here is the row that we’re looking for. Our query wants to return not only these key columns, but also the included columns that are on the child page. So if we look in our trace, sure enough that was the second page that it read.

It went to the root page and ‘seeked’ to that one leaf page, it did not have to read other pages.

Very, very cool that we can trace that and prove it.

Lets look at a slightly more complicated example.

What if we’re trying to search on a column that isn’t the leading column, and we don’t have LastName in there?

I’m looking in this case for the same row, but who knows, maybe there are other Pawel’s in there! I want to know information for all of my employees with the FirstName Pawel.

All the rows are sorted first by LastName, there could be Pawel’s anywhere in my child pages, so we can’t seek on this index. The optimizer will look around and say, “Is there a great index for me that leads on FirstName?”

My clustered index on the table is keyed on an EmployeeKey, that doesn’t help. I can’t seek on that to find the FirstName, but do I have a nonclustered index that’s great for this? I don’t. Currently, I have the clustered index that’s keyed on EmployeeKey, and I have a nonclustered index that leads on LastName, but does have FirstName in there– and the nonclustered index has all these other columns as well.

The SQL Server is smart, it says: I could scan that nonclustered index. I could also scan the clustered index. But it will look at, “Okay, well, how many pages are in them?” It will say: if I’m going to scan something, I will pick the one that’s smaller to scan. (That is why I didn’t leave my fill factor at one percent, by the way! Because that large page count would make it disfavor the index.)

Lets go ahead and start our trace again, and with our trace going we’re going to run this query looking for all rows with this FirstName Pawel. In fact, there is only one row, our familiar row.

When we look at our execution plan, we see not an index seek but an index scan

It said, “I had to scan the index, I couldn’t find the data directly and efficiently by following the keys.” Yes, this is a key column but it is not the leading key column, and you don’t have the leading key column in your predicate. This is the second [key column], but I could scan the index.

When I look at the tooltip for this now, there is no seek predicate here at the bottom.

I wasn’t able to seek on something, but I do have a non-seek predicate

This is a filter that’s been collapsed into the seek, where it’s: okay I’ve got to look at all these rows, and then for each one I’m going to check: Are you Pawel? Are you Pawel? Is your FirstName Pawel? Is your FirstName Pawel? So that I can get the data out of there.

How many logical reads did I do? Looking at our properties, in this case we did six logical reads. Okay, well six is an interesting number. Before we had to do two: the root page and the leaf page.

You may recall that there are only four leaf pages for this index. Our root page plus our leaf pages equals five pages. We did six [logical reads].

Well, let’s look at our trace and see what it captured

I’m going to stop our trace and then let’s go ahead and reopen our trace file and check out our latest results in there. We’ll re-sort by the timestamp descending, and let’s take a look at what we have here for our query. Things are a little different now for our query.

We have, let’s highlight this, I’m going to pop this up– this is the query that was looking for the FirstName. We have more pages listed here. What I’m going to do is do a new vertical tab group so we can have this open at the same time as our other window. We’ll scroll over a little bit and look at some of these pages that get hard to read.

The first page we have is page 187

We’re going to go ahead and look at page 187. This is a page that, hmm. I’m not sure from this information. This is a page who has child pages. Let’s look at this page with dump style = 2, to get more information about what this page is. When I ran this with dump style = 2, I get some information from the metadata: what is the object_id? This is object_id 74, sounding a lot like a system object, right?

This is a system table named syssingleobjrefs.

These reads are of system tables– and we can kind of tell from the low page numbers like 97 there– if we have to pull some system pages, not all of it will show up in the count of logical reads for our queries. Well let’s look at his one, page 93078.

Let’s copy that page id, and we’ll paste that in. Let’s first show that with dump style 3, just investigating what that page is– this looks like it’s another system page. It doesn’t look, yeah, if we look at some of the keys on here, this is kind of interesting. I think this is related to some of the Management Studio tools I showed. We can just tell from the guideposts for what the child pages are ms_DiagramPane2.

So this isn’t related to our query, either.

Let’s find the pages for that scan

When we get up here, and we get into the 158___’s, this looks like the actual pages that are being counted in the six pages. I’m going to zoom a little, and we’ve got one, two, three, four, five six pages here that are related to our table. One of these pages, the root page, is actually listed twice.

Lets go ahead and inspect those. I’m going to get this 158584 value and copy it to my clipboard. Here it is, I have this here– or a similar value I had there already– and now let’s go ahead and look at that page. Sure enough, if we look at that, that is the root page four our index that has the four child pages on it. We can confirm, let’s zoom in here: this is our root page of the index and then here is… It went to the first page in the leaf, it then found the second page on the leaf and was following those pointers to scan through the leaf.

We do have some additional buffer latches in here just from me having all my tools open in Management Studio when using them in my session.

So it is really fun, even if we have these extra pages in there by using dump style=2 and dump style=3 and looking for the object_id and decoding it, we can figure out, “Hey, what was that a system object that you had to go read?”

But we can tell that the scan: it went to the root page, then it went to one end of the index and it said, “I’m going to go ahead and scan through you using the pointers in there.”

That example was the query that was looking for FirstName, which is a key column, but not the first column in the key. We didn’t provide a predicate for the first column in the key .

What if we do something similar, but we’re searching in the Status column?

Status is an included column, it’s not in the key at all. Can it use our index?

It can use our index. If we execute this query, SQL Server will check and see: “Do I have a great index that leads on Status where I can efficiently find this?” We don’t, in this case. EmployeeKey isn’t going to work, we’re not going to be able to seek on that for starters. And then this index, this smaller index is a good choice, though, because it has all the columns we need and is smaller than the clustered index. So we can do a scan.

If we look at the properties of that scan, we do not have a seek predicate, but we do have a predicate, otherwise known as a hidden filter. We’ll look it at ever row and say: are you current? are you current? Are you current?

So SQL Server can, if we put predicates on those included columns, it can use them to help filter data, but we can’t seek on included columns because they’re simply tacked on, and they ride along in the leaf of the index.

They don’t impact the sorting at all, and we also don’t have any guideposts for them in the upper levels of the index.