0

I have a reasonably complex query that takes under a second to run once SQL server has established the query plan (satisfactory). However the first time the query runs the event ShowPlanXML according to the profiler takes about 14 seconds (not satisfactory).

Is there any way to optimise the ShowPlanXML so that the first time it runs it completes more quickly?

Or am I going to have create a plan guide ?

For info here is the SQL query (as generated by NHibernate):

SELECT top 20 this_.UserId as UserId55_0_, this_.User_Version as User2_55_0_, this_.User_ApplicationId as User3_55_0_, this_.User_DeletedOn as User4_55_0_, this_.User_CreatedOn as User5_55_0_, this_.User_ModifiedOn as User6_55_0_, this_.User_CreatedById as User7_55_0_, this_.User_CreatedByName as User8_55_0_, this_.User_ModifiedById as User9_55_0_, this_.User_ModifiedByName as User10_55_0_, this_.User_Name as User11_55_0_, this_.User_ExternalId as User12_55_0_, this_.User_DynamicFields as User13_55_0_, 
this_.User_FirstName as User14_55_0_, this_.User_LastName as User15_55_0_, this_.User_Prefix as User16_55_0_, this_.User_Gender as User17_55_0_, this_.User_Language as 
User18_55_0_, this_.User_Code as User19_55_0_, this_.User_Nationality as User20_55_0_, this_.User_FirstLanguage as User21_55_0_, this_.User_DrivingLicence as User22_55_0_, 
this_.User_Category as User23_55_0_, this_.User_UserStatus as User24_55_0_, this_.User_UserType as User25_55_0_, this_.User_WorkPhone as User26_55_0_, this_.User_MobilePhone as 
User27_55_0_, this_.User_Fax as User28_55_0_, this_.User_Mail as User29_55_0_, this_.User_Login as User30_55_0_, this_.User_Password as User31_55_0_, this_.User_BornOn as 
User32_55_0_, this_.User_StartedOn as User33_55_0_, this_.User_FinishedOn as User34_55_0_, this_.User_Address as User35_55_0_, this_.User_PostalCode as User36_55_0_, 
this_.User_City as User37_55_0_, this_.User_Country as User38_55_0_, this_.User_PositionTitle as User39_55_0_, this_.User_Comments as User40_55_0_, this_.User_OptionalField1 as 
User41_55_0_, this_.User_OptionalField2 as User42_55_0_, this_.User_OptionalField3 as User43_55_0_, this_.User_PasswordConsecutiveFailedAttempts as User44_55_0_, 
this_.User_PasswordModificationDate as User45_55_0_, this_.User_WrongPasswordAttemptDate as User46_55_0_, this_.User_PictureUrl as User47_55_0_, this_.User_PasswordModificationStatus as User48_55_0_, this_.User_SecretQuestionConsecutiveFailedAttempts as User49_55_0_, this_.User_PlatformMailTransfer as User50_55_0_, this_.User_TimeZoneId as User51_55_0_, this_.User_ConnectionState as User52_55_0_, this_.User_LastConnectionId as User53_55_0_, this_.User_TotalPercentRealized as User54_55_0_
FROM Dir_User this_ 
WHERE this_.UserId in (
      SELECT distinct this_0_.UserId as y0_ 
      FROM Dir_User this_0_ inner join Dir_UserDynamicGroup dynamicgro3_ on this_0_.UserId=dynamicgro3_.UsDy_UserId 
      inner join Dir_Group dynamicgro1_ on dynamicgro3_.UsDy_DynamicGroupId=dynamicgro1_.GroupId 
      WHERE dynamicgro1_.GroupId = (51904517) 
      and this_0_.User_ApplicationId = 65536 
      and this_0_.User_DeletedOn is null 
      and this_0_.UserId in (
            SELECT distinct this_0_0_.TargetUserId as y0_ 
            FROM Dir_UserGroupMember this_0_0_ 
            WHERE this_0_0_.OwnerUserId = 7341195 
            and ( (this_0_0_.Scope & 139280) != 0  or ( (this_0_0_.Scope & 139280) != 0  
            and this_0_0_.GroupId = this_0_0_.SubGroupId)))) 
            ORDER BY this_.User_Name asc
Tom Carter
  • 2,938
  • 1
  • 27
  • 42
  • Are you saying that the query takes that long to execute the first time it executes due to compilation or that literally the showplan is taking that long? If the latter, I say not to worry about it; you won't be running the query in your application and bringing back the showplan results. It's a diagnostic tool only meant for tuning and troubleshooting. – Ben Thul Apr 30 '12 at 13:02
  • It's the former - according to the profiler, the ShowPlanXml event runs every time the query is executed in SSMS. The first time takes 14 seconds to compile, from then on the plan is accessed from a cache. If I run DBCC DROPCLEANBUFFERS the cache is cleared and the plan is recalculated again taking 14 seconds – Tom Carter Apr 30 '12 at 13:38
  • According to this (http://msdn.microsoft.com/en-us/library/ms188661.aspx), that event fires every time a query runs and, I quote "traces that contain this event class may incur significant performance overhead". If you're trying to look at the performance of your query, I'd suggest looking at DMVs instead, namely sys.dm_exec_query_stats and its brethren. – Ben Thul Apr 30 '12 at 19:01

1 Answers1

1

The show-plan profiler events can have a significant impact on the performance of SQL Server (see sqlserver.query_post_execution_showplan Performance Impact). If you want to get an accurate representation of the amount of time taken to compile a stored procedure you should use an alternative method.

You should be able to identify how much time the plan took to compile by looking at the plan cache directly, see Identifying High Compile Time Statements from the Plan Cache.

Unfortunately I'm not aware of many ways to reduce compilation time for SQL Server queries other than simply reducing the complexity of the query. Attempting to reduce the frequency that plan compilation is required through plan caching is the standard approach to improving performance.

Justin
  • 84,773
  • 49
  • 224
  • 367