Was ist STATISTICS TIME?
In der letzten Woche hattet Ihr Statistics IO kennengelernt, ein Hilfsmittel, das euch verrät, wie viele Daten eine Abfrage von der Festplatte lesen muss, um eine Abfrage zu beantworten. Wie unterscheidet sich nun Statistics Time von Statistics IO? Während Statistics IO die Festplattenzugriffe protokolliert, liefert Statistics Time die benötigte CPU Zeit einer Abfrage zurück. Das heißt, die Zeit, die einerseits verwendet wurde, um die Abfrage zu lesen, zu verstehen und einen Ausführungsplan für die Abfrage zu finden und andererseits die Zeit, die die CPU während der Durchführung der Abfrage beispielsweise mit Berechnung von Werten beschäftigt war.
Wie könnt ihr mit STATISTICS TIME arbeiten?
Wenn ihr sehen wollt, wie viele Zugriffe auf die Festplatte eine Abfrage verursacht, dann könnt ihr diese Information erlangen, indem ihr vor der Abfrage ein SET STATISTICS TIME ON abschickt. Was ihr dann seht ist eine Reihe von Informationen, die wir im Folgenden ein wenig untersuchen möchten.
Fragen wir dafür nun mit den Statistiken die StockItems-Tabelle in der Wide World Importers Datenbank ab:
SET STATISTICS TIME ON
SELECT
[StockItemID]
,[StockItemName]
,[UnitPrice]
FROM [Warehouse].[StockItems]
Neben den Resultaten erhaltet ihr im Messages-Reiter noch Informationen über die Ausführung:
SQL Server Execution Times:
CPU time = 1 ms, elapsed time = 0 ms
Total execution time: 00:00:00.019
Hier seht ihr, dass der SQL Server für die Abfrage insgesamt eine Millisekunde CPU Zeit aufbringen musste.
Dass die CPU hier nicht viel zu tun hatte, ist klar, es wurden ja nur 3 Werte einer Tabelle ausgelesen und zurückgeliefert. Geben wir der CPU nun also etwas zu tun, indem wir eine Berechnung auf einer der Spalten ausführen:
SET STATISTICS TIME ON
SELECT
sin([StockItemID])
,[StockItemName]
,[UnitPrice]
FROM [Warehouse].[StockItems]
Wir berechnun nun also den Sinus der StockItemID. Wie sinnvoll das ist, darüber möchte der Ninja zunächst einmal kein Wort verlieren, stattdessen sprechen wir lieber darüber, was nun mit unserer Statistik geschieht. Die Ausgabe sieht nun wie folgt aus:
SQL Server parse and compile time:
CPU time = 0 ms, elapsed time = 0 ms.
(227 rows affected)
SQL Server Execution Times:
CPU time = 0 ms, elapsed time = 0 ms.
Hier könnt ihr sehen, dass der SQL Server nun einen weiteren Schritt bei der Ausführung der Abfrage benötigt, um die Abfrage zu lesen und einen Ausfühungsplan zu ermitteln. Die Zeit, die dafür benötigt wird, ist aber so gering, dass sie im Falle einer so einfachen Abfrage nicht weiter ins Gewicht fällt und null Millisekunden in Anspruch nimmt. Auch das Berechnen des Sinus bringt die CPU gerade anscheinend nicht gerade zum Glühen, da die CPU Zeit für die 227 Zeilen nicht einmal messbar ist, also erhöhen wir ganz nach den Trainingsgrundsätzen des Ninjas die Komplexität noch einmal und versuchen, die CPU zum Rechnen zu bekommen. Dafür lassen wir uns etwas neues einfallen und machen einen Join auf eine größere Tabelle, wobei wir auf den Spalten, über die wir joinen möchten, eine Berechnung durchführen.
Eine solche Anfrage wäre beispielsweise:
SET STATISTICS TIME ON
SELECT
si.[StockItemID]
,[StockItemName]
,[UnitPrice]
FROM [Warehouse].[StockItems] si
LEFT JOIN Warehouse.StockItemTransactions sit
ON sin(si.[StockItemID]) = cos(sit.[StockItemID])
Dass auch diese Abfrage vollkommen sinnfrei ist, ist klar, doch erfüllt sie ihren Zweck, denn wenn ihr nun auf die Statistiken schaut, dann solltet ihr einen Output sehen, der so oder so ähnlich aussieht:
SQL Server Execution Times:
CPU time = 97 ms, elapsed time = 373 ms.
Total execution time: 00:00:00.453
Hier seht ihr, dass tatsächlich die CPU eures Rechners für diese Abfrage einige Rechenoperationen durchführen musste, die insgesamt 97 Millisekunden der insgesamt 373 Millisekunden die eure Abfrage dauerte in Anspruch genommen haben.
Ähnlich wie bei IO Statistiken, ist auch das Tuning von Abfragen mittels Time-Statistiken eine Wissenschaft für sich, die einen einfachen Ninja-Beitrag sprengen würde. Dennoch lohnt es sich hier einmal einen Blick darauf zu werfen, da auch eine Parse und Compile Zeit von 10 Millisekunden bei einer Abfrage, die 1000 Mal pro Minute ausgeführt wird, einen Laufzeitunterschied von 10 Sekunden verursacht. Auch hier verweist der Ninja in Erfurcht auf die anerkannten Tuning-Experten dieser Welt.
