1. 程式人生 > >一次儲存過程引數嗅探定位流程總結

一次儲存過程引數嗅探定位流程總結

昨天一開發同事反饋一個儲存過程很慢,但是重編譯後,儲存過程就很快了。瞭解基本情況後,初步判斷是引數嗅探問題。那麼如何診斷定位、分析問題呢?下面簡單介紹一下這次引數嗅探問題定位的流程過程。

首先檢視該儲存過程的執行計劃相關資訊:

如下截圖所示,此儲存過程是2018-09-12 9:03:01快取的,最後一次執行是2018-09-14 08:58,而且自上次快取後,執行了24875次。從這裡我們基本判斷該儲存過程一直在重用快取的執行計劃,而且沒有產生重編譯現象。

SELECT  d.object_id ,
        d.database_id ,
        OBJECT_NAME(object_id, database_id) 'proc name' ,
        d.cached_time ,
        d.last_execution_time ,
        d.total_elapsed_time ,
        d.total_elapsed_time / d.execution_count AS [avg_elapsed_time] ,
        d.last_elapsed_time ,
        d.execution_count
FROM    sys.dm_exec_procedure_stats AS d
WHERE   OBJECT_NAME(object_id, database_id) = 'sp_GetOTList'
ORDER BY [total_worker_time] DESC;

然後我們使用下面指令碼找到該儲存過程的實際執行計劃,將儲存過程的執行計劃的XML內容拷貝到Plan Explorer工具。生成比較清晰、詳細的執行計劃圖。

SELECT
        d.object_id ,
        DB_NAME(d.database_id) DBName ,
        OBJECT_NAME(object_id, database_id) 'SPName' ,
        d.cached_time ,
        d.last_execution_time ,
        d.total_elapsed_time/1000000    AS total_elapsed_time,
        d.total_elapsed_time / d.execution_count/1000000 
                                        AS [avg_elapsed_time] ,
        d.last_elapsed_time/1000000        AS last_elapsed_time,
        d.execution_count ,
        d.total_physical_reads ,
        d.last_physical_reads ,
        d.total_logical_writes ,
        d.last_logical_reads ,
        et.text SQLText ,
        eqp.query_plan executionplan
FROM    sys.dm_exec_procedure_stats AS d
CROSS APPLY sys.dm_exec_sql_text(d.sql_handle) et
CROSS APPLY sys.dm_exec_query_plan(d.plan_handle) eqp
WHERE   OBJECT_NAME(object_id, database_id) = 'sp_GetOTList'
ORDER BY [total_worker_time] DESC;

如下截圖所示,我們可以清晰的找到Est Cost、 Est Cpu Cost、 Est IO Cost等高的SQL語句(其實這個是實際執行計劃,而不是預估的執行計劃),

然後重點研究、對比, 然後使用WITH(RECOMPILE)重新執行該儲存過程,生成新的執行計劃,然後按照上面方式將儲存過程執行計劃的XML拷貝到Plan Explorer工具裡面。 然後我們可以對比、研究看看到底出現了什麼情況

舊的實際執行計劃

如上截圖所示,開銷最大的SQL語句的實際執行計劃如上所示,注意開銷佔比最大的地方。 下面截圖是Nested Loops裡面迴圈的次數(迭代次數20次),也是我們

對比執行計劃需要重點關注的地方

新的實際執行計劃

新的執行計劃中,可以看到舊執行計劃開銷最大的SQL語句在整體開銷的佔比減少了很多,但是該語句的新舊執行計劃是一樣的。唯一不同的就是兩個Nested Loops裡面迴圈的次數不一樣。這個就是產生效能差異的地方,如果對巢狀迴圈連線不太熟悉,可以參考一下下面這段內容:

Nested Loops也稱為巢狀迭代,它將一個聯接輸入用作外部輸入表(顯示為圖形執行計劃中的頂端輸入),將另一個聯接輸入用作內部(底端)輸入表。外部迴圈逐行消耗外部輸入表。內部迴圈為每個外部行執行,在內部輸入表中搜索匹配行。最簡單的情況是,搜尋時掃描整個表或索引;這稱為單純巢狀迴圈聯接。如果搜尋時使用索引,則稱為索引巢狀迴圈聯接。如果將索引生成為查詢計劃的一部分(並在查詢完成後立即將索引破壞),則稱為臨時索引巢狀迴圈聯接。

舊執行計劃:

  • 巢狀迴圈次數:20* 30
  • 巢狀迴圈次數:20*20

新執行計劃:

  • 巢狀迴圈次數: 1* 1
  • 巢狀迴圈次數: 1* 1

那麼為什麼產生這個差異,就是因為儲存過程裡面一段SQL語句使用了儲存過程引數,而恰巧裡面那個表按照這個欄位的資料分佈很不均衡。所以當儲存過程按照第一次傳入的引數生成執行計劃並快取下來,而按照那個引數生成的執行計劃並不是一直都是最優執行計劃,那麼就導致了效能問題出現了,這也就是引數嗅探問題。

解決方法

在SQL語句後面使用HINT提示來解決引數嗅探,本想在對應的SQL語句後面使用OPTION (RECOMPILE),但是考慮此儲存過程呼叫頻繁,而且同事極力推薦使用提示OPTION (OPTIMIZE FOR UNKNOWN).修改過後,效能測試效果也確實顯著。