sys.dm_exec_requests - start_time

7

Ich habe die folgende Abfrage, die mir den Status von Abfragen in einer Datenbank angibt, für die ich verantwortlich bin (obwohl ich kein DBA bin).

SELECT 
     T3.FullStatement as FullSQLStatement
    ,T3.ExecutingStatement
    ,req.session_id as SessionId
    ,T2.login_name as LoginName
    ,command as SQLCommand
    ,start_time as StartTime
    ,DateDiff(MINUTE,start_time,GetDate()) as ElapsedTimeMinutes
    ,req.status as QueryStatus
    ,req.wait_type as WaitType
    ,req.wait_time as WaitTimeMs
    ,blocking_session_id as BlockingSessionId
    ,req.row_count as [RowCount]
    ,req.cpu_time as CpuTimeMs
    ,req.total_elapsed_time as TotalElapsedTimeMs
    ,SubString(sqltext.TEXT,req.statement_start_offset,req.statement_end_offset-req.statement_start_offset)
FROM sys.dm_exec_requests req
    Inner Join sys.dm_exec_sessions T2 ON T2.session_id = req.session_id
    Cross Apply dbo.GetExecutingSQLStatement (req.session_id) T3
    Cross Apply sys.dm_exec_sql_text(sql_handle) AS sqltext
where req.database_id = 5
Order By 6 Desc

Es wird eine Ausgabe generiert, die teilweise wie folgt aussieht:

Geben Sie hier die Bildbeschreibung ein Auch wenn es in dem Beispiel, das ich aufgenommen habe, nicht sehr gut angezeigt wird, ist start_time die Startzeit der vollständigen Anweisung und nicht der ausführende Teil der Anweisung. Gibt es irgendwo eine Möglichkeit, die Startzeit des ausführenden Teils zusammen mit der Startzeit der vollständigen Anweisung abzurufen? Dies ist für mich wichtig, da eine vollständige Aussage natürlich viele individuelle Fragen enthalten kann.

Randy Minder
quelle

Antworten:

8

Im Moment scheint dies kein möglicher Wert zu sein, was bedauerlich ist, da dies ein praktischer Wert zu sein scheint.

Ok, ich habe es (meistens) gefunden. last_execution_timeIn der DMV sys.dm_exec_query_stats befindet sich ein Feld , obwohl diese DMV die folgende Warnung enthält:

Eine erste Abfrage von sys.dm_exec_query_stats kann zu ungenauen Ergebnissen führen, wenn derzeit eine Workload auf dem Server ausgeführt wird. Genauere Ergebnisse können durch erneutes Ausführen der Abfrage ermittelt werden.

Ich bin mir auch nicht sicher, wie der Wert von last_execution_timedurch mehrere gleichzeitige Ausführungen von exakt demselben SQL über mehrere Sitzungen hinweg beeinflusst wird, da dies sys.dm_exec_query_statspro Abfragestapel und nicht pro Sitzung erfolgt.

Unten ist was ich bisher habe. Es gibt vielleicht eine Sache, die ich irgendwie bereinigen möchte, aber dies sollte bereits die erste Abfrage in einem Stapel berücksichtigen, in der kein entsprechender Eintrag vorhanden ist, sys.dm_exec_query_statsda diese nach dem aktuellen (idealerweise, aber nicht immer rechtzeitig) ausgefüllt wird Anweisung / Abfrage abgeschlossen. Und es scheint für Stapel mit einer einzelnen Abfrage zu funktionieren, probieren Sie es also aus.

SELECT req.session_id AS [SessionID],
       req.start_time AS [BatchStartTime],
       req.total_elapsed_time as [BatchMilliseconds], --[TotalElapsedTimeMs],
       CASE WHEN stat.last_execution_time IS NOT NULL THEN
                DATEADD(MILLISECOND,
                        (stat.last_elapsed_time / 1000.0),
                        stat.last_execution_time)
            ELSE req.start_time END AS [StatementStartTime],
       DATEDIFF(MILLISECOND,
                CASE WHEN stat.last_execution_time IS NOT NULL THEN
             DATEADD(MILLISECOND, (stat.last_elapsed_time / 1000.0),
                stat.last_execution_time)
                  ELSE req.start_time END, GETDATE()) AS [StatementMilliseconds],
       T2.login_name AS [LoginName],
       req.command AS [SQLCommand],
       req.[status] AS [QueryStatus],
       req.wait_type AS [WaitType],
       req.wait_time AS [WaitTimeMs],
       blocking_session_id AS [BlockingSessionId],
       req.row_count AS [RowCount],
       req.cpu_time AS [CpuTimeMs],
       sqltext.[text] AS [QueryBatch],
       SUBSTRING(sqltext.[text],
                 req.statement_start_offset / 2,
                 CASE req.statement_end_offset
                      WHEN -1 THEN DATALENGTH(sqltext.[text])
                      ELSE (req.statement_end_offset - req.statement_start_offset) / 2
                 END) AS [CurrentQuery]
FROM sys.dm_exec_requests req
INNER JOIN sys.dm_exec_sessions T2
        ON T2.session_id = req.session_id
LEFT JOIN sys.dm_exec_query_stats stat
        ON stat.[sql_handle] = req.[sql_handle]
       AND stat.statement_end_offset = (req.statement_start_offset - 2)
CROSS APPLY sys.dm_exec_sql_text(req.[sql_handle]) sqltext
-- WHERE req.session_id = 56
ORDER BY req.start_time;

Ich habe mit Ihrer Anfrage zu testen (leicht modifiziert) und die folgende SQL in einem anderen Tab / Sitzung (die Lauf TOP(1), TOP(2)usw., und 10.1, 10.2usw. auf die WAITFORZeiten sind , um es leicht sichtbar zu machen , welche Aussage verarbeitet wird , wenn bei der aktuellen Suche Anweisungsfeld):

SELECT GETDATE() AS [StartTime];
GO
SELECT TOP(1) [name] FROM sys.objects;
WAITFOR DELAY '00:00:10.1';

SELECT TOP(2) [name] FROM sys.objects;
WAITFOR DELAY '00:00:10.2';

SELECT TOP(3) [name] FROM sys.objects;
WAITFOR DELAY '00:00:10.3';

SELECT TOP(4) [name] FROM sys.objects;
WAITFOR DELAY '00:00:10.4';

Führen Sie dann Ihre Abfrage einfach mehrmals aus und es ist ziemlich klar, dass dm_exec_requests.start_timeund dm_exec_sessions.last_request_start_timesind:

  • der gleiche Wert und
  • Ändern Sie sich während der Ausführung dieses Stapels überhaupt nicht.

Ich habe versucht, den Ausführungsplan über zu erhalten CROSS APPLY sys.dm_exec_text_query_plan(req.plan_handle, req.statement_end_offset, req.statement_end_offset) tplan, aber das war NULLnicht sehr hilfreich.


Um mit Ihrer Abfrage zu testen, musste ich die ersten beiden Spalten und den Verweis auf die dbo.GetExecutingSQLStatementFunktion entfernen . Dies ist wahrscheinlich etwas, das Sie auch loswerden könnten, da Sie diese Logik in dieser Abfrage bereits über haben CROSS APPLY sys.dm_exec_sql_text(req.[sql_handle]). Sie müssen nur die folgenden drei Änderungen vornehmen:

  • T3.FullStatement (Feld 1 auswählen) wird sqltext.[text]

  • T3.ExecutingStatement (Feld 2 auswählen) wird SUBSTRING(sqltext.[text], req.statement_start_offset / 2, CASE req.statement_end_offset WHEN -1 THEN LEN(sqltext.[text]) ELSE (req.statement_end_offset - req.statement_start_offset) / 2 END)

  • Entfernen Sie das SUBSTRING(Ihr aktuelles letztes Feld). Wenn Sie sich das, was SUBSTRINGich direkt oben vorschlage , genau ansehen , ist es im Wesentlichen das, was Sie am Ende dort hatten. Erwarten Sie, dass es zwei Fehler korrigiert:

    • Ihr SUBSTRING hat nicht berücksichtigt, wann nur 1 Abfrage im Stapel vorhanden war. In diesem Fall statement_end_offsetwird -1Ihr Teilstring eine Fehlermeldung erhalten
    • Ihr SUBSTRING hat die Übersetzung der Doppelbyte-Byteanzahl in die Zeichenanzahl nicht berücksichtigt.

Aber ich schweife ab.


Solomon Rutzky
quelle