3

I've got a Linq query that runs "fast" on my development server and very slow on production server (2 seconds locally vs 3 minutes on production). While trying to investigate and compare the execution plans of the two I decided to "unwrap" the Linq query out of the sp_executesql statement and run it as a dynamic query on the local (fast) environment.

Now same server, same query but one wrapped inside the sp_executesql the other dynamic have a much bigger gap in running time: the former runs in 2 seconds the latter takes 14 minutes.

I was reading this article http://technet.microsoft.com/en-au/library/cc966425.aspx where it explains how sp_executesql use cached executing plan, would that make up 13min and 58sec difference?

I believe posting the actual queries maybe irrelevant (and look ugly and convoluted) however, I paste them here if that can give more insight.

First, executing in 2 seconds:

exec sp_executesql N'SELECT [t0].[id] AS [Id], (CONVERT(Float,[dbo].[RankWords]((
    SELECT [t18].[searchable_1]
    FROM (
        SELECT TOP (1) [t17].[searchable_1]
        FROM [dbo].[contents] AS [t17]
        WHERE [t17].[navigation_tree_id] = [t0].[id]
        ) AS [t18]
    ), @p12, @p13, @p14))) + (CONVERT(Float,[dbo].[RankWords]((
    SELECT [t20].[name]
    FROM (
        SELECT TOP (1) [t19].[name]
        FROM [dbo].[contents] AS [t19]
        WHERE [t19].[navigation_tree_id] = [t0].[id]
        ) AS [t20]
    ), @p15, @p16, @p17))) AS [GlobalRank], [t0].[modified_date] AS [ModifiedDate], [t0].[parent_id] AS [ParentId], [t0].[template_id] AS [TemplateId], (
    SELECT [t22].[name]
    FROM (
        SELECT TOP (1) [t21].[name]
        FROM [dbo].[contents] AS [t21]
        WHERE [t21].[navigation_tree_id] = [t0].[id]
        ) AS [t22]
    ) AS [Name], [t0].[id] AS [id2], [t0].[uri], [t0].[site_id], [t0].[list_order], [t0].[pointed_node_id], [t0].[start_date], [t0].[expiry_date], [t0].[is_external_link], [t0].[priority_level], [t0].[is_active], [t0].[power_level_required]
FROM [dbo].[navigation_trees] AS [t0]
WHERE (((
    SELECT COUNT(*)
    FROM [dbo].[label__navigation_tree] AS [t1]
    WHERE [t1].[navigation_tree_id] = [t0].[id]
    )) > @p0) AND ([t0].[template_id] IS NOT NULL) AND (([t0].[template_id]) IN (@p1, @p2, @p3)) AND (EXISTS(
    SELECT TOP (1) NULL AS [EMPTY]
    FROM [dbo].[contents] AS [t2]
    WHERE [t2].[navigation_tree_id] = [t0].[id]
    )) AND (((CONVERT(Bit,[dbo].[HasMatch](
    (CASE 
        WHEN ((
            SELECT [t4].[name]
            FROM (
                SELECT TOP (1) [t3].[name]
                FROM [dbo].[contents] AS [t3]
                WHERE [t3].[navigation_tree_id] = [t0].[id]
                ) AS [t4]
            )) IS NOT NULL THEN CONVERT(NVarChar(MAX),(
            SELECT [t6].[name]
            FROM (
                SELECT TOP (1) [t5].[name]
                FROM [dbo].[contents] AS [t5]
                WHERE [t5].[navigation_tree_id] = [t0].[id]
                ) AS [t6]
            ))
        WHEN (@p4 + ((
            SELECT [t8].[title]
            FROM (
                SELECT TOP (1) [t7].[title]
                FROM [dbo].[contents] AS [t7]
                WHERE [t7].[navigation_tree_id] = [t0].[id]
                ) AS [t8]
            ))) IS NOT NULL THEN CONVERT(NVarChar(MAX),@p5 + ((
            SELECT [t10].[title]
            FROM (
                SELECT TOP (1) [t9].[title]
                FROM [dbo].[contents] AS [t9]
                WHERE [t9].[navigation_tree_id] = [t0].[id]
                ) AS [t10]
            )))
        WHEN (@p6 + ((
            SELECT [t12].[description]
            FROM (
                SELECT TOP (1) [t11].[description]
                FROM [dbo].[contents] AS [t11]
                WHERE [t11].[navigation_tree_id] = [t0].[id]
                ) AS [t12]
            ))) IS NOT NULL THEN @p7 + ((
            SELECT [t14].[description]
            FROM (
                SELECT TOP (1) [t13].[description]
                FROM [dbo].[contents] AS [t13]
                WHERE [t13].[navigation_tree_id] = [t0].[id]
                ) AS [t14]
            ))
        ELSE CONVERT(NVarChar(MAX),@p8)
     END), @p9))) = 1) OR ((CONVERT(Bit,[dbo].[HasMatch]((
    SELECT [t16].[searchable_1]
    FROM (
        SELECT TOP (1) [t15].[searchable_1]
        FROM [dbo].[contents] AS [t15]
        WHERE [t15].[navigation_tree_id] = [t0].[id]
        ) AS [t16]
    ), @p10))) = 1)) AND ([t0].[pointed_node_id] IS NULL) AND ([t0].[site_id] = @p11) AND ([t0].[is_active] = 1)',N'@p0 int,@p1 int,@p2 int,@p3 int,@p4 nvarchar(4000),@p5 nvarchar(1),@p6 nvarchar(4000),@p7 nvarchar(1),@p8 nvarchar(4000),@p9 nvarchar(3),@p10 nvarchar(3),@p11 int,@p12 nvarchar(3),@p13 int,@p14 bit,@p15 nvarchar(3),@p16 int,@p17 bit',@p0=0,@p1=158,@p2=159,@p3=160,@p4=N'',@p5=N' ',@p6=N'',@p7=N' ',@p8=N'',@p9=N'actor',@p10=N'actor',@p11=15,@p12=N'actor',@p13=3,@p14=0,@p15=N'actor',@p16=3,@p17=0

