Including nvarchar(max) columns in select clause dramatically increases execution time

Question

I have simple table that consists of the columns and indexes as shown at below.

Here is my index created upon recommendation of sql database engine tuning advisor.It includes all columns.

CREATE NONCLUSTERED INDEX [_dta_index_PROPOSAL_PROCESS_12_13243102__K2_K7_K1_3_4_5_6_8_9_10] ON [dbo].[PROPOSAL_PROCESS]
(
    [PROPOSAL_ID] ASC,
    [IS_DELETED] ASC,
    [ID] ASC
)
INCLUDE (   [CREATOR_USER_ID],
    [CREATION_TIME],
    [LAST_UPDATER_USER_ID],
    [LAST_UPDATE_TIME],
    [CURRENT_PROPOSAL_OBJECT],
    [INTERFACTORING_XML],
    [OMDM_OUTPUT_XML]) WITH (PAD_INDEX = OFF, STATISTICS_NORECOMPUTE = OFF, SORT_IN_TEMPDB = OFF, DROP_EXISTING = OFF, ONLINE = OFF, ALLOW_ROW_LOCKS = ON, ALLOW_PAGE_LOCKS = ON) ON [PRIMARY]
GO

Whenever I added columns checked in picture-1 execution time increases seriously.Here are my test results.

If I include none of aforementioned columns.

SET STATISTICS IO ON
SET STATISTICS TIME ON
CHECKPOINT; 
GO 
DBCC DROPCLEANBUFFERS; 
GO  
DECLARE @DynamicFilterParam_000001 bit = 0,
        @DynamicFilterParam_000002 bit = null,
        @EntityKeyValue1 int = 4419;    
SELECT 
    [Extent1].[ID] AS [ID], 
    --[Extent1].[CURRENT_PROPOSAL_OBJECT] AS [CURRENT_PROPOSAL_OBJECT], 
    --[Extent1].[INTERFACTORING_XML] AS [INTERFACTORING_XML], 
    --[Extent1].[OMDM_OUTPUT_XML] AS [OMDM_OUTPUT_XML], 
    [Extent1].[PROPOSAL_ID] AS [PROPOSAL_ID], 
    [Extent1].[CREATOR_USER_ID] AS [CREATOR_USER_ID], 
    [Extent1].[CREATION_TIME] AS [CREATION_TIME], 
    [Extent1].[LAST_UPDATER_USER_ID] AS [LAST_UPDATER_USER_ID], 
    [Extent1].[LAST_UPDATE_TIME] AS [LAST_UPDATE_TIME], 
    [Extent1].[IS_DELETED] AS [IS_DELETED]
    FROM [dbo].[PROPOSAL_PROCESS] AS [Extent1]
    WHERE (([Extent1].[IS_DELETED] = @DynamicFilterParam_000001) ) AND ([Extent1].[PROPOSAL_ID] = @EntityKeyValue1);

(54 row(s) affected) Table 'PROPOSAL_PROCESS'. Scan count 1, logical reads 58, physical reads 2, read-ahead reads 55, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

(1 row(s) affected)

SQL Server Execution Times: CPU time = 31 ms, elapsed time = 16 ms. SQL Server parse and compile time: CPU time = 0 ms, elapsed time = 0 ms.

SQL Server Execution Times: CPU time = 0 ms, elapsed time = 0 ms.

If I add CURRENT_PROPOSAL_OBJECT to select clause of previous query

(54 row(s) affected) Table 'PROPOSAL_PROCESS'. Scan count 1, logical reads 58, physical reads 2, read-ahead reads 55, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

(1 row(s) affected)

SQL Server Execution Times: CPU time = 0 ms, elapsed time = 545 ms. SQL Server parse and compile time: CPU time = 0 ms, elapsed time = 0 ms.

If I add INTERFACTORING_XML to select clause of previous query

(54 row(s) affected) Table 'PROPOSAL_PROCESS'. Scan count 1, logical reads 58, physical reads 2, read-ahead reads 55, lob logical reads 1822, lob physical reads 376, lob read-ahead reads 0.

(1 row(s) affected)

SQL Server Execution Times: CPU time = 47 ms, elapsed time = 2415 ms. SQL Server parse and compile time: CPU time = 0 ms, elapsed time = 0 ms.

If I add CURRENT_PROPOSAL_OBJECT to select clause of previous query

(54 row(s) affected) Table 'PROPOSAL_PROCESS'. Scan count 1, logical reads 58, physical reads 2, read-ahead reads 55, lob logical reads 5048, lob physical reads 944, lob read-ahead reads 0.

(1 row(s) affected)

SQL Server Execution Times: CPU time = 47 ms, elapsed time = 6912 ms. SQL Server parse and compile time: CPU time = 0 ms, elapsed time = 0 ms.

So at the end of the day I am facing with 6912 mili seconds.What is the reason of this terrible performance ?

Am I missing to create some indexes ? It is a result of bad design originate from putting big sized nvarchar in a the same table ?

Thanks in advance

Edit: Here is the scripts for regenerating the issue.I tried to create the same issue on sql-fiddle but it didn't insert even one row.

Edit 2: If I include all columns in select clause and just give another proposal Id that makes query to return 2 rows,execution time generally stays approximately at 100 ms.Query execution time becomes worse and worse depending on the increasing of returning rows.No connection with indexes.

Answer 1

NVARCHAR(max) is a replacement for the old ntext data type.

ntext would always store its information as a BLOB, outside of the row. Where possible, NVARCHAR(max) will attempt to store the information in the row. If it can't due to size, then it'll store the text in a BLOB.

SQL Server will handle the translation back from BLOB into readable nvarchar text, but not for free. Each time that SQL Server has to go out of the row, that's additional overhead.

The tuning advisor is effectively telling you this. Compare the number of lob (large object) reads on your first query (0), with those that follow and reference the nvarchar(max) fields.

Answer 2

Don't take the tuning adviser as gospel, its gives you recommendations for the plan it generated to get the job done, more often than not a better index can be applied.

A nonclustered index on all the columns if effectively doubling the size of the table. As you will have the clustered index (the actual table) and a copy in the nonclustered index. This will double the amount of write if you are inserting into the table.

If you are selecting from one table start but just have the two columns in the where clause of the key of you index, so an index on Proposal_ID and Is_Deleted. Use SET STATISTICS IO ON and the execution plan and have a look at whats its doing then you can play about from there.

Richie Rump's statistic parser : http://statisticsparser.com/ is goood for reading output from statistic io

Answer 3

Am I missing to create some indexes ? It is a result of bad design originate from putting big sized nvarchar in a the same table ?

In all your cases i could see elapsed time not being consistent ..but overall cpu time stays relatively low..

if my query starts at 1ms and takes 8000 ms,this is total time of the query/elapsed time ,but in this CPU time can be only 10 ms..

This seems to happen in your case,try running the query and you will see query waiting for cpu..

Finally,i dont see any issue with your query and indexes and i believe the execution time you are seeing is due to wait stats