Solving Slow Query

Question

We are installing a new forum (yaf) for our site. One of the stored procedures is extremely slow - in fact it always times out in the browser. If I run it in MSSMS it takes nearly 10 minutes to complete. Is there a way to find out what part of this query if taking so long?

The Query:

DECLARE @BoardID int 
DECLARE @UserID int
DECLARE @CategoryID int = null
DECLARE @ParentID int = null

SET @BoardID = 1
SET @UserID = 2

    select 
    a.CategoryID, 
    Category        = a.Name, 
    ForumID         = b.ForumID,
    Forum           = b.Name, 
    Description,
    Topics          = [dbo].[yaf_forum_topics](b.ForumID),
    Posts           = [dbo].[yaf_forum_posts](b.ForumID),
    Subforums       = [dbo].[yaf_forum_subforums](b.ForumID, @UserID),
    LastPosted      = t.LastPosted,
    LastMessageID   = t.LastMessageID,
    LastUserID      = t.LastUserID,
    LastUser        = IsNull(t.LastUserName,(select Name from [dbo].[yaf_User] x where x.UserID=t.LastUserID)),
    LastTopicID     = t.TopicID,
    LastTopicName   = t.Topic,
    b.Flags,
    Viewing         = (select count(1) from [dbo].[yaf_Active] x JOIN [dbo].[yaf_User] usr ON x.UserID = usr.UserID where x.ForumID=b.ForumID AND usr.IsActiveExcluded = 0),
    b.RemoteURL,
    x.ReadAccess
from 
    [dbo].[yaf_Category] a
    join [dbo].[yaf_Forum] b on b.CategoryID=a.CategoryID
    join [dbo].[yaf_vaccess] x on x.ForumID=b.ForumID
    left outer join [dbo].[yaf_Topic] t ON t.TopicID = [dbo].[yaf_forum_lasttopic](b.ForumID,@UserID,b.LastTopicID,b.LastPosted)
where 
    a.BoardID = @BoardID and
    ((b.Flags & 2)=0 or x.ReadAccess<>0) and
    (@CategoryID is null or a.CategoryID=@CategoryID) and
    ((@ParentID is null and b.ParentID is null) or b.ParentID=@ParentID) and
    x.UserID = @UserID
order by
    a.SortOrder,
    b.SortOrder

IO Statistics:

Table 'Worktable'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'yaf_Active'. Scan count 14, logical reads 28, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'yaf_User'. Scan count 0, logical reads 3, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'yaf_Topic'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'yaf_Category'. Scan count 0, logical reads 28, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'yaf_Forum'. Scan count 0, logical reads 488, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'yaf_UserGroup'. Scan count 231, logical reads 693, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'Worktable'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'yaf_ForumAccess'. Scan count 1, logical reads 2, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'yaf_AccessMask'. Scan count 1, logical reads 2, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'yaf_UserForum'. Scan count 1, logical reads 0, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

Client Statistics:

Client Execution Time   11:54:01        
Query Profile Statistics            
  Number of INSERT, DELETE and UPDATE statements    0       0.0000
  Rows affected by INSERT, DELETE, or UPDATE statements 0       0.0000
  Number of SELECT statements   8       8.0000
  Rows returned by SELECT statements    19      19.0000
  Number of transactions    0       0.0000
Network Statistics          
  Number of server roundtrips   3       3.0000
  TDS packets sent from client  3       3.0000
  TDS packets received from server  34      34.0000
  Bytes sent from client    3166        3166.0000
  Bytes received from server    128802      128802.0000
Time Statistics         
  Client processing time    156478      156478.0000
  Total execution time  572009      572009.0000
  Wait time on server replies   415531      415531.0000

Execution Plan

Answer 1

With those kind of IO stats, the query must be blocking. While the SP is running, check sys.dm_exec_requests, for the session_id of your procedure running window (the @@SPID), and see blocking_session_id, wait_type, wait_time and wait_resource. These should guide you to the reason for blocking.

Answer 2

Take a look at Do you use Column=@Param OR @Param IS NULL in your WHERE clause? Don't, it doesn't perform to get an idea of how to rewrite this by using sp_executesql which will perform better.

Also this looks like a function call?

 left outer join [dbo].[yaf_Topic] t ON t.TopicID = [dbo].[yaf_forum_lasttopic](b.ForumID,@UserID,b.LastTopicID,b.LastPosted)

perhaps your function is messing this thing up, hardcode something instead the function call and see if it makes a drastic difference

Answer 3

I noticed this table is your biggest IO culprit:

Table 'yaf_UserGroup'. Scan count 231, logical reads 693, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

I also noticed that the offending table is not directly mentioned anywhere in your query. That means it must be referenced in one of the UDFs used in the your query. My guess is that the UDFs prevent the query from effectively using indexes on your yaf_UserGroup table. You can correct this by merging the logic from the offending UDF directly into the query.

Finally, however you fix this, it looks like yaf is open source. That means you should contribute your fix back to the original project. This will benefit you by helping keep your code more inline with the base project, so that a future update doesn't undo your performance fix.

Answer 4

I don't see anything bad about your execution plan.

Most probably, another session locks your query or your server is under extremely heavy load.

Answer 5

Correlated subqueries are run row-by row. Convert them to joins.

Same thing with your UDFs. Converting them to joins should speed things up a lot as they too are running row-by-row.

And what SQL Menace said.