0

I am trying to speed up a long running query that I have (takes about 10 minutes to run...). In order to track down what part of the query is costing me the most time I included the Actual Execution Plan when I ran it and found a particular section that was taking up 55% (screen shot below)

alt text http://img109.imageshack.us/img109/9571/53218794.png

This didn't quite seem right to me so I added Print '1' and Print '2' before and after this trouble section. When I run the query for a mere 17 seconds and then cancel it the 1 and 2 print out which I'm assuming means it's getting through that section in the first 17 seconds.

alt text http://img297.imageshack.us/img297/4739/66797633.png

Am I doing something wrong here or is my Execution plan misleading me?

Dustin Laine
  • 37,935
  • 10
  • 86
  • 125
Abe Miessler
  • 82,532
  • 99
  • 305
  • 486
  • Can you provide the full query? – NotMe Dec 29 '09 at 21:15
  • It doesn't look like what you posted is the problem part of the query. It looks like there's more that you are cutting off...and that's where the problem is. – Justin Niessner Dec 29 '09 at 21:16
  • Why do you say that the part I posted isn't the problem part of the query? Am I wrong to assume that a section that takes up 55% should take about half of the 10 minutes to run? What other things do you use to determine problem parts of the query? – Abe Miessler Dec 29 '09 at 21:20
  • I'd rather not post up the whole query online if I can avoid it. Is it not possible to find the problem sections using only the execution plan? – Abe Miessler Dec 29 '09 at 21:21
  • It's possible to figure a lot out by looking at the execution plan, but you are only showing part of it. Further, the time issue might not be tied directly to the query cost. There is a lot more that could be going on; which is why it is important to look at the whole transaction. – NotMe Dec 30 '09 at 03:51
  • What else is it that you would be looking for in the execution plan? I'd rather not post up the execution plan or the query, sorry for making this so difficult. – Abe Miessler Dec 31 '09 at 00:36

4 Answers4

1

Metrics from perfmon will also help figure out what's going wrong... you could be running into some serious IO issues with the drive your tempDB is residing on. Additionally, run a trace and look at the CPU & IO of the actual run.

Good perfmon metrics to look at are disk queue length (avg & writes).

If you don't have access to perfmon or don't want to trace things, use "SET STATISTICS IO ON" at the beginning of your query and allow it to complete...don't stop it. Just because an execution plan says it's taking over have the cost doesn't mean it will run for half of the query time...it could be much more (or less).

Rob
  • 166
  • 1
  • 4
1

It says Query 10: Query cost (relative to the batch): 55%. Are 100% positive that it is the 10th statement in the batch that you surounded with Print statements? Could the INSERT ... INTO #mpProgramSet2 execute multiple times, some times in under 17 seconds other time for 5 minutes, depending on how much data was selected/inserted?

As a side note you should run with SET STATISTICS TIME ON rather that prints, this will give you exact compile/time and execution time of each statement in the batch.

Remus Rusanu
  • 288,378
  • 40
  • 442
  • 569
  • Yeah i'm positive. I'll make sure to use statistics next time. Might help me track down what's going on here. – Abe Miessler Dec 29 '09 at 23:44
  • Could the execution time vary because data changed? Also you must sure you run on warmed caches each time. If you add `SET STATISTICS IO ON` you should look at differences, for the same statement, between logical reads and physical reads. A large number of physical reads indicate a cold cache (had to wait for I/O), while next execution may have only logical reads and 0 physical ones (meaning it found all data cached in memory, no need for I/O). – Remus Rusanu Dec 29 '09 at 23:47
0

We would need the full query to understand what's going on; but I would probably start with setting MAXDOP to 1 in order to limit the number of processors it's running on.

Note that sometimes queries need to be limited to only 1 processor due to locks etc.

Further you might try adding NOLOCKs to any of your selects which can get away with dirty reads.

NotMe
  • 87,343
  • 27
  • 171
  • 245
0

I wouldn't trust that printing the '1' and '2' will prove anything about what has executed and what has not. I do the same thing, but I just wouldn't rely on it as proof. You could print the @@rowcount from that first insert query - that would indicate for sure that the insert has occurred.

Although the plan says that query may take 55% of the cost, it may not be 55% of the execution time, especially if the query results are cached.

Another advantage of printing the @@rowcount is to compare the actual number of rows to the estimated rows (51K). If they differ by a lot then you might investigate the statistics for your indexes.

MikeW
  • 5,702
  • 1
  • 35
  • 43