Skip to main content
Database Administrators

Return to Question

Added possible hint
Source Link
crokusek
crokusek
  • 2.2k
  • 4
  • 26
  • 34

Possible hint (2013/04/26): The query performs multiple inner merge joins and I found this on Paul White's blog:

Exchange Spills

Posted by: Paul White NZ (view profile) Posted on: Monday, March 07, 2011 at 3:29 AM

...these are almost always caused by a sequence of exchanges operation in order-preserving mode, separated by one or more operators that require sorted input e.g. Merge Join, Stream Aggregate, Segment...

In SQL Server 2008 there is a Profiler event to show when this type of exchange 'deadlock' is resolved by spilling exchange packets to disk.

The primary workaround is to avoid these plan shapes (especially parallel Merge Join at high DOP, in my experience). It is sometimes enough to force a hash or loop join instead using a hint, but this is advanced tuning and really requires detailed knowledge of the data concerned.

Possible hint (2013/04/26): The query performs multiple inner merge joins and I found this on Paul White's blog:

Exchange Spills

Posted by: Paul White NZ (view profile) Posted on: Monday, March 07, 2011 at 3:29 AM

...these are almost always caused by a sequence of exchanges operation in order-preserving mode, separated by one or more operators that require sorted input e.g. Merge Join, Stream Aggregate, Segment...

In SQL Server 2008 there is a Profiler event to show when this type of exchange 'deadlock' is resolved by spilling exchange packets to disk.

The primary workaround is to avoid these plan shapes (especially parallel Merge Join at high DOP, in my experience). It is sometimes enough to force a hash or loop join instead using a hint, but this is advanced tuning and really requires detailed knowledge of the data concerned.

added tempdb stats screenshot
Source Link
crokusek
crokusek
  • 2.2k
  • 4
  • 26
  • 34

For slow case, tempdb before/after (select * sys.fn_virtualfilestats(db_id('tempdb'),null)) ( only showing a few 100ms of latency ): TempDbBeforeAfter

Should I be looking at the differences in the RunTimeCountersPerThread lines? It appears it is just the order that is different between the Threads.

Should I be looking at the differences in the RunTimeCountersPerThread lines? It appears it is just the order that is different between the Threads.

For slow case, tempdb before/after (select * sys.fn_virtualfilestats(db_id('tempdb'),null)) ( only showing a few 100ms of latency ): TempDbBeforeAfter

Should I be looking at the differences in the RunTimeCountersPerThread lines? It appears it is just the order that is different between the Threads.

Tweeted twitter.com/#!/StackDBAs/status/327604427835981824
Source Link
crokusek
crokusek
  • 2.2k
  • 4
  • 26
  • 34

How to determine cause of runtime increase given two query plans with SpillToTempDb warning

Two actual query plans were captured for two executions of one query:

Plan "Fast" took ~1s and occurs about 90% of the time.

Plan "Slow" took ~16s.

Since the graphical plans look identical to me, I dumped the XML versions and performed a diff to look at the text differences to be sure.

There are 2 "SpillToTempDb" warnings on the fast side and four on the slow side. Looking that the 2 extra on the slow side:

One SpillToTempDb warning on "Parallelism (Repartition Streams) Cost 1%": <SpillToTempDb SpillLevel="0" /> On SpillToTempDb warning on "Parallelism (Distribute Streams) Cost 1%": <SpillToTempDb SpillLevel="0" />

The cost is the same (1%) for both the slow and fast cases. Does that mean the warning can be ignored? Is there a way to show "actual" times or costs. That would be so much better! Actual row counts are the same for the operation with the spill.

Besides performing a manual text diff of xml execution plans to find the differences in warnings, how can I tell what the 1500% increase in runtime is actually due to?

Differences except "RunTimeCountersPerThread" lines:

Left file: C:\Users\chrisr\Desktop\fast.sqlplan Right file: C:\Users\chrisr\Desktop\slow.sqlplan 10 <ThreadStat Branches="10" UsedThreads="85"> 10 <ThreadStat Branches="10" UsedThreads="73"> ------------------------------------------------------------------------ ------------------------------------------------------------------------ 19 <MemoryGrantInfo SerialRequiredMemory="1536" SerialDesiredMemory="10816" RequiredMemory="124224" DesiredMemory="133536" RequestedMemory="133536" GrantWaitTime="0" GrantedMemory="133536" MaxUsedMemory="105440" /> 19 <MemoryGrantInfo SerialRequiredMemory="1536" SerialDesiredMemory="10816" RequiredMemory="124224" DesiredMemory="133536" RequestedMemory="133536" GrantWaitTime="0" GrantedMemory="133536" MaxUsedMemory="107840" /> ------------------------------------------------------------------------ 276 <Warnings> 277 <SpillToTempDb SpillLevel="0" /> 278 </Warnings> ------------------------------------------------------------------------------------------------------------------------------------------------ 630 <Warnings> 631 <SpillToTempDb SpillLevel="0" /> 632 </Warnings> ------------------------------------------------------------------------

Should I be looking at the differences in the RunTimeCountersPerThread lines? It appears it is just the order that is different between the Threads.