我正在开发一个小项目来监视用户存储过程的活动和执行指标。我定期(大约每 10 分钟)拍摄 sys.dm_exec_procedure_stats DMV 的快照,然后对过程database_id、object_id、plan_handle和 plan cached_time列进行 INNER JOIN 连续快照,以计算执行指标增量。让我困惑的是,这些增量有时是负数,因为在极少数情况下,后一个快照的执行指标值低于同一对象的前一个快照的值。这怎么可能?
我正在多个实例和不同版本的 SQL Server 上进行数据收集/处理,到目前为止,这种奇怪的行为仅发生在 SQL Server 2008 R2 上。
下图中有一个例子。与同一对象的先前快照相比,突出显示的快照具有较低的 exec 指标值(total_worker_time、execution_count 等),这很奇怪,因为两个快照具有相同的 database_id、object_id、plan_handle 和计划缓存时间。
请注意:下图中显示的那些快照没有被我的脚本以任何方式处理,它们是普通旧的结果 - SELECT “desired columns” FROM sys.dm_exec_procedure_stats。
只是为了更多地澄清我正在做的事情,这是我用于拍摄快照和计算增量的算法:
从 sys.dm_exec_procedure_stats 中获取快照 (S0)(从 sys.dm_exec_procedure_stats 中选择“所需列”)
等待一段时间(假设 - 10 分钟);
从 sys.dm_exec_procedure_stats 中获取另一个快照 (S1)(从 sys.dm_exec_procedure_stats 中选择“所需列”)
按时间戳对快照 S0 和 S1 进行排序,对database_id、object_id、plan_handle和plan_cached_time列执行 INNER JOIN,并计算执行指标增量。
该算法生成的脚本非常简单。让我烦恼的是,当我在 SSMS 屏幕上转储快照 S0 和 S1 时,有时(在 SQL Server 2008 R2 上)我会得到上图所示的结果,其中快照 (S1) 与快照 S0 相比具有较低的执行指标值,甚至尽管它们共享相同的database_id、object_id、plan_handle和plan_cache_time,并且快照S1具有更高的last_execution_time DATETIME值。
我不知道...也许我在这里做错了什么,但是如果有人基于 sys.dm_exec_procedure_stats DMV 的聚合数据构建用户程序监控脚本,也许他们应该小心,因为他们可能会得到负面结果SQL Server 2008 R2 上的增量。
这是我用来检查负/无效增量的脚本。如果逻辑有误,请告诉我。
我在 SQL Server 2008 R2、2012、2016、2017 和 2019 版本上进行了测试,仅在 SQL Server 2008 R2 上发现了负增量。
SET NOCOUNT ON
-- Create a table to hold sys.dm_exec_procedure_stats snapshots
IF OBJECT_ID('tempdb.dbo.#SNAPSHOTS') IS NULL
BEGIN
CREATE TABLE #SNAPSHOTS (
timestamp DATETIME2(0),
database_id INT,
object_id INT,
plan_handle VARBINARY(64),
plan_cached_time DATETIME,
last_execution_time DATETIME,
execution_count BIGINT,
total_elapsed_time BIGINT,
total_worker_time BIGINT,
total_logical_reads BIGINT
)
END
DECLARE @timestamp DATETIME2(0), @last_execution_time DATETIME, @iteration INT = 0, @negatives INT = 0, @rows INT
-- Loop indefinitely
WHILE 1 = 1
BEGIN
-- Get last execution time from the snapshot table
SELECT @last_execution_time = MAX(last_execution_time),
@timestamp = GETDATE()
FROM #SNAPSHOTS
IF @last_execution_time IS NULL
SET @last_execution_time = GETDATE() - 30
-- Take snapshot from sys.dm_exec_procedure_stats DMV of all procs. that were executed after the last snapshot collection time
INSERT INTO #SNAPSHOTS
SELECT @timestamp, database_id, object_id, plan_handle, cached_time, last_execution_time, execution_count, total_worker_time, total_elapsed_time, total_logical_reads
FROM sys.dm_exec_procedure_stats
WHERE last_execution_time > @last_execution_time
SET @rows = @@ROWCOUNT
-- Check for negative/invalid deltas
;WITH c AS (
SELECT ROW_NUMBER()OVER(PARTITION BY database_id, object_id, plan_handle, plan_cached_time ORDER BY timestamp) row, *
FROM #SNAPSHOTS
)
SELECT @negatives = COUNT(*)
FROM c s0
INNER JOIN c s1 ON s0.database_id = s1.database_id AND s0.object_id = s1.object_id AND s0.plan_handle = s1.plan_handle AND s0.plan_cached_time = s1.plan_cached_time AND s0.row = s1.row - 1
WHERE s1.execution_count - s0.execution_count < 0
OR s1.total_elapsed_time - s0.total_elapsed_time < 0
OR s1.total_logical_reads - s0.total_logical_reads < 0
OR s1.total_worker_time - s0.total_worker_time < 0
SET @iteration += 1
RAISERROR(N'Iteration: %d. Rows added: %d. Negative/Invalid deltas: %d', 10, 10, @iteration, @rows, @negatives) WITH NOWAIT
WAITFOR DELAY '00:01:00' -- Wait a bit before taking another snapshot
END