Stored procedure виполняется очень бистро и медленно в одно и тоже время

NEKOS
Дата: 25.01.2013 02:19:02
Добрый день,

У меня в продакшене есть такое странное поведение. Одна и таже процедура может виполнятся менше секунды а может около минуты в одно и тоже время с одинаковими параметрами. С помощю такого селекта
SELECT d.name,
  er.session_id,  blocking_session_id,--st.text,
  SUBSTRING(st.text, (er.statement_start_offset/2)+1, 
        ((CASE er.statement_end_offset
          WHEN -1 THEN DATALENGTH(st.text)
         ELSE er.statement_end_offset
         END - er.statement_start_offset)/2) + 1) AS statement_text,
er.percent_complete

FROM 
  sys.dm_exec_requests AS er 
  CROSS APPLY sys.dm_exec_sql_text(er.sql_handle) AS st
  inner join sys.databases d on er.database_id = d.database_id
WHERE er.Session_id <>  @@spid


я вичислил что зависает на следуещем запросе

SELECT TOP 1 @inv_id = INV_ID  
FROM  dbo.T_DW_OPER dwo 
INNER JOIN     dbo.T_DW_CHECK dwc    ON dwo.DWC_ID = dwc.DWC_ID  
WHERE   dwc.DWS_ID = @dws_id  
ORDER by dwo.DWO_ID desc


В тоже врема профайлер показывает что процедура делает очень много чтений
CPU - 45875
Read - 5078540
Write - 0
Duration - 46032

ниже навожу єкзекюшен план єтого селекта

RowsExecutesStmtTextStmtIdNodeIdParentPhysicalOpLogicalOpArgumentDefinedValuesEstimateRowsEstimateIOEstimateCPUAvgRowSizeTotalSubtreeCostOutputListWarningsTypeParallelEstimateExecutions
11SELECT TOP 1 @inv_id = INV_ID FROM dbo.T_DW_OPER dwo INNER JOIN dbo.T_DW_CHECK dwc ON dwo.DWC_ID = dwc.DWC_ID WHERE dwc.DWS_ID = @dws_id ORDER by dwo.DWO_ID desc110NULLNULLNULLNULL1NULLNULLNULL0.5330461NULLNULLSELECT0NULL
11 |--Top(TOP EXPRESSION:((1)))121TopTopTOP EXPRESSION:((1))NULL101E-07110.5330461[Expr1004]NULLPLAN_ROW01
11 |--Nested Loops(Inner Join; WHERE:([CMT].[dbo].[T_DW_CHECK].[DWC_ID] as [dwc].[DWC_ID]=[CMT].[dbo].[T_DW_OPER].[DWC_ID] as [dwo].[DWC_ID]))132Nested LoopsInner JoinWHERE:([CMT].[dbo].[T_DW_CHECK].[DWC_ID] as [dwc].[DWC_ID]=[CMT].[dbo].[T_DW_OPER].[DWC_ID] as [dwo].[DWC_ID])NULL10411.6985200.5330459[dwo].[DWO_ID]; [Expr1004]NULLPLAN_ROW01
00 |--Compute Scalar(DEFINE:([Expr1004]=CONVERT_IMPLICIT(int;[CMT].[dbo].[T_DW_OPER].[INV_ID] as [dwo].[INV_ID];0)))143Compute ScalarCompute ScalarDEFINE:([Expr1004]=CONVERT_IMPLICIT(int;[CMT].[dbo].[T_DW_OPER].[INV_ID] as [dwo].[INV_ID];0))[Expr1004]=CONVERT_IMPLICIT(int;[CMT].[dbo].[T_DW_OPER].[INV_ID] as [dwo].[INV_ID];0)3933.55600.2527148290.03633642[dwo].[DWO_ID]; [dwo].[DWC_ID]; [Expr1004]NULLPLAN_ROW01
11 | |--Clustered Index Scan(OBJECT:([CMT].[dbo].[T_DW_OPER].[PK_DW_OPER__DWO_ID] AS [dwo]); ORDERED BACKWARD)154Clustered Index ScanClustered Index ScanOBJECT:([CMT].[dbo].[T_DW_OPER].[PK_DW_OPER__DWO_ID] AS [dwo]); ORDERED BACKWARD[dwo].[DWO_ID]; [dwo].[DWC_ID]; [dwo].[INV_ID]3933.55618.211272.78002340.03594306[dwo].[DWO_ID]; [dwo].[DWC_ID]; [dwo].[INV_ID]NULLPLAN_ROW01
281 |--Table Spool193Table SpoolLazy SpoolNULLNULL38.973770.010.0001071153160.4343231[dwc].[DWC_ID]NULLPLAN_ROW03934
281 |--Index Seek(OBJECT:([CMT].[dbo].[T_DW_CHECK].[IDX_DW_CHECK_DWS_ID] AS [dwc]); SEEK:([dwc].[DWS_ID]=CONVERT_IMPLICIT(numeric(10;0);[@dws_id];0)) ORDERED FORWARD)1109Index SeekIndex SeekOBJECT:([CMT].[dbo].[T_DW_CHECK].[IDX_DW_CHECK_DWS_ID] AS [dwc]); SEEK:([dwc].[DWS_ID]=CONVERT_IMPLICIT(numeric(10;0);[@dws_id];0)) ORDERED FORWARD[dwc].[DWC_ID]38.973770.0031250.0001998711160.003324871[dwc].[DWC_ID]NULLPLAN_ROW01


