CPU time drops, but elapsed time increases

Question

CPU time drops, but elapsed time increases

Viewing 15 posts - 16 through 29 (of 29 total)

You must be logged in to reply to this topic. Login to reply

Sander A. Default port Points: 1440 More actions · Answer 1

RBarryYoung (2/22/2010)
And now, having said all this and gone all this way, I notice something that could make it all irrelevant. *sigh*
Sander: you said that the slower query had an "execution time" of 20 seconds? How did you measure this? I know that that may seem like a silly question, however because of the amount of parallelism in that query, its actually very important.

Yes i did, and it really takes the time execution time sais it does

RBarryYoung SSC Guru Points: 143329 More actions · Answer 2

Sander A. (2/22/2010)
RBarryYoung (2/22/2010)
And now, having said all this and gone all this way, I notice something that could make it all irrelevant. *sigh*
Sander: you said that the slower query had an "execution time" of 20 seconds? How did you measure this? I know that that may seem like a silly question, however because of the amount of parallelism in that query, its actually very important.
Yes i did, and it really takes the time execution time sais it does

Huh? What I asked was how did you measure it?

There are at least three different ways (probably more) and only one is a problem with parallelism, so we really need to know just how you got this number?

[font="Times New Roman"]-- RBarryYoung[/font], [font="Times New Roman"] (302)375-0451[/font] blog: MovingSQL.com, Twitter: @RBarryYoung [font="Arial Black"]
Proactive Performance Solutions, Inc. [/font][font="Verdana"] "Performance is our middle name."[/font]

RBarryYoung SSC Guru Points: 143329 More actions · Answer 3

RBarryYoung (2/21/2010)
Paul White (2/21/2010)
I'm not sure about that equation!
It's right. Trust me, I've been doing this for a looong time across many different environments and OSs, 20 years at least. The equation traditionally used for breakdown of physical component waits is shorter (CPU, Disk, Network), but I threw in the periphery stuff just for completeness.

OK, that looks a little arrogant to me in retrospect. Sorry Paul. :blush:

OMG, is it really 4am?!?

[font="Times New Roman"]-- RBarryYoung[/font], [font="Times New Roman"] (302)375-0451[/font] blog: MovingSQL.com, Twitter: @RBarryYoung [font="Arial Black"]
Proactive Performance Solutions, Inc. [/font][font="Verdana"] "Performance is our middle name."[/font]

Paul White SSC Guru Points: 150467 More actions · Answer 4

Barry,

One day, we will meet in person, and we will have a long and no doubt fascinating conversation about all this :-D.

I think we probably agree more than is apparent from our discourse thus far, but I nevertheless look forward to a detailed chat about it.

On the 'execution time' thing: my assumption was that elapsed time was as reported by running the query manually from SSMS. That is, from execution start to the end of the complete result set.

Paul

Paul White
SQLPerformance.com
SQLkiwi blog
@SQL_Kiwi

Paul White SSC Guru Points: 150467 More actions · Answer 5

RBarryYoung (2/22/2010)
OMG, is it really 4am?!?

Lightweight 😛

I was still posting at 6:30am last night/this morning/you know what I mean.

Paul White
SQLPerformance.com
SQLkiwi blog
@SQL_Kiwi

Sander A. Default port Points: 1440 More actions · Answer 6

RBarryYoung (2/22/2010)
Sander A. (2/22/2010)
RBarryYoung (2/22/2010)
And now, having said all this and gone all this way, I notice something that could make it all irrelevant. *sigh*
Sander: you said that the slower query had an "execution time" of 20 seconds? How did you measure this? I know that that may seem like a silly question, however because of the amount of parallelism in that query, its actually very important.
Yes i did, and it really takes the time execution time sais it does
Huh? What I asked was how did you measure it?
There are at least three different ways (probably more) and only one is a problem with parallelism, so we really need to know just how you got this number?

Ow i'm sorry, i didn't read your post well enough. I measured it in ssms, with the command "set statistics io on". ssms also took about 20 seconds to come up with the results.

RBarryYoung SSC Guru Points: 143329 More actions · Answer 7

Paul White (2/22/2010)
RBarryYoung (2/22/2010)
OMG, is it really 4am?!?
Lightweight 😛
I was still posting at 6:30am last night/this morning/you know what I mean.

Yeah, but that's when I'm supposed to wake up. :w00t:

[font="Times New Roman"]-- RBarryYoung[/font], [font="Times New Roman"] (302)375-0451[/font] blog: MovingSQL.com, Twitter: @RBarryYoung [font="Arial Black"]
Proactive Performance Solutions, Inc. [/font][font="Verdana"] "Performance is our middle name."[/font]

