Ist total_elapsed_time in DMV sys.dm_exec_requests völlig ungenau?

Ich verwende SQL Server 2012 und versuche, einige Abfragen für die Überwachung mithilfe der DMVs zusammenzustellen. Wenn Sie sich das total_elapsed_timeFeld in der sys.dm_exec_requestsDMV ansehen, sehen die Zahlen jedoch anders aus. Hier ist ein Beispiel:

SELECT
  session_id, RunTime = CURRENT_TIMESTAMP,
  start_time, total_elapsed_time
FROM sys.dm_exec_requests
WHERE session_id = 284;

session_id  RunTime                 start_time              total_elapsed_time
284         2016-04-07 16:14:03.690 2016-04-07 16:08:14.587 1419976

Nach meinen Berechnungen * sollte die abgelaufene Zeit bei 349.103 liegen - nicht bei 1.419.976. Das ist um mehr als den Faktor 4 anders.

_{* Aus der Differenz in Millisekunden zwischen der aktuellen Uhrzeit und der start_time d.
SELECT DATEDIFF(MILLISECOND, '2016-04-07T16:08:14.587', '2016-04-07T16:14:03.690');}

Hier ist die Serverinfo:

SELECT @@VERSION;

Microsoft SQL Server 2012 - 11.0.5592.0 (X64) 
    Apr 17 2015 15:18:46 
    Copyright (c) Microsoft Corporation
    Enterprise Edition: Core-based Licensing (64-bit) on Windows NT 6.1 <X64> (Build 7601: Service Pack 1)

Irgendwelche Ideen, was diese Diskrepanz verursachen könnte?

Es gibt einen Fehler, der die Zeit in einer parallelen Operation zusammenfasst. Dies ist im Jahr 2014 behoben.

Die total_elapsed_time ist für eine bestimmte parallele Abfrage in einem Stapel korrekt, bis zur nächsten Anweisung im Stapel und dann zur total_elapsed_time übergegangen wird wird. vom DOP aufgelöst.

Beispiel

Führen Sie dies in einem Abfragefenster aus:

USE AdventureWorks2012
GO
SELECT *
FROM Sales.SalesOrderDetail sod
JOIN Production.Product p ON sod.ProductID = p.ProductID
ORDER BY Style 

waitfor delay '00:00:15'

Führen Sie dies in einer Sekunde aus:

select 
    DATEDIFF(ms, start_time, getdate()) ActualElapsedTime,
    total_elapsed_time from sys.dm_exec_requests
where session_id = <your session_id for the above batch>

Die beiden Werte sind nahezu identisch, bis SQL Server zur WAITFORDELAYAnweisung wechselt. Anschließend sollte die total_elapsed_time angezeigt werden explodieren (vorausgesetzt, die erste Abfrage hat einen parallelen Plan wie auf meinem Server).

Ich erinnere mich, dass ich vor ein paar Jahren für einen Kunden daran gearbeitet habe. Ich habe den Fehler in der internen Datenbank gefunden (ich bin ein Microsoft Premier Developer Consultant), aber keine öffentliche Referenz.

Es sieht so aus, als könnte es sich auch um einen Bug / ein Problem mit der DMV handeln. Es gibt einen Bug Connect Bericht hier von derselben Art von Ungenauigkeit. Die vorgeschlagene Problemumgehung ist zu verwenden

GETDATE() - sys.dm_exec_requests.start_time

statt total_elapsed_time . Das Problem wurde in SQL Server 2014 behoben. So zitieren Sie den Kommentar zum Connect-Element von "Nathan (MSFT)":

Das Problem mit sys.dm_exec_requests.total_elapsed_time ist nicht RESTOREbetriebsspezifisch. es wurde auch mit beobachtet UPDATE STATISTICS. Dieses Problem wird in SQL Server 2008 R2 nicht behoben. [...] Das Problem wurde in SQL Server 2014 behoben.

Ich habe ein paar Server überprüft und auf den Hintergrundanforderungen eine Abweichung von ungefähr 14s über 2 Monate beobachtet.

Abgesehen davon ist jedoch der einzige signifikante Unterschied, den ich bei anderen Anfragen feststellen kann, wo die Spid in einen Schlafzustand übergegangen ist. Ich vermute, dass dieser Wert in diesem Zustand nicht erhöht wird. Ich konnte jedoch keine Abfrage in SLEEPING erzwingen, um sie zu testen. (WAITFOR geht zum Suspendieren anstatt zu schlafen).

Es kann andere Ursachen geben, aber ich habe noch keine gefunden. Sie können dies ausschließen, indem Sie Ihre Abfrage überwachen, um sicherzustellen, dass sie nicht in den Status SLEEPING wechselt.