в этих таблицах около 2-3 милионов записей

dbo.T_DW_OPER
index DWC_ID
index INV_ID
Primary Key DWO_ID

dbo.T_DW_CHECK
Index DWS_ID
Primary Key DWO_ID

MSSQL 2005 Enterprice Edition
Microsoft SQL Server 2005 - 9.00.5057.00 (X64) Mar 25 2011 13:33:31 Copyright (c) 1988-2005 Microsoft Corporation Enterprise Edition (64-bit) on Windows NT 5.2 (Build 3790: Service Pack 2)

может у когото есть идеи?
alexeyvg
Дата: 25.01.2013 09:03:44
NEKOS
может у когото есть идеи?
Можно попробовать сделать инедксы:
dbo.T_DW_OPER (DWC_ID asc, DWO_ID desc) INCLUDE(INV_ID)
dbo.T_DW_CHECK(DWS_ID asc) INCLUDE (DWC_ID)

Может, план поменяется...
Crimean
Дата: 25.01.2013 12:03:07
> Одна и таже процедура может виполнятся менше секунды
> а может около минуты в одно и тоже время
> с одинаковими параметрами
> В тоже врема профайлер показывает
> CPU - 45875 Read - 5078540 Write - 0 Duration - 46032

где строки из профайлера, которые покажут 5`078`540 ридсов за меньше секунды?? 46 секунд - еще поверю
итого - вопрос задан некорректно, когда меньше секунды - параметры другие или данные другие, а мы уже в планы полезли
NEKOS
Дата: 25.01.2013 15:23:39
Crimean
>
где строки из профайлера, которые покажут 5`078`540 ридсов за меньше секунды?? 46 секунд - еще поверю

когда менше секунди то профайлер показивает иначие дание
CPU - 0 Read - 19 Write - 0 Duration - 0
Glory
Дата: 25.01.2013 15:27:13
NEKOS
ниже навожу єкзекюшен план єтого селекта

Разве это реальный план из Профайлера для медленного случая ?
komrad
Дата: 25.01.2013 15:30:49
NEKOS
может у когото есть идеи?


неплохо бы неявное преобразование типов убрать
[DWS_ID]=CONVERT_IMPLICIT(numeric(10;0);[@dws_id];0)) ORDERED FORWARD) 
[Expr1004]=CONVERT_IMPLICIT(int;[CMT].[dbo].[T_DW_OPER].[INV_ID] as [dwo].[INV_ID];0)
Mind
Дата: 26.01.2013 00:47:51
NEKOS
Добрый день,

У меня в продакшене есть такое странное поведение. Одна и таже процедура может виполнятся менше секунды а может около минуты в одно и тоже время с одинаковими параметрами.
Что прям один и тот же процесс запускает процедуру с теми же параметрами и время выполнения разное?
Планы что тоже одинаковые? Если нет, то где второй план? Желательно в виде xml.
NEKOS
Дата: 28.01.2013 16:35:21
Етот план что я показали и есть по ходу план когда выполняется много чтений но я не могу на 100% быть увереным. Почему я так думаю, потому что на другом сервере план показивает намного проще, без table spool.
Почему так поводится сервер я еще не знаю. Но если сделань индекси так как сказал alexeyvg то план стает очень простым, но я еще не пустил ето в продакшен, жду approve.