RBarryYoung SSC Guru Points: 143329 More actions · Answer 8

Sander A. (2/22/2010)
RBarryYoung (2/22/2010)
Sander A. (2/22/2010)
RBarryYoung (2/22/2010)
And now, having said all this and gone all this way, I notice something that could make it all irrelevant. *sigh*
Sander: you said that the slower query had an "execution time" of 20 seconds? How did you measure this? I know that that may seem like a silly question, however because of the amount of parallelism in that query, its actually very important.
Yes i did, and it really takes the time execution time sais it does
Huh? What I asked was how did you measure it?
There are at least three different ways (probably more) and only one is a problem with parallelism, so we really need to know just how you got this number?
Ow i'm sorry, i didn't read your post well enough. I measured it in ssms, with the command "set statistics io on". ssms also took about 20 seconds to come up with the results.

OK, as long as you personally observed it too, then that should still be good.

[font="Times New Roman"]-- RBarryYoung[/font], [font="Times New Roman"] (302)375-0451[/font] blog: MovingSQL.com, Twitter: @RBarryYoung [font="Arial Black"]
Proactive Performance Solutions, Inc. [/font][font="Verdana"] "Performance is our middle name."[/font]

RBarryYoung SSC Guru Points: 143329 More actions · Answer 9

FYI: for Paul or anyone else who wants to check out what I've been talking about wrt "Physical Wait Time Decomposition", I believe that common/formal term for the most used form is "Response Time Analysis" or RTA. If you google that you'll find lots of references, though many of them seem to think that its a new technique (its at least 25 years old, probably more), and many of the newer advocates are a little sloppy/fuzzy on the formal requirements for correctness.

[font="Times New Roman"]-- RBarryYoung[/font], [font="Times New Roman"] (302)375-0451[/font] blog: MovingSQL.com, Twitter: @RBarryYoung [font="Arial Black"]
Proactive Performance Solutions, Inc. [/font][font="Verdana"] "Performance is our middle name."[/font]

Paul White SSC Guru Points: 150467 More actions · Answer 10

Right, now I see it. I had been working from the data (CPU/ IO) contained in the execution plan post. The figures and plans there bear no resemblance to the originally posted CPU usage statistics.

Not sure how I missed the key point so many times before: the CPU usage for the second query was 3 seconds against a total elapsed time of 20 seconds. So, of course, the other 17 seconds were spent doing something else - almost certainly physical IO. Sigh.

So, the worktable was either an index spool or lazy spool caused by the lack of a useful index. The post containing the execution plan did mention indexing changes, so that fits.

Barry, I apologise for doubting you.

Paul

Paul White
SQLPerformance.com
SQLkiwi blog
@SQL_Kiwi

Sander A. Default port Points: 1440 More actions · Answer 11

Paul White (2/22/2010)
So, the worktable was either an index spool or lazy spool caused by the lack of a useful index. The post containing the execution plan did mention indexing changes, so that fits.

There were no index changes between the 2 query's, these 2 where run at once.

Paul White SSC Guru Points: 150467 More actions · Answer 12

Sander A. (2/22/2010)
Paul White (2/22/2010)
So, the worktable was either an index spool or lazy spool caused by the lack of a useful index. The post containing the execution plan did mention indexing changes, so that fits.
There were no index changes between the 2 query's, these 2 where run at once.

I meant that there were index changes between the time you first posted results, and subsequently posting the two query execution plans.

The two later execution plans were run on the same system, with the same data and indexes - yes.

Paul

Paul White
SQLPerformance.com
SQLkiwi blog
@SQL_Kiwi

Sander A. Default port Points: 1440 More actions · Answer 13

Sander A.

Default port

Points: 1440

February 22, 2010 at 4:13 am

#1122828

yes 😉

TheSQLGuru SSC Guru Points: 134017 More actions · Answer 14

Some very interesting discussions on this thread - wish I had had the time to pop in before it had run it's course!

By the way, I have definitely seen this query, or one very like it, posted here before. My honest recommendation is that you seek the services of a good consultant at some stage to help you.
Paul

That is the single most important statement for the OP in my opinion...

Best,
Kevin G. Boles
SQL Server Consultant
SQL MVP 2007-2012
TheSQLGuru on googles mail service

Anders Pedersen SSChampion Points: 11410 More actions · Answer 15

For what it is worth...

I have seen this behavior in a few different cases now with queries with CTE's. Small rewrites, can cause large changes in CPU time, but little differences in Elapsed time. One of the actually even had an identical query plan.....