前陣子遇到一個很是棘手的問題,監控系統DPA發現某個自定義標量函數被調用的次數非常高,高到一個離譜的程度。然後在Troubleshooting這個問題的時候,確實遇到了一些問題讓我很是糾結,下文是解決問題過程的一點思索和嘗試,如果你有更好的思路和解決方法,也請多多指教。 DPA可以監控到該函數每小時... ...
前陣子遇到一個很是棘手的問題,監控系統DPA發現某個自定義標量函數被調用的次數非常高,高到一個離譜的程度。然後在Troubleshooting這個問題的時候,確實遇到了一些問題讓我很是糾結,下文是解決問題過程的一點思索和嘗試,如果你有更好的思路和解決方法,也請多多指教。
DPA可以監控到該函數每小時被調用的次數,如下截圖所示:
那麼第一個問題來了。 DPA如何監控獲取這個函數每小時執行多少次呢? 其實這個很簡單, sys.dm_exec_query_stats視圖裡面有個欄位execution_count 統計SQL的執行次數,但是它記錄的是計劃自上次編譯以來所執行的次數。那麼,我整點執行兩次結果的差值(execution_count的差值)就是一小時內的執行次數。
execution_count Number of times that the plan has been executed since it was last compiled.(計劃自上次編譯以來所執行的次數。)
這個我們可以試驗一下,如下所示,在AdventureWorks2014,我們創建一個自定義標量函數,然後我們
USE AdventureWorks2014;
GO
CREATE FUNCTION Sales.FetchProductOrderNum
(
@ProuctID INT
) RETURNS INT
BEGIN
DECLARE @SaleOrderNum INT;
SELECT @SaleOrderNum=COUNT(SalesOrderID) FROM Sales.SalesOrderDetail
WHERE ProductID=@ProuctID
GROUP BY ProductID;
RETURN @SaleOrderNum;
END
GO
DBCC FREEPROCCACHE; --刪除計劃緩存中的所有元素
GO
DECLARE @ProductID INT;
SET @ProductID=870
SELECT DISTINCT ProductID, Sales.FetchProductOrderNum(ProductID) FROM Sales.SalesOrderDetail
WHERE ProductID=@ProductID
SELECT qs.plan_handle
, OBJECT_NAME(qt.objectid)
, qs.execution_count AS [Execution Count]
, qs.execution_count / DATEDIFF(Second, qs.creation_time, GETDATE()) AS [Calls/Second]
, qs.total_worker_time / qs.execution_count AS [AvgWorkerTime]
, qs.total_worker_time AS [TotalWorkerTime]
, qs.total_elapsed_time / qs.execution_count AS [AvgElapsedTime]
, qs.max_logical_reads
, qs.max_logical_writes
, qs.total_physical_reads
, DATEDIFF(Minute, qs.creation_time, GETDATE()) AS [Age in Cache]
FROM
sys.dm_exec_query_stats AS qs
CROSS APPLY
sys.dm_exec_sql_text(qs.[sql_handle]) AS qt
WHERE
qt.[dbid] = DB_ID()
AND qt.objectid = OBJECT_ID('Sales.FetchProductOrderNum')
OPTION (RECOMPILE);
DECLARE @ProductID INT;
SET @ProductID=897
SELECT DISTINCT ProductID, Sales.FetchProductOrderNum(ProductID) FROM Sales.SalesOrderDetail
WHERE ProductID=@ProductID
DECLARE @ProductID INT;
SET @ProductID=870
SELECT DISTINCT ProductID, Sales.FetchProductOrderNum(ProductID) FROM Sales.SalesOrderDetail
WHERE ProductID=@ProductID
如上所示,假設一個小時內只執行了上面兩個SQL,那麼我知道這個自定義函數被調用了 9378 - 4688 =4690次。 所以基於這種規則,就可以找出一小時內自定義函數的調用次數,當然其它資料庫對象也可以如此計算。
那麼接下來的問題,一個資料庫中有多腳本都調用了這個自定義標量函數,但是我怎麼判別、區分那個SQL腳本調用了自定義函數最多(或者能查出TOP 10 SQL語句),這個問題糾結了好久,查找了好多資料,均無法實現這個功能。
為什麼有這樣的需求呢? 因為,不能定位那個SQL調用的次數最多,我無法定位問題根源,我遇到的案例,發現有接近200個地方調用這個自定義函數,如果一個個去判斷分析、這個是個累死人的體力活,而且有些SQL非常不容易確定
會調用多少次,(例如有些是在臨時表上調用該函數, 有些條件是傳入的變數等等)。
SELECT TOP 120
SUBSTRING(qt.text, ( qs.statement_start_offset / 2 ) + 1,
( ( CASE qs.statement_end_offset
WHEN -1 THEN DATALENGTH(qt.text)
ELSE qs.statement_end_offset
END - qs.statement_start_offset ) / 2 ) + 1) ,
qt.text ,
qs.execution_count ,
qs.total_logical_reads ,
qs.last_logical_reads ,
qs.total_logical_writes ,
qs.last_logical_writes ,
qs.total_worker_time ,
qs.last_worker_time ,
qs.total_elapsed_time / 1000000 total_elapsed_time_in_S ,
qs.last_elapsed_time / 1000000 last_elapsed_time_in_S ,
qs.last_execution_time ,
qp.query_plan
FROM sys.dm_exec_query_stats qs
CROSS APPLY sys.dm_exec_sql_text(qs.sql_handle) qt
CROSS APPLY sys.dm_exec_query_plan(qs.plan_handle) qp
WHERE qt.text LIKE '%FunctionName%'
ORDER BY qs.execution_count DESC;
如果你用這樣的SQL語句,也是無法找到那個SQL調用自定義函數