Second one executing in 14 minutes:

DECLARE @p0 int,@p1 int,@p2 int,@p3 int,@p4 nvarchar(4000),@p5 nvarchar(1),@p6 nvarchar(4000),@p7 nvarchar(1),@p8 nvarchar(4000),@p9 nvarchar(3),@p10 nvarchar(3),@p11 int,@p12 nvarchar(3),@p13 int,@p14 bit,@p15 nvarchar(3),@p16 int,@p17 bit

SET @p0=0
SET @p1=158
SET @p2=159
SET @p3=160
SET @p4=N''
SET @p5=N' '
SET @p6=N''
SET @p7=N' '
SET @p8=N''
SET @p9=N'actor'
SET @p10=N'actor'
SET @p11=15
SET @p12=N'actor'
SET @p13=3
SET @p14=0
SET @p15=N'actor'
SET @p16=3
SET @p17=0

SELECT 
    [t0].[id] AS [Id], 
    (
        CONVERT(Float,[dbo].[RankWords]
        ((
            SELECT [t18].[searchable_1]
            FROM (
                SELECT TOP (1) [t17].[searchable_1]
                FROM [dbo].[contents] AS [t17]
                WHERE [t17].[navigation_tree_id] = [t0].[id]
                ) AS [t18]
            ), 
            @p12, 
            @p13, 
            @p14
        ))
    ) + 
    (
        CONVERT(Float,[dbo].[RankWords]((
            SELECT [t20].[name]
            FROM (
                SELECT TOP (1) [t19].[name]
                FROM [dbo].[contents] AS [t19]
                WHERE [t19].[navigation_tree_id] = [t0].[id]
                ) AS [t20]
            ), 
            @p15, 
            @p16, 
            @p17
        ))
    ) 
    AS [GlobalRank], 
    [t0].[modified_date] AS [ModifiedDate], 
    [t0].[parent_id] AS [ParentId], 
    [t0].[template_id] AS [TemplateId], 
    (
        SELECT [t22].[name]
        FROM (
            SELECT TOP (1) [t21].[name]
            FROM [dbo].[contents] AS [t21]
            WHERE [t21].[navigation_tree_id] = [t0].[id]
            ) AS [t22]
    ) AS [Name], 
    [t0].[id] AS [id2], 
    [t0].[uri], 
    [t0].[site_id], 
    [t0].[list_order], 
    [t0].[pointed_node_id], 
    [t0].[start_date], 
    [t0].[expiry_date], 
    [t0].[is_external_link], 
    [t0].[priority_level], 
    [t0].[is_active], 
    [t0].[power_level_required]

FROM [dbo].[navigation_trees] AS [t0]
WHERE 

    (
        ((
        SELECT COUNT(*)
        FROM [dbo].[label__navigation_tree] AS [t1]
        WHERE [t1].[navigation_tree_id] = [t0].[id]
        )) > @p0
    ) 
    AND 
    ([t0].[template_id] IS NOT NULL) 
    AND 
    (([t0].[template_id]) IN (@p1, @p2, @p3)) 
    AND 
    (EXISTS(
        SELECT TOP (1) NULL AS [EMPTY]
        FROM [dbo].[contents] AS [t2]
        WHERE [t2].[navigation_tree_id] = [t0].[id]
    )) 
    AND 
    (
        ((
            CONVERT(Bit,[dbo].[HasMatch](
        (CASE 
            WHEN ((
                SELECT [t4].[name]
                FROM (
                    SELECT TOP (1) [t3].[name]
                    FROM [dbo].[contents] AS [t3]
                    WHERE [t3].[navigation_tree_id] = [t0].[id]
                    ) AS [t4]
                )) IS NOT NULL 
            THEN 
                CONVERT(NVarChar(MAX),
                (
                    SELECT [t6].[name]
                    FROM (
                        SELECT TOP (1) [t5].[name]
                        FROM [dbo].[contents] AS [t5]
                        WHERE [t5].[navigation_tree_id] = [t0].[id]
                        ) AS [t6]
                    )               
                )
            WHEN 
                (@p4 + ((SELECT [t8].[title]
                            FROM (
                                SELECT TOP (1) [t7].[title]
                                FROM [dbo].[contents] AS [t7]
                                WHERE [t7].[navigation_tree_id] = [t0].[id]
                                ) AS [t8]
                            ))
                ) IS NOT NULL 
            THEN CONVERT(NVarChar(MAX),@p5 + ((
                SELECT [t10].[title]
                FROM (
                    SELECT TOP (1) [t9].[title]
                    FROM [dbo].[contents] AS [t9]
                    WHERE [t9].[navigation_tree_id] = [t0].[id]
                    ) AS [t10]
                )))
            WHEN (@p6 + ((
                SELECT [t12].[description]
                FROM (
                    SELECT TOP (1) [t11].[description]
                    FROM [dbo].[contents] AS [t11]
                    WHERE [t11].[navigation_tree_id] = [t0].[id]
                    ) AS [t12]
                ))) IS NOT NULL THEN @p7 + ((
                SELECT [t14].[description]
                FROM (
                    SELECT TOP (1) [t13].[description]
                    FROM [dbo].[contents] AS [t13]
                    WHERE [t13].[navigation_tree_id] = [t0].[id]
                    ) AS [t14]
                ))
            ELSE CONVERT(NVarChar(MAX),@p8)
         END), @p9))) = 1)

        OR ((CONVERT(Bit,[dbo].[HasMatch]((
        SELECT [t16].[searchable_1]
        FROM (
            SELECT TOP (1) [t15].[searchable_1]
            FROM [dbo].[contents] AS [t15]
            WHERE [t15].[navigation_tree_id] = [t0].[id]
            ) AS [t16]
        ), @p10))) = 1)

    ) AND ([t0].[pointed_node_id] IS NULL) AND ([t0].[site_id] = @p11) AND ([t0].[is_active] = 1)

Thanks.

Edit (Adding explanation of solution):

I have rewritten the Linq expression to generate a leaner query with fewer inner selects, which as a result had taken down the dynamic Query from 14 minutes to 35 seconds that had still left a 33 seconds difference between the one running with the sp_executesql and the dynamic one.

I then used the Execution Plan index suggestion to create the following indexes:

CREATE NONCLUSTERED INDEX [JH_contents_navigation_tree_id]
ON [dbo].[contents] ([navigation_tree_id])


CREATE NONCLUSTERED INDEX [JH_label_navigation_tree_navigation_tree_id]
ON [dbo].[label__navigation_tree] ([navigation_tree_id])

CREATE NONCLUSTERED INDEX [JH_navigation_trees_sid_pnid_isactv_tmplid]
ON [dbo].[navigation_trees] ([site_id],[pointed_node_id],[is_active],[template_id])

which have brought the two queries at few hundreds milliseconds mark.

This has solved also my other problem of difference in execution time between my Development server and Production server, however, while I can explain the difference in execution time between the Production and Development server down to server installation idiosyncrasies I still don't understand why on the same server the query run with the sp_executesql was still very fast despite the underlying tables were still missing indexes!? (Please add comments even if I've marked as answered, that will be interesting to know)

All suggestion helped me to narrow down the problem, so thank you all. However I feel Aaron Kempf's answer closes identified the actual problem.

Giuseppe Romagnuolo
  • 3,362
  • 2
  • 30
  • 38
  • 1
    Can you catch both runs in the sql profiler and compare the IO? I don't think this is plan caching (shouldn't require minutes to generate a plan). My best guess is that one run uses parallelization and another one doesn't due to a connection setting. – Amy B Feb 28 '11 at 15:32
  • On a slightly modified (optimised) query I get: in the sp_executesql 375101 reads, 4253 writes, duration 1727 while in the dynamic I get 20762153 reads, 0 writes, duration 33947. Does this prove one does't use parallelization (I'm looking up this soon after). Can you explain a bit further what do you mean by "due to a connection setting"? – Giuseppe Romagnuolo Feb 28 '11 at 17:01
  • Assuming you're using SQL 2005+, you owe it to yourself (and hapless coworkers) to learn about Common Table Expressions and User-Defined Functions. – Mark Sowul Feb 28 '11 at 20:03
  • @Mark Sowul: The queries above are using UDF (ie HasMatch and RankWords) however the actual SQL statement is generated by a C# Linq expression so it's a little hard to anticipate when the generated query would use CTE. Since the post, I have rewritten the Linq expression to generate a leaner query with fewer inner selects, which as a result had taken down the dynamic Query from 14 minutes to 35 seconds that had still left a 33 seconds difference between the one running with the sp_executesql and the dynamic one. However I managed to bring both queries to few milliseconds by adding indexes. – Giuseppe Romagnuolo Mar 03 '11 at 10:47
  • 1
    Oh, duh, it's generated. Incidentally I should have suggested you look at the 'Display Actual Execution Plan' and see if it mentions any indices that would help, but wow, 14 minutes to milliseconds is damned impressive. – Mark Sowul Mar 03 '11 at 11:44
  • @Mark Sowul: That is exactly what I have done. – Giuseppe Romagnuolo Mar 03 '11 at 13:01
  • I answered a similar question [here](http://stackoverflow.com/a/15477956/11808). – Christoffer Lette Mar 18 '13 at 13:28

2 Answers2

4

sounds like a different plan is used, or the data in the databases isnt the same.

to get a new query plan try to add a space to the dynamic (not sp_executesql) and re-run it

also you can try to update your statistics.

this can also happen if you cast/convert data types on columns that you join on.

Menahem
  • 3,974
  • 1
  • 28
  • 43
0

I just think that you should look at indexing the correct fields. Who cares which one is faster, unless you're returning a HUGE amount of rows, I haven't had ANY query take more than 30 seconds in the past decade.

Aaron Kempf
  • 580
  • 2
  • 11
  • Adding indexes have equalled the two queries I have used the Execution Plan to see what indexes was suggesting and created the following: CREATE NONCLUSTERED INDEX [JH_contents_navigation_tree_id] ON [dbo].[contents] ([navigation_tree_id]) CREATE NONCLUSTERED INDEX [JH_label_navigation_tree_navigation_tree_id] ON [dbo].[label__navigation_tree] ([navigation_tree_id]) CREATE NONCLUSTERED INDEX [JH_navigation_trees_sid_pnid_isactv_tmplid] ON [dbo].[navigation_trees] ([site_id],[pointed_node_id],[is_active],[template_id]). – Giuseppe Romagnuolo Mar 03 '11 at 13:09