Performance Issue with a Lengthy Stored Procedure

Hi Friends,

Today I am going to share my experience with one of the performance issues what I had in my Environment. By the by I am not an expert in Performance tuning and these are just my ideas and I could be totally wrong.

There was one Lengthy Stored procedure (More than 10000 lines of code) which was executing for more than 3 hours. My Manager asked me to have a look in to that and perhaps fine tune it if possible.

The problem is we don't have test environment to play with also this SP contains DML commands inside them hence it is not possible to execute this any time.

This is Month end stored procedure so it executes only once per month. When I started investigating my approach would be to see where the problem lies with in the stored procedure.

I usually use DMV's  to identify the problematic statement.  I was able to do that and it was 

insert into #temp with (tablock) select * from table

To fine tune this the developers requested us to restore the copy of the database and they re-arranged the stored procedure in such a way that when executed we will get only estimated results instead of actual values getting inserted in to tables because of the DML statements.

Now the real task has began the developer when ran the SP on Test it completed in less than a minute where as when executed on the primary replica it was executing forever.

exec [sp_testing]
      @Country_ID    = 901
    , @Run_Type      = 'F'
    , @HeadOffice_ID = N'0'
    , @Refund_Type   = 'A'
    , @Invoice_No    = 0
    , @User_ID       = 0
    , @Test          = 1 

Since the Stored procedure has been modified with @Test=1 I thought of executing this on secondary replica and the results were similar to that of Test where the SP got executed in less than 30 seconds.

Wow then where is the problem . Why it is executing so long on primary replica?

whenever the SP gets in to execution on Primary replica it stuck there and it will run continuously. My initial thought was to replace the temporary table with permanent and to my surprise it ran with in 30 seconds.

I thought there lies some problem with Tempdb hence I ran performance counters to see if there lies any issue. However I couldn't find any as the AVG Disk Reads/sec and AVG Disk Writes/sec are with in 15 milliseconds.

So I was clueless where the problem is this time I modified the Stored procedure just by giving new name that's it no changes to SP whatsoever. Again the SP got completed in less than 30 seconds.

well why just a name change is helping the SP to run with in expected timelines? 

This made me to realize that this is because a new plan would sit in plan cache as the SP would gets created as new object.

Again I am clueless this time I ran the original SP with recompile and it took just 25 seconds. 

As there are many lines inside the stored procedure even though we execute the SP with recompile few of the statements are still showing the older dates. Below query helps to do the same.

SELECT (SELECT TOP 1 SUBSTRING(sql_text.text,statement_start_offset / 2+1 ,   
       ((CASE WHEN statement_end_offset = -1   
         THEN (LEN(CONVERT(nvarchar(max),sql_text.text)) * 2)
         ELSE statement_end_offset END)  - statement_start_offset) / 2+1))  AS text,  
        cast(txt_query_plan.query_plan as xml) query_plan,creation_time,last_execution_time
FROM sys.dm_exec_query_stats AS Query_Stats
CROSS APPLY sys.dm_exec_sql_text(sql_handle) AS sql_text
cross apply sys.dm_exec_text_query_plan (plan_handle, statement_start_offset, statement_end_offset) txt_query_plan
where txt_query_plan.objectid=144534698 order by last_execution_time desc

There are couple of ways to make every statement to get executed with new plans one way is to make use of sp_recompile and the other way is to make use of option (recompile) only for the problematic statement.

As said in the beginning I am not an expert hence please feel free to pass on your comments if you have read from the beginning to end.


Anonymous said…
You should check on parameter snipping...vsramja
Anonymous said…
Sorry for the typo.
It's parameter sniffing