2018-08-26

[Parameter Sniffing] Reuse bad execution plan and Recompile stored procedure, 重複使用效能差的 執行計劃 與 重新編譯 預存程序


曾經,遇見過 Parameter Sniffing 副作用的處理方式:

  • 只能採用  "Local Variables / OPTIMIZE FOR UNKNOWN"。

強調 重新編譯 Stored Procedure 對於 資源耗用與影響。

這是不合理的作法,缺少了對於 資料特性、存取資料量、執行頻率、Index、Statistics等角度考量,也忽視改寫 T-SQL 優化效能的可行性。

一昧使用 "Local Variables / OPTIMIZE FOR UNKNOWN" 機制,或許,節省了開發時程 或 管控方便,但卻落得 Stored Procedure 執行效能不佳的問題!

本案例,將以 "重複使用 效能差的 Execution Plan" 與 "重新編譯 Stored Procedure" 的整體執行效能差異來對照。







[Parameter Sniffing] Reuse bad execution plan and Recompile stored procedure. 
重複使用效能差的 執行計劃 與 重新編譯 預存程序



01. 使用範例 Parameter Sniffing 與 OR 運算子,請參考以下文章:

Parameter Sniffing with OR Operator issue, 當 Parameter Sniffing 遇上 OR 運算子 (1)


條件式:  WHERE (@SalesOrderID IS NULL OR sd.SalesOrderID = @SalesOrderID)

  • @SalesOrderID IS NULL: 當 @SalesOrderID 是 NULL 時,取回全部的資料,回傳 118,744 rows。
  • sd.SalesOrderID = @SalesOrderID: 取回 指定的 SalesOrderID 的 資料,回傳 12 rows。

以 Index 使用策略來看:
  • 這兩個條件式,應該是使用不同的 Index 存取方式,例如:Index Scan、Index Seek 等。


-- figure 00_Parameter Sniffing with OR issue





02. 執行此 Stored Procedure: dbo.GetSalesList。

  • 1st
    • 使用 sp_recompile,重新編譯。
    • 輸入參數 NULL。
  • 2nd
    • 因 Parameter Sniffing 發揮功效,重複使用 Execution Plan。
    • 誤用到效能差的 Execution Plan: Clustered Index Scan
    • 輸入參數 43659。
  • 3rd
    • 再度 使用 sp_recompile,重新編譯。
    • 使用效能佳的 Execution Plan: Clustered Index Seek
    • 輸入 NULL 與 43659。

-- figure 11_Parameter Sniffing_sp_recompile_Exec_Proc





03. 使用 DMV 查詢 記憶體 Cache 區,檢視 Performance Data.


-- figure 22_Compare_ComileTime_CPU





SubTreeCost
CompileTime(ms)
LastElapsedTime(sec) 
LastCPUTime(sec) 
LastLogicalReads
LastRows
1st
5.0630900
17
1.345748000
0.541942000
2,249
118,744
2nd
5.0630900
170.1817640000.066875000156412
3rd0.562674060.1239310000.01033300039812



-- 1st: Parameter Sniffing with OR issue
-- Clustered Index Scan, return 118,744 rows

  • StatementSubTreeCost 5.0630900
  • CompileTime(ms) 17
  • CompileCPU(ms) 17
  • CompileMemory(KB) 1216
  • LastElapsedTime(sec) 1.345748000
  • LastCPUTime(sec) 0.541942000
  • LastLogicalReads 2,249
  • LastRows 118,744

-- 2nd: Bad: Clustered Index Scan, return 12 rows
-- Reuse bad execution plan

  • StatementSubTreeCost 5.0630900
  • CompileTime(ms) 17
  • CompileCPU(ms) 17
  • CompileMemory(KB) 1216
  • LastElapsedTime(sec) 0.181764000
  • LastCPUTime(sec) 0.066875000
  • LastLogicalReads 1564
  • LastRows 12

-- 3rd: "sp_recompile"
-- Good: Index Scan + Clustered Index Seek, return 12 rows

  • StatementSubTreeCost 0.5626740
  • CompileTime(ms) 6
  • CompileCPU(ms) 6
  • CompileMemory(KB) 1000
  • LastElapsedTime(sec) 0.123931000
  • LastCPUTime(sec) 0.010333000
  • LastLogicalReads 398
  • LastRows 12


比較

  • 編譯 Compile 時間的最大值: 0.017 sec。
  • 每次執行時間的差距(0.181764 - 0.12393) : 0.057834 sec
  • 每次 Logical Read 的差距(1564 - 398):1166。
  • 加入 編譯 Compile 時間的耗損(0.057834 - 0.017):0.040834 sec

若執行 100 次,Reuse bad execution plan 與 Recompile stored procedure 來比較:

  • 執行時間差距 ( (0.181764)*100 - (0.12393 + 0.017)*100 ) ,多耗用: 4.0834 sec。
  • Logical Read 差距(1166 *100) ,多耗用:116,600。


由上,隨著執行次數越頻繁,因故重複使用 效能差的 Execution Plan,卻是耗費更多的資源。


可以得知:

  • 非 每秒 都要大量執行 或 同時間會大量執行 的程式,改用重新編譯 Stored Procedure,獲取更佳的執行效能。這筆支出,是值得的。



-- Get execution plan for cached query: [CompileTime(ms)], [StatementSubTreeCost], [LastElapsedTime(sec)], LastLogicalReads, LastRows etc.
WITH XMLNAMESPACES ('http://schemas.microsoft.com/sqlserver/2004/07/showplan' as ns)

SELECT TOP 10 st.text [TSQL], DB_NAME(st.dbid) [DB], 
 TRY_CAST(qp.query_plan.value('(/ns:ShowPlanXML/ns:BatchSequence/ns:Batch/ns:Statements/ns:StmtSimple/@StatementSubTreeCost)[1]', 'float') 
 AS decimal(38,7)) [StatementSubTreeCost],
 qp.query_plan.value('(/ns:ShowPlanXML/ns:BatchSequence/ns:Batch/ns:Statements/ns:StmtSimple/ns:QueryPlan/@CompileTime)[1]', 'int') [CompileTime(ms)], 
 qp.query_plan.value('(/ns:ShowPlanXML/ns:BatchSequence/ns:Batch/ns:Statements/ns:StmtSimple/ns:QueryPlan/@CompileCPU)[1]', 'int') [CompileCPU(ms)],
 qp.query_plan.value('(/ns:ShowPlanXML/ns:BatchSequence/ns:Batch/ns:Statements/ns:StmtSimple/ns:QueryPlan/@CompileMemory)[1]', 'int') [CompileMemory(KB)],
 qs.last_elapsed_time/1000000.0 [LastElapsedTime(sec)],
 qs.last_worker_time/1000000.0 [LastCPUTime(sec)],
 qs.last_logical_reads LastLogicalReads,
 qs.last_physical_reads LastPhysicalRead,
 qs.last_logical_writes LastlogicalWrites,
 qs.last_rows LastRows,
 cp.usecounts [ExecutionCount], cp.size_in_bytes/1024.0 [PlanSize(KB)],
 cp.cacheobjtype [CacheObject], cp.objtype [ObjType], qs.plan_generation_num [PlanRecompile],
 qp.query_plan.query('(/ns:ShowPlanXML/ns:BatchSequence/ns:Batch/ns:Statements/ns:StmtSimple/ns:QueryPlan/ns:ParameterList/ns:ColumnReference[@Column])') [ParameterList],
 qp.query_plan [QueryPlan], cp.plan_handle, qs.last_execution_time, qs.creation_time
FROM sys.dm_exec_cached_plans cp INNER JOIN sys.dm_exec_query_stats qs
         ON cp.plan_handle = qs.plan_handle
 CROSS APPLY sys.dm_exec_sql_text(cp.plan_handle) st
 CROSS APPLY sys.dm_exec_query_plan(cp.plan_handle) qp
WHERE st.dbid = DB_ID('AdventureWorks2014') 
-- AND cp.objtype = 'Proc' CHARINDEX ('Products', st.text) >0
-- st.text LIKE '%xxx%'
ORDER BY StatementSubTreeCost DESC;
GO

-- figure 23_Get execution plan for cached query








Sample Code

20180825_Get_parse_compile_execute_time_SQL
https://drive.google.com/drive/folders/0B9PQZW3M2F40OTk3YjI2NTEtNjUxZS00MjNjLWFkYWItMzg4ZDhhMGIwMTZl?usp=sharing





Reference


[Case Study] Parameter Sniffing with OR Operator issue, 當 Parameter Sniffing 遇上 OR 運算子 (1)
http://sharedderrick.blogspot.com/2018/08/case-study-parameter-sniffing-with-or.html

[SQL Server] Get SubTreeCost, CompileTime, CompileMemory, Execution Count, Plan Recompile from Plan Cache - 子樹成本

沒有留言:

張貼留言