Skany indeksów i statystyki odczytów STATISTICS IO

W SQL Server mamy wiele sposobów i narzędzi, za pomocą których możemy obserwować liczniki związane z wydajnością – DMV, statystyki sesji, Extended Events czy Profiler. Analizując szczegółowo pewien przypadek skanowania indeksu, natrafiłem na kolejny wyjątek przekłamywania informacji o dokładnej liczbie fizycznych odczytów przez zmienną sesji STATSTISTICS IO.


Statystyki odczytów – SET STATISTICS IO

Powszechnie znanym problemem związanym ze statystykami widocznymi poprzez STATISTICS IO, jest pomijanie liczby odczytów generowanych przez funkcje skalarne użytkownika. Brak informacji w planie wykonania, jak również w statystykach odczytu jest mylące i może prowadzić do błędnej interpretacji wyników np. w porównywaniu wydajności zapytań. Jak się okazuje nie jest to jedyny przypadek pomijania niektórych odczytów z wykorzystaniem STATISTICS IO.

Na zjawisko większej liczby stron wczytanej do pamięci niż by się można tego było spodziewać, natrafiłem testując skanowanie indeksu klastrowego. Warto podkreślić, że wbrew powszechnie utartym opiniom (powielanym zresztą w wielu publikacjach), skanowanie indeksu to nie tylko czytanie stron na poziomie liści (leaf level skan).

W trakcie skanu, wczytywana jest cała jego struktura, włącznie ze wszystkimi stronami poziomów pośrednich + strony IAM, co może wydawać się nieco zaskakujące. Wynika to prawdopodobnie z faktu, że zazwyczaj sama struktura indeksu (korzeń + poziomy pośrednie) jest relatywnie niewielka w stosunku do poziomu liści. Skanując więc tabelę, warto przy okazji przeczytać pozostałe strony, aby mieć w pamięci cały obiekt. Poza tym strony te, i tak głównie znajdują się w ekstentach zalokowanych na potrzeby danej tabeli, więc zysk z wykorzystanie odczytów wyprzedzających (read-ahead reads) jest znacznie większy niż odsiewanie stron indeksu (<> DATA_PAGES). Taka jest moja interpretacja tego faktu.

Krótki przykład. Skanowanie indeksu klastrowego tabeli dbo.Orders i liczba odczytów widocznych poprzez SET STATISTICS IO :

USE NORTHWIND
GO

DBCC DROPCLEANBUFFERS; 
DBCC FREEPROCCACHE; 
CHECKPOINT
GO

SET STATISTICS IO ON
GO

SELECT * FROM dbo.Orders
(830 row(s) affected)
Table 'Orders'. Scan count 1, logical reads 22, physical reads 1, read-ahead reads 21, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

W tym przypadku, pierwsze wykonanie zapytania (z wyczyszczonym buforem) skutkowało w sumie 22 odczytami fizycznymi (physical + read-ahead reads) ładującymi strukturę do pamięci RAM. Następnie, wszystkie 22 strony zostały odczytane (logical reads) w celu realizacji zapytania.
Zatem każde kolejne wykonanie tego zapytania będzie wiązało się już tylko z logicznymi odczytami owych 22 stron z bufora.

Dlaczego wartością oczekiwaną są 22 strony ? Zerknijmy na strukturę tego indeksu i całkowitą liczbę stron dla obiektu PK_Orders.

SELECT i.index_id, i.NAME
	,index_type_desc
	,index_level
	,page_count
	,record_count, avg_fragmentation_in_percent
FROM sys.dm_db_index_physical_stats(DB_ID(), OBJECT_ID(N'dbo.Orders'),1,NULL,'DETAILED') x
INNER JOIN sys.indexes i ON x.index_id = i.index_id
	AND x.object_id = i.object_id
order by i.index_id, x.index_level desc

statystyki_odczytow_01

Jak widać indeks jest dwu-poziomowy, 1 strona korzenia + 20 stron liści = 21. Brakującą stroną jest IAM, która również jest czytana. Pełna struktura, wszystkie strony dla obiektu PK_Orders to :

SELECT page_type_desc, count(*) as PageCnt
FROM  
	(select name, index_id from sys.indexes where object_id = object_id('dbo.Orders') and name = 'PK_Orders' ) i 
		cross apply sys.dm_db_database_page_allocations (db_id(), object_id('dbo.Orders'), index_id, NULL, 'DETAILED') a
	where page_type_desc is not null
group by page_type_desc 

statystyki_odczytow_02
Skanowanie indeksu to wczytanie wszystkich stron związanych z jego strukturą do pamięci. Oczywiście są pewne wyjątki, chociażby częściowe skanowanie indeksu (np. SELECT TOP 10 * FROM tabela), ale w przypadku pełnych skanów… to poprostu pełne skany.
Być może powyższy przykład jest mało przekonujący z uwagi na rozmiar indeksu, ale możesz ten fakt potwierdzić, samodzielnie odpytując strukturę bardziej rozdmuchanego indeksu :

SET STATISTICS IO OFF
GO
IF object_id('dbo.CLX_TEST') is not null
	DROP TABLE dbo.CLX_TEST
GO

CREATE TABLE dbo.CLX_TEST
(
	id bigint IDENTITY(1,1),
	id2 char(200) default NEWID(), 
	payload char(100),
)
GO

insert into dbo.CLX_TEST with (tablockx) (payload)
select top 10000 left(text,100) from sys.messages
GO

-- Kompozytowy   żeby trochę rozdmuchać indeks
CREATE CLUSTERED INDEX CLX_ID_ID2_CLX_TEST on dbo.CLX_TEST(id,id2)  

DBCC DROPCLEANBUFFERS; 
DBCC FREEPROCCACHE; 
CHECKPOINT
GO

SET STATISTICS IO ON
GO

SELECT * FROM dbo.CLX_TEST
 
SELECT  page_type_desc, page_level,  COUNT(*) as PageCnt
FROM  sys.dm_db_database_page_allocations 
         (db_id(), object_id('dbo.CLX_TEST'), 1, NULL, 'DETAILED') a
WHERE page_type_desc is not null
GROUP BY page_type_desc, page_level

Fizyczne odczyty

Wróćmy do odczytów fizycznych, czy na pewno było ich 22 ? Zerknijmy raz jeszcze na statystyki i liczbę stron danych bazy Northwind, które pojawią się w buforze (widok sys.dm_os_buffer_descriptors, strony z innych baz, odczyty systemowe etc. pomijam) :

IF object_id('tempdb..#t1') is not null
	DROP TABLE #t1
IF object_id('tempdb..#t2') is not null
	DROP TABLE #t2
GO

dbcc freeproccache
dbcc dropcleanbuffers
checkpoint
GO

select * into #t1 from sys.dm_os_buffer_descriptors where database_id = db_id()
select * from dbo.Orders
select * into #t2 from sys.dm_os_buffer_descriptors where database_id = db_id()

-- ile nowych stron ?
select count(*) as NowychStron 
from (
	select * from #t2  
	except 
	select * from #t1 
) x

statystyki_odczytow_03

Tym razem widzimy wynik 29. Zobaczmy więc co to są za strony :

;with cte as (
		select * from #t2   
		except 
		select * from #t1
  )  
select  d.page_id, d.page_level, d.page_type, d.row_count, x.extent_page_id, x.is_mixed_page_allocation,  OBJECT_NAME(p.object_id) as TableName , i.name  
from  cte d 
	inner join sys.dm_db_database_page_allocations (db_id(), null , null , NULL, 'DETAILED') x on d.page_id = x.allocated_page_page_id
	left join sys.allocation_units a on d.allocation_unit_id = a.allocation_unit_id 
	left join sys.partitions p on a.container_id = p.partition_id
	left join sys.indexes i on p.object_id = i.object_id and p.index_id = i.index_id
group by d.page_id, d.page_level, d.page_type, d.row_count, x.extent_page_id, x.is_mixed_page_allocation,  p.object_id , i.name  
order by page_id

statystyki_odczytow_04

No i tu niespodzianka. Pomimo, że skanujemy indeks klastrowy PK_Orders to przeczytaliśmy przy okazji 1 stronę zupełnie z innej tabeli (Order Details) plus 6 stron indeksów które nie biorą udziału w realizacji tego zapytania. Jak łatwo się domyślić jest to efekt uboczy mechanizmu read-ahead reads. Te dodatkowe (i niepotrzebne do realizacji zapytania) 7 stron, znajduje się w ekstentach mieszanych (tutaj są to ekstenty numer 456 i 472). Trafiły do buffer cache w wyniku read-ahead reads, co oczywiście nie jest wielkim narzutem ale rozbieżność w liczbie odczytów widocznych w STATISTICS IO pozostaje faktem.

Korzystając z DMV zobaczymy faktyczną liczbę stron wczytanych do bufora :

SELECT st.text, total_logical_reads, 
	total_physical_reads, execution_count,   last_rows
FROM sys.dm_exec_query_stats AS qs  
	 CROSS APPLY sys.dm_exec_sql_text(qs.sql_handle) AS st  
WHERE   st.text  not like '%sys%'

statystyki_odczytow_05
Możemy potwierdzić to zachowanie przechwytując informacje o odczytach za pomocą zdarzeń XE : file_read_completed i physical_page_read. Zdefniujmy sesję XE w ten sposób :

dbcc dropcleanbuffers
checkpoint
GO

CREATE EVENT SESSION [reads] ON SERVER 
ADD EVENT sqlserver.file_read_completed(SET collect_path=(1)
    WHERE ([sqlserver].[session_id]=( 52 ))),
ADD EVENT sqlserver.physical_page_read(
    WHERE ([sqlserver].[session_id]=( 52 ))) 
ADD TARGET package0.event_file(SET filename=N'C:\TEMP\file_read.xel')
WITH (MAX_MEMORY=4096 KB,EVENT_RETENTION_MODE=ALLOW_SINGLE_EVENT_LOSS,MAX_DISPATCH_LATENCY=30 SECONDS,
	  MAX_EVENT_SIZE=0 KB,MEMORY_PARTITION_MODE=NONE,TRACK_CAUSALITY=OFF,STARTUP_STATE=OFF)
GO
ALTER EVENT SESSION [reads] ON SERVER STATE = START;
GO

SELECT * FROM dbo.Orders
GO

DROP EVENT SESSION [reads] ON SERVER 
GO

SELECT Event_type,  SUM(size) as Size , COUNT(*) as Events_cnt
FROM   ( 
       SELECT	Event_type =n.event_xml.value('(//@name)[1]','nvarchar(max)'),
				size=e.event_data_XML.value('(//data[@name="size"]/value)[1]','int'), 
				page_id=e.event_data_XML.value('(//data[@name="page_id"]/value)[1]','int') 
 
        FROM    ( 
               SELECT CAST(event_data AS XML) AS event_data_XML 
               FROM sys.fn_xe_file_target_read_file(N'C:\temp\file_read*.xel', NULL, NULL, NULL) 
               )e CROSS APPLY event_data_XML.nodes('//event') n (event_xml)
       )q 
GROUP BY Event_type

Po wykonaniu zapytania z czystym buforem, dostaniemy informacje o następującej liczbie zdarzeń (file_read_completed zawiera parametr size wyrażony w bajtach co po prostym przeliczeniu 237568 / 1024 / 8 daje dokładnie 29 stron) :
statystyki_odczytow_06

No i na koniec jeszcze jeden sposób, ostatecznie potwierdzający że 29 stron to było dokładnie tyle, ile zostało wczytanych z pliku z danymi bazy Northwind. Korzystam tutaj z fajnego narzędzia MS do monitorowania aktywności – procmon dostępnego tutaj. Kilka filtrów (proces, plik bazodanowy) i prosta matematyka daje potwierdzenie poprzedniego rezultatu (3 faktyczne operacje IO, w sumie 29 stron).
statystyki_odczytow_07


Podsumowanie i wnioski

Informacje na temat statystyk odczytu widocznych w parametrach sesji STATISTICS IO powinny być traktowane jako przybliżone. Wartości odczytów dotyczą, obiektów które są widoczne w planie wykonania (+ wyjątki dla tabel tymczasowych pośrednich i funkcji skalarnych) – lepiej więc stosować DMV jeśli chcemy widzieć dokładne wyniki. Rozbieżność nie jest duża, nie ma negatywnego wpływu na wydajność i jest logicznie wytłumaczalna.
Skanowanie indeksów klastrowych to czytanie wszystkich stron związanych z ich strukturą (leaf pages, intermediate, root, IAM’s).

Dodaj komentarz

Twój adres e-mail nie zostanie opublikowany. Wymagane pola są oznaczone *

This site is protected by reCAPTCHA and the Google Privacy Policy and Terms of Service apply.