Operator Time Oddities In SQL Server Query Plans

SILENCE YOUR CELL PHONES

---

Thanks for watching!

Video Summary

In this video, I dive into the complexities of operator times and execution plans in SQL Server, particularly focusing on how they behave differently in batch mode versus row mode. I explain that while these new features are incredibly valuable for query performance tuning, there are some quirks that can make them confusing. For instance, I demonstrate how operator times are measured per operator in batch mode but add up along the plan in row mode, and how there’s no clear visual indicator of when a switch between modes occurs. By walking through these examples using SSMS 18, I aim to help you better understand and navigate these peculiarities, making your query tuning efforts more efficient.

Full Transcript

Howdy folks, Erik Darling here with Erik Darling Data. Still six months in I have managed not to fire myself which is amazing because I always considered me to be one of my most underperforming employees so it’s a real tribute to I guess nepotism that I haven’t fired myself yet. Anyway, I’m here to talk about operator times and execution plans. I want to talk about them because they can be really, really confusing. And hopefully me recording this video will help you understand exactly what’s going on with them. Now, they’re only available in SSMS 18. So if you aren’t using SSMS 18, I actually understand why because it’s really buggy. crashes more than normal SSMS. But this is a great new feature for especially unemployed query tuners who, you know, need to make a buck here and there, spare changing outside bodegas and, you know, trying to get some money up for a beer and a beer and a banana or something. But yeah, these things are weird and I’m going to try to explain why. Now, in SQL Server, well, I mean, 2019 CTP3 batch mode is generally available for rowstore queries. You could still see this in SQL Server 2017 or 16 or wherever else, you know, batch mode is available or wherever you have chosen to sneakily introduce batch mode into your rowstore queries with the temp table trick or with the filtered index trick. But anyway, this gets really odd. Now, the first thing I want to explain is that in batch mode plans, the timing is per operator. But there are two things that suck. One is that there’s no general indicator of which operators ran in batch mode. There’s one operator in this plan, that window aggregate that can only happen in batch mode. So we know that’s batch mode.

But if you look at the index scan, the sort, the compute scaler, the filter, any of those other operators, there’s no visual indicator that they happened in batch mode. The other thing that sucks is that there’s no visual indicator when we switch between row mode and batch mode. There’s nothing that says, there’s nothing that says, hey, like there’s no, there’s no, there’s no like little like interruption in the arrow or like, you know, little like, like, like little flippy sign that says, hey, that we switched here. We made it, we made an adjustment. Now, I’m going to show you why this is important. So I run this, I run this query, and this query does run for about four and a half seconds that that timing isn’t up for debate. That did happen in about four and a half seconds.

But what you’ll see across the bottom of the execution plan is that each, like the operator times for each one of those operators looks funky. They don’t add up. So this ran for 1.2 seconds, this ran for 2 seconds, this ran for 0.15 milliseconds, this ran for 0.9, 900 milliseconds, or 157 milliseconds, 900 milliseconds, 0.37 milliseconds.

So all of these are individual times. And if you add them up across the line, they’ll add up to about 4.3. But what gets weird is this is batch mode, right? So batch mode, this is batch mode. In fact, all of these are batch mode up to right here. Where they stop being batch mode is that this gather streams. This is row mode. And this top is also row mode.

There’s a difference between batch mode and row mode here. And the way that these operator times operate. And that is, for batch mode, it’s per operator. For row mode, it adds up along the plan. I know that sounds confusing, so I’m going to change this query slightly and rerun it. And I’m going to show you the difference. So remember what this looks like. Each one of these operators does a thing, and we measure that thing separately until we get to the row mode part.

And the row mode part reflects an adding up of everything here, right? So when we get to that gather streams, we’re adding up all of the child operator times. Prior to that in batch mode, each operator time is individual. Now I’m going to run, I’m going to change the query a little bit, and I’m going to rerun it. And this is going to execute fully in row mode. So this index seek is row mode, this source row mode, segment’s row mode, this is row mode.

Nested loops, of course, is row mode. I wish bash mode nested loops would become a thing, but it just hasn’t yet. But what the difference here is that when we look across these query times, or when we look across these operator times, they add up. So we have 1.04, 1.84, 1.99, 2.16, 2.33, go up here to 2.6, 2.65.

They add up as we go across, right? So that top operator reflects adding up all of the child operators together because they’re all row mode, right? So each row mode operator is a reflection of it and whatever time the operator or operators before it took.

So if that’s not confusing enough, again, like I was saying, when operators in a plan might switch between batch and row mode, we don’t have an indicator of when that happens, right? So in a really complicated plan where there might be a lot of switches, this might be even harder to try and figure out. So rather than me saying, well, you need to get your times right, I think it just might be easier for us as query tuning people to have a visual indicator of when an operator is in batch mode and or when we flip or even if we had like a visual indicator of when we switch between batch and row mode.

Like maybe the arrow gets interrupted, maybe there’s something between the operators, like a little swirly thing that says, hey, we switched here. So you could at least have an indicator that one thing was batch or row mode and the other thing made a switch to batch or row mode from whatever the previous operator was. Another place where this can get kind of confusing is in plans that look like this.

Now, this plan is all row mode. All of these operators are row mode. There is no batch mode happening in any of these, I promise you. But what happens is at the very end, gather streams, finish it.

Well, it says 11.242, but that nested loop says 11.499. So where these pretty accurately add up across the whole thing, they sort of get funky at the gather streams. So gather streams says it finished about, I don’t know, 300 or so milliseconds before the nested loops did, which is a little awkward.

Again, this isn’t like a big query tuning dilemma. It’s just sort of an oddity. And it’s happened across multiple queries for me.

I have another example of it happening over here where, again, all of this stuff happens. Well, I can’t say that’s entirely true. Anyway, all of this stuff happens in row mode.

Where it’s supposed to add up, it doesn’t quite add up because we have this oddity over here where the hash join says that it finished in 5.572 seconds. And then the gather stream says it finished in 5.132 seconds. This is also a little bit of a weird plan because even though it’s in row mode, at least last I checked it was all in row mode.

Who knows what happens between runs? It looks like it’s still in row mode to me. But this stream aggregate.

So these two operators are killing me. So we have this stream aggregate that ran in 1.83. And then this repartition streams that ran in 1.73. So this was supposed to add up, but it didn’t add up for some reason.

So that’s another thing that’s kind of odd. Sometimes, despite your best efforts to understand these things, you run a demo and then you look a little more closely while you’re recording a video. And you spot something even stranger.

So now I have to go figure out just what that was about. But that’s going to require a lot of day drinking. So I need to go get started on that. Anyway, I do think this is incredibly valuable.

As query performance tuners, usually when we’re looking at an execution plan, it’s a lot of guesswork as to, okay, let’s figure out what went wrong here. Let’s figure out what we need to focus on. Let’s figure out what’s bad.

This does help us focus quite a bit of our efforts on, okay, which operator really did take a long time to run? What’s sticking out like that awful sore thumb? Anyway, I’m Erik Darling with Erik Darling Data.

Still haven’t fired myself, and I will see you around in another video when it’s less hot and wearing headphones doesn’t make my ears sweat. Have a lovely Saturday. Can you talk to me today?

Have a lovely night. Hi. Hi. Thank you.

Video Summary

In this video, I dive into the complexities of operator times and execution plans in SQL Server, particularly focusing on how they behave differently in batch mode versus row mode. I explain that while these new features are incredibly valuable for query performance tuning, there are some quirks that can make them confusing. For instance, I demonstrate how operator times are measured per operator in batch mode but add up along the plan in row mode, and how there’s no clear visual indicator of when a switch between modes occurs. By walking through these examples using SSMS 18, I aim to help you better understand and navigate these peculiarities, making your query tuning efforts more efficient.

Full Transcript

Howdy folks, Erik Darling here with Erik Darling Data. Still six months in I have managed not to fire myself which is amazing because I always considered me to be one of my most underperforming employees so it’s a real tribute to I guess nepotism that I haven’t fired myself yet. Anyway, I’m here to talk about operator times and execution plans. I want to talk about them because they can be really, really confusing. And hopefully me recording this video will help you understand exactly what’s going on with them. Now, they’re only available in SSMS 18. So if you aren’t using SSMS 18, I actually understand why because it’s really buggy. crashes more than normal SSMS. But this is a great new feature for especially unemployed query tuners who, you know, need to make a buck here and there, spare changing outside bodegas and, you know, trying to get some money up for a beer and a beer and a banana or something. But yeah, these things are weird and I’m going to try to explain why. Now, in SQL Server, well, I mean, 2019 CTP3 batch mode is generally available for rowstore queries. You could still see this in SQL Server 2017 or 16 or wherever else, you know, batch mode is available or wherever you have chosen to sneakily introduce batch mode into your rowstore queries with the temp table trick or with the filtered index trick. But anyway, this gets really odd. Now, the first thing I want to explain is that in batch mode plans, the timing is per operator. But there are two things that suck. One is that there’s no general indicator of which operators ran in batch mode. There’s one operator in this plan, that window aggregate that can only happen in batch mode. So we know that’s batch mode.

But if you look at the index scan, the sort, the compute scaler, the filter, any of those other operators, there’s no visual indicator that they happened in batch mode. The other thing that sucks is that there’s no visual indicator when we switch between row mode and batch mode. There’s nothing that says, there’s nothing that says, hey, like there’s no, there’s no, there’s no like little like interruption in the arrow or like, you know, little like, like, like little flippy sign that says, hey, that we switched here. We made it, we made an adjustment. Now, I’m going to show you why this is important. So I run this, I run this query, and this query does run for about four and a half seconds that that timing isn’t up for debate. That did happen in about four and a half seconds.

But what you’ll see across the bottom of the execution plan is that each, like the operator times for each one of those operators looks funky. They don’t add up. So this ran for 1.2 seconds, this ran for 2 seconds, this ran for 0.15 milliseconds, this ran for 0.9, 900 milliseconds, or 157 milliseconds, 900 milliseconds, 0.37 milliseconds.

So all of these are individual times. And if you add them up across the line, they’ll add up to about 4.3. But what gets weird is this is batch mode, right? So batch mode, this is batch mode. In fact, all of these are batch mode up to right here. Where they stop being batch mode is that this gather streams. This is row mode. And this top is also row mode.

There’s a difference between batch mode and row mode here. And the way that these operator times operate. And that is, for batch mode, it’s per operator. For row mode, it adds up along the plan. I know that sounds confusing, so I’m going to change this query slightly and rerun it. And I’m going to show you the difference. So remember what this looks like. Each one of these operators does a thing, and we measure that thing separately until we get to the row mode part.

And the row mode part reflects an adding up of everything here, right? So when we get to that gather streams, we’re adding up all of the child operator times. Prior to that in batch mode, each operator time is individual. Now I’m going to run, I’m going to change the query a little bit, and I’m going to rerun it. And this is going to execute fully in row mode. So this index seek is row mode, this source row mode, segment’s row mode, this is row mode.

Nested loops, of course, is row mode. I wish bash mode nested loops would become a thing, but it just hasn’t yet. But what the difference here is that when we look across these query times, or when we look across these operator times, they add up. So we have 1.04, 1.84, 1.99, 2.16, 2.33, go up here to 2.6, 2.65.

They add up as we go across, right? So that top operator reflects adding up all of the child operators together because they’re all row mode, right? So each row mode operator is a reflection of it and whatever time the operator or operators before it took.

So if that’s not confusing enough, again, like I was saying, when operators in a plan might switch between batch and row mode, we don’t have an indicator of when that happens, right? So in a really complicated plan where there might be a lot of switches, this might be even harder to try and figure out. So rather than me saying, well, you need to get your times right, I think it just might be easier for us as query tuning people to have a visual indicator of when an operator is in batch mode and or when we flip or even if we had like a visual indicator of when we switch between batch and row mode.

Like maybe the arrow gets interrupted, maybe there’s something between the operators, like a little swirly thing that says, hey, we switched here. So you could at least have an indicator that one thing was batch or row mode and the other thing made a switch to batch or row mode from whatever the previous operator was. Another place where this can get kind of confusing is in plans that look like this.

Now, this plan is all row mode. All of these operators are row mode. There is no batch mode happening in any of these, I promise you. But what happens is at the very end, gather streams, finish it.

Well, it says 11.242, but that nested loop says 11.499. So where these pretty accurately add up across the whole thing, they sort of get funky at the gather streams. So gather streams says it finished about, I don’t know, 300 or so milliseconds before the nested loops did, which is a little awkward.

Again, this isn’t like a big query tuning dilemma. It’s just sort of an oddity. And it’s happened across multiple queries for me.

I have another example of it happening over here where, again, all of this stuff happens. Well, I can’t say that’s entirely true. Anyway, all of this stuff happens in row mode.

Where it’s supposed to add up, it doesn’t quite add up because we have this oddity over here where the hash join says that it finished in 5.572 seconds. And then the gather stream says it finished in 5.132 seconds. This is also a little bit of a weird plan because even though it’s in row mode, at least last I checked it was all in row mode.

Who knows what happens between runs? It looks like it’s still in row mode to me. But this stream aggregate.

So these two operators are killing me. So we have this stream aggregate that ran in 1.83. And then this repartition streams that ran in 1.73. So this was supposed to add up, but it didn’t add up for some reason.

So that’s another thing that’s kind of odd. Sometimes, despite your best efforts to understand these things, you run a demo and then you look a little more closely while you’re recording a video. And you spot something even stranger.

So now I have to go figure out just what that was about. But that’s going to require a lot of day drinking. So I need to go get started on that. Anyway, I do think this is incredibly valuable.

As query performance tuners, usually when we’re looking at an execution plan, it’s a lot of guesswork as to, okay, let’s figure out what went wrong here. Let’s figure out what we need to focus on. Let’s figure out what’s bad.

This does help us focus quite a bit of our efforts on, okay, which operator really did take a long time to run? What’s sticking out like that awful sore thumb? Anyway, I’m Erik Darling with Erik Darling Data.

Still haven’t fired myself, and I will see you around in another video when it’s less hot and wearing headphones doesn’t make my ears sweat. Have a lovely Saturday. Can you talk to me today?

Have a lovely night. Hi. Hi. Thank you.

Going Further

---

If this is the kind of SQL Server stuff you love learning about, you’ll love my training. Blog readers get 25% off the Everything Bundle — over 100 hours of performance tuning content. Need hands-on help? I offer consulting engagements from targeted investigations to ongoing retainers. Want a quick sanity check before committing to a full engagement? Schedule a call — no commitment required.