Kilka słów o STATISTICS IO, STATISTICS TIME

Jedną z podstawowych informacji jakie możemy uzyskać w trakcie optymalizacji zapytań jest informacja o statystykach czasowych i statystykach związanych z odczytami stron danych. Ale co tak naprawdę te komunikaty oznaczają?
W ramach niniejszego artykułu postaram się Wam przybliżyć dwie komendy pozwalające uzyskać te informacje, a mianowicie SET STATISTICS TIME oraz SET STATISTICS IO. Do celów demonstracyjnych wykorzystamy bazę WideWorldImporters.

SET STATISTICS IO ON

Na samym początku włączymy statystyki:

SET STATISTICS IO ON

Ustawienie to odnosi się jedynie do sesji, a nie serwera – dlatego też otrzymamy żądane informacje dla każdego zapytania jakie uruchomimy w ramach bieżącej sesji. Jeżeli chcemy wyłączyć te informacje możemy to osiągnąć w analogiczny do powyższego sposób zmieniając jedynie przełącznik z ON na OFF:

SET STATISTICS IO OFF

Kolejnym krokiem jaki wykonamy będzie odpytanie wybranej tabeli z włączonymi STATISTICS IO. Nim jednak to zrobimy to użyjemy komendy DBCC DROPCLEANBUFFERS, która da nam pewność, że żadna z naszych stron danych nie znajduje się w buforze oraz DBCC FREEPROCCACHE usuwająca cache planów zapytań (pamiętajcie żeby nie wykonywać tych zapytań na środowisku produkcyjnym!):

DBCC DROPCLEANBUFFERS
DBCC FREEPROCCACHE GO
SELECT * FROM Dimension.Customer AS C
WHERE C.Category ='Novelty Shop'

W tym miejscu przedstawmy co każdy z otrzymanych zapisów oznacza:

• Logical reads – liczba stron przeczytanych z pamięci
• Physical reads – liczba stron przeczytanych z dysku
• Read-ahead reads – liczba stron przeczytanych w ramach mechanizmu Read-Ahead (jest to mechanizm, który może odczytać do 64 dodatkowych stron z danych niejako „zgadując”, że mogą być one potrzebne)
• LOB logical reads – liczba stron zawierających obiekty typu LOB(ang. Large Object Binary – obiekty przechowywane m.in. w kolumnie typu varbinary(max) itp.) z pamięci
• LOB physical reads – liczba stron zawierających obiekty typu LOB z dysku
• LOB read-ahead reads – liczba stron zawierających obiekty typu LOB przeczytanych przez mechanizm Read-ahead

Tak więc zinterpretujmy sobie nasze testowe zapytanie. SQL Server w trakcie wykonania zapytania musi się upewnić czy 8KB strony z pożądanymi danymi znajdują się w pamięci operacyjnej – mogą się one tam znajdować w wyniku fizycznych odczytów wykonanych podczas bieżącego lub wcześniejszych zapytań . Jeżeli SQL Server wykryje, że pożądanych stron nie ma w pamięci to  wywoływana jest operacja IO w celu odczytu tych stron z dysku. W ramach naszego SELECT’a SQL Server odczytał 1 stronę bezpośrednio z dysku oraz 20 kolejnych w ramach mechanizmu Read-Ahead. Strony po odczytaniu z dysku zostały umieszczone na wydzielonej do tego celu części pamięci nazwanej data cache. Następnie po tych fizycznych operacjach 15 stron danych zostało odczytanych z pamięci aby zwrócić pożądany przez zapytanie wynik. Odnotujmy tutaj to, że nie może w ramach zapytania występować odczyt fizyczny bez odczytu logicznego tj. dane odczytane fizycznie z dysku są umieszczane w pamięci i optymalizator odczytuje te dane bezpośrednio z pamięci.

Ze względu na fakt, iż tabela Dimension.Customer nie zawiera żadnych danych typu LOB to wskaźniki związane z tymi typami są równe 0. Jeżeli byśmy ponownie uruchomili powyższe zapytanie to wtedy wszystkie pożądane dane znajdowałyby się w pamięci tak więc nie występowałyby żadne odczyty fizyczne (również te pochodzące z mechanizmu read-ahead). Jeżeli chodzi o odczyt danych LOB to należy również pamiętać, że indeksy kolumnowe są interpretowane jako obiekty typu LOB i zapytanie w momencie korzystania z takiej struktury w informacjach będzie zwracać informacje tak jakby były one obiektem typu LOB. Jednakże indeksy kolumnowe wykraczają poza ramy niniejszego artykułu i zajmiemy się nimi w późniejszym czasie.

Oprócz powyższych informacji otrzymaliśmy również tajemniczo brzmiące Scan Count równy 1. Jest to informacja oznaczająca nic innego jak liczbę operacji skanowania lub wyszukiwania na poziomie liści indeksu. Scan Count może być równy 0 jedynie w przypadku gdy szukana jest jedna wartość w ramach indeksu unikalnego – tak jak zostało to przedstawione poniżej. Pole Customer Key jest kluczem głównym tabeli Dimension.Customer, a więc automatycznie założony na nim został unikalny indeks zgrupowany.

SELECT * FROM Dimension.Customer AS C
WHERE C.[Customer Key]=1

Scan count może również przyjmować wartość większą niż 1 wtedy gdy do wyszukania określonych wartości potrzeba więcej niż jednej operacji na poziomie liści. Dlatego też poniższe zapytanie wyszukujące potrzebuje 3 operacji typu Index seek aby zwrócić pożądany rezultat:

SELECT
*
FROM
Dimension.Customer AS C
WHERE
C.[Customer Key] IN (1,2,3)

SET STATISTICS TIME ON

Kolejną z omawianych statystyk dostępnych w SQL Server jest statystyka czasowa. Aby otrzymać takową statystykę możemy wykorzystać polecenie SET STATISTICS TIME ON. Podobnie jak w poprzednim przypadku tak i teraz ustawienie to odnosi się do bieżącej sesji. Włączmy je, wykonajmy testowe zapytanie i spójrzmy na otrzymany rezultat.

SET STATISTICS TIME ON
GO
SELECT * FROM Dimension.Customer AS C
JOIN Fact.[Order] AS O
ON O.[Customer Key]=C.[Customer Key] GO

Pierwszy węzeł, a mianowicie SQL Server parse and compile time jest niczym innym jak czasem w milisekundach, który był potrzebny na optymalizację zapytania. Parsowanie jest to proces podczas, którego zapytanie SQL jest sprawdzane pod kątem poprawności syntaktycznej. W tym węźle zawiera się również czas potrzebny na powstanie wewnętrznej struktury zwanej drzewem wykonania. Compilation Time z kolei jest to czas potrzebny na kompilację planu zapytania powstałego na podstawie powstałego wcześniej drzewa wykonania. W przypadku gdy wartości w tym węźle są równe 0 ms oznacza to, iż optymalizator nie spędził żadnego czasu na optymalizacji ponieważ gotowy plan znajdował się w plan cache.

Kolejną widoczną częścią rezultatu jest węzeł SQL Server Execution Times, który jest rzeczywistym czasem potrzebnym na wykonanie zapytania na podstawie skompilowanego planu wykonania . CPU Time tak jak możecie się domyślać oznacza czas procesora potrzebny na realizację zapytania – warto tutaj zauważyć, iż w przypadku gdy SQL Server używa wielu CPU do wykonania zapytania to czas ten może być wyższy niż rzeczywisty czas (jest to nic innego jak suma czasów każdego z CPU, które wykonywały zapytanie). Elapsed time z kolei mówi o tym, jaki rzeczywisty czas minął na całościową realizację zapytania(czy też jego optymalizację).

Warto pamiętać, iż nawet na tej samej maszynie wykonanie tego samego zapytania może różnić się czasami ze względu na fakt, iż cały proces zależy m.in. od dostępności zasobów, cache itd.

Informacje o czasach związanych z parsowaniem i kompilacją możemy również wyczytać z planów wykonania. Wystarczy dla danego zapytania włączyć plan zapytania w wersji XML i tam odnaleźć węzeł QueryPlan tak jak zostało to przedstawione na poniższym zrzucie ekranowym:

Pojawia się pytanie jak używać tych danych podczas procesu optymalizacji naszych zapytań?

Jeśli chodzi o STATISTICS IO to jest to narzędzie pozwalające nam np. w przypadku gdy zminimalizowaliśmy rozmiar danych zmierzyć różnicę o ilości stron itp. Nie przywiązujmy wagi do odczytów fizycznych – to, że strony danych znajdują się na dysku, a nie w pamięci nie jest elementem tuningu konkretnych zapytań. Jeśli chodzi o czasy należy mieć na uwadze, że są to statystyki bardzo mocno związane z serwerem. Dodatkowo trzeba pamiętać, iż w grę wchodzą tutaj również czasy związane z dostarczeniem danych do narzędzia klienckiego czy też jego graficzne wyświetlenie. Tak więc narzędzia te nie są panaceum na wszystkie problemy i nie dają konkretnych odpowiedzi lecz myślę, że każdy kto na poważnie chce zajmować się SQL Server powinien potrafić się nimi posługiwać.