I make this post with a certain amount of guilt; because I feel that I have not searched enough for a similar problem. If there is a similar post, please direct me to it.
Perform a search based on a set of parameters, a common scenario where the search parameters are not mandatory. I use XML to pass the set of parameters to the database. So, the input to my SP is an XML variable.
Based on whether the nodes have values or not, I decide to join on the related tables. So, if the user has selected only one parameter, there will be minimum number of tables involved. I use dynamic SQL to achieve this. I have created local variables to avoid Parameter Sniffing.
The SP performs very well except for a specific parameter; irrespective of the value(s) of this parameter.
In this case, what normally takes 1 or 2 seconds, takes up to 10 minutes.
The SP has two parts.
1) parse the input XML variable and form the dynamic query - @query
2) execute @query using sp_executesql
exec sp_executesql @query , N'@searchcriteria xml, @user varchar(30)', @searchcriteria = @locsearchcriteria, @user = @locuser
This takes a long time (worst case was 10 minutes) for the troublesome parameter.
To analyze this, I copied the body of the SP, declared the variables and tested it. Here also, it takes the same time. Then, i broke it into two parts - part1 and part2. Part1 parses the XML and forms the dynamic query, part2 executes the dynamic query using sp_executesql. Part1 gets executed in less than a sec but part1 + part2 takes a long time to get results.
So, I printed the dynamic query, declared the input variables and executed it and duh! It works in less than a second!!!
What happens differently when the dynamic query is called from within the SP?
To find this out, I checked sys.dm_exec_query_stats view. It turns out that when the dynamic query is executed separately, I get three rows. I guess this indicates plan recompilation. When I execute the SP containing the dynamic query, there are 14 rows!! Why?
I have attached contents of the stats view for both cases. The bottom 3 rows are when the dynamic query was run separately. I can see that for execution of SP, there was a plan recompilation (not very sure if that is what plan_generation_num = 2 indicates) after about 5 minutes. In this case, that's the time it took for the SP to fetch results. If that is the case, why does it take 5 minutes to do the recompilation?
Any advice will help me a lot. I do not know what this implies.