This is my story: I have a long running query, it takes about 10s to execute. In order to optimize it I've created an index that I thought might help - it's creation was recommended by the sys.dm_db_missing_index_group_stats system view as well.
But the server decided not to use the index. Out of curiosity, I tried to force it by hint - and the query finished in 0.5s!
I tried to find out why the server ignores the index. I updated statistics on all tables included in query, with fullscan to be sure. But no change.
Then I found surprising thing: according to execution plan, estimated subtree cost of the original query (executing 10s) was 0.675 but estimated subtree cost of query with forced index (executing 0.5s) was 3.28 - see included execution plan for detail.
If I understand it well, the server thinks that execution plan with index will run much slower than plan without it, but the reality is the other way around. And the difference is really significant. How is that possible?
To be sure about the real execution times I've set STATISTICS TIME ON and get these results:
Original query
SQL Server Execution Times:
CPU time = 10766 ms, elapsed time = 11046 ms.
Query with forced index:
SQL Server Execution Times:
CPU time = 203 ms, elapsed time = 433 ms.
I've googled it for a while but havent found any clue. I don't think parallelism could give any explanation (see Measuring Query Performance : "Execution Plan Query Cost" vs "Time Taken") because both queries run with Degree Of Parallelism = 1 and also, the "fast" query has not only short elapsed time but also low CPU time.
My environment: Windows Server 2012 R2 64bit, SQL Server 2012 (v11.0.5613.0), 64GB RAM, 16 cores. The biggest table t_object has around 25M rows.
Here is the execution plan of both queries run in a batch, first the original one, second the one with forced index:
And here is "frame part" of execution plan in XML. I can provide a full one, after I find how to not exceed the limit of body size:
<?xml version="1.0" encoding="utf-16"?>
<BatchSequence>
<Batch>
<Statements>
<StmtSimple StatementCompId="3" StatementEstRows="241" StatementId="1" StatementOptmLevel="FULL" StatementOptmEarlyAbortReason="GoodEnoughPlanFound" StatementSubTreeCost="0.675167" StatementText="SELECT TOP 241 t_Object.c_id AS id, t_Object.c_objectDefName AS objectDefName, t_Object.c_id AS display, t_Object.c_owner AS owner, t_Object.c_ownerDefName AS ownerDefName 
, t_KPDokBase.c_typ, a_KPCisTypDokumentu0.c_nazev, t_KPDokBase.c_kpid, t_KPDokBase.c_pojistnik, t_KPDokBase.c_kpdatum, t_KPDokBase.c_urgentni, t_KPDokBase.c_poznamka
 FROM t_KPDokBase LEFT JOIN t_KPCiselnik a_KPCisTypDokumentu0 ON t_KPDokBase.c_typ=a_KPCisTypDokumentu0.c_Id , t_Document, t_Object 
 WHERE t_Document.c_Id = t_KPDokBase.c_Id AND t_Object.c_Id = t_Document.c_Id AND ((t_Object.c_createDT >= '20151021 10:16:04.875') AND (((t_KPDokBase.c_pravaTyp = '') OR (t_KPDokBase.c_pravaTyp <> 'zdravotni')))) AND t_Document.c_trashed=0 AND t_Document.c_versionType=1
 --doba využití procesoru = 10531 ms, uplynulá doba = 10816 ms.

" StatementType="SELECT" QueryHash="0x5B65E1C5AEEE1DB3" QueryPlanHash="0x3AEC766C66B98CA1" RetrievedFromCache="true">
<QueryPlan DegreeOfParallelism="1" MemoryGrant="1376" CachedPlanSize="72" CompileTime="57" CompileCPU="57" CompileMemory="848">
<MemoryGrantInfo SerialRequiredMemory="1024" SerialDesiredMemory="1376" RequiredMemory="1024" DesiredMemory="1376" RequestedMemory="1376" GrantWaitTime="0" GrantedMemory="1376" MaxUsedMemory="640" />
<OptimizerHardwareDependentProperties EstimatedAvailableMemoryGrant="209569" EstimatedPagesCached="419139" EstimatedAvailableDegreeOfParallelism="8" />
<RelOp AvgRowSize="271" EstimateCPU="2.41E-05" EstimateIO="0" EstimateRebinds="0" EstimateRewinds="0" EstimatedExecutionMode="Row" EstimateRows="241" LogicalOp="Top" NodeId="0" Parallel="false" PhysicalOp="Top" EstimatedTotalSubtreeCost="0.675167">
<OutputList>
</OutputList>
<RunTimeInformation>
<RunTimeCountersPerThread Thread="0" ActualRows="241" ActualEndOfScans="1" ActualExecutions="1" />
</RunTimeInformation>
<Top RowCount="false" IsPercent="false" WithTies="false">
<TopExpression>
<ScalarOperator ScalarString="(241)">
<Const ConstValue="(241)" />
</ScalarOperator>
</TopExpression>
</Top>
</RelOp>
</QueryPlan>
</StmtSimple>
</Statements>
</Batch>
<Batch>
<Statements>
<StmtSimple StatementCompId="4" StatementEstRows="241" StatementId="2" StatementOptmLevel="FULL" StatementSubTreeCost="3.28305" StatementText="SELECT TOP 241 t_Object.c_id AS id, t_Object.c_objectDefName AS objectDefName, t_Object.c_id AS display, t_Object.c_owner AS owner, t_Object.c_ownerDefName AS ownerDefName 
, t_KPDokBase.c_typ, a_KPCisTypDokumentu0.c_nazev, t_KPDokBase.c_kpid, t_KPDokBase.c_pojistnik, t_KPDokBase.c_kpdatum, t_KPDokBase.c_urgentni, t_KPDokBase.c_poznamka
 FROM t_KPDokBase LEFT JOIN t_KPCiselnik a_KPCisTypDokumentu0 ON t_KPDokBase.c_typ=a_KPCisTypDokumentu0.c_Id , t_Document, t_Object WITH (INDEX(IX_cdt_obdn_ow_owdn))
 WHERE t_Document.c_Id = t_KPDokBase.c_Id AND t_Object.c_Id = t_Document.c_Id AND ((t_Object.c_createDT <= '20151021 10:16:04.875') AND (((t_KPDokBase.c_pravaTyp = '') OR (t_KPDokBase.c_pravaTyp <> 'zdravotni')))) AND t_Document.c_trashed=0 AND t_Document.c_versionType=1
 --doba využití procesoru = 218 ms, uplynulá doba = 669 ms.
" StatementType="SELECT" QueryHash="0xED6590A88AF84552" QueryPlanHash="0x61ED516F58A6CB68" RetrievedFromCache="true">
<StatementSetOptions ANSI_NULLS="true" ANSI_PADDING="true" ANSI_WARNINGS="true" ARITHABORT="true" CONCAT_NULL_YIELDS_NULL="true" NUMERIC_ROUNDABORT="false" QUOTED_IDENTIFIER="true" />
<QueryPlan DegreeOfParallelism="1" MemoryGrant="2451104" CachedPlanSize="80" CompileTime="26" CompileCPU="26" CompileMemory="800">
<MemoryGrantInfo SerialRequiredMemory="1536" SerialDesiredMemory="2451104" RequiredMemory="1536" DesiredMemory="2451104" RequestedMemory="2451104" GrantWaitTime="0" GrantedMemory="2451104" MaxUsedMemory="2632" />
<OptimizerHardwareDependentProperties EstimatedAvailableMemoryGrant="209569" EstimatedPagesCached="419139" EstimatedAvailableDegreeOfParallelism="8" />
</QueryPlan>
</StmtSimple>
</Statements>
</Batch>
</BatchSequence>
</ShowPlanXML>
