HiveBrain v1.2.0
Get Started
← Back to all entries
patternsqlModerate

Does STATISTICS IO output include Version Store reads?

Submitted by: @import:stackexchange-dba··
0
Viewed 0 times
versionincludeoutputstorereadsstatisticsdoes

Problem

SQL Server has an option SET STATISTICS IO ON that shows the number of logical and physical page reads for a query. Do these stats include reads of the version store for SNAPSHOT and RCSI queries?

Solution

STATISTICS IO does not include Version Store reads, at least for the version store in tempdb.

Here's a demo for proof:

--setup script
USE master
GO

CREATE DATABASE TestDB
GO

ALTER DATABASE TestDB
SET ALLOW_SNAPSHOT_ISOLATION ON
GO

USE TestDB
GO

DROP TABLE IF EXISTS dbo.Test
GO

CREATE TABLE dbo.Test (ID int identity PRIMARY KEY, junk int)

INSERT dbo.Test
SELECT TOP (100000) 1
FROM master.dbo.spt_values a
CROSS JOIN master.dbo.spt_values b


Start a 30s update loop in one SSMS tab

--UPDATE loop
SET NOCOUNT ON
DECLARE @stop datetime = DATEADD(SECOND, 30, GETDATE())

WHILE GETDATE() < @stop
BEGIN
    BEGIN TRAN

    UPDATE dbo.Test
    SET junk += 1

    COMMIT
END

UPDATE dbo.Test
SET junk = 1


And while the loop is going, run two identical queries in SNAPSHOT with STATISTICS IO ON, separated by 15s to allow versions to accumulate.

USE TestDB
SET STATISTICS IO ON
GO

SET TRANSACTION ISOLATION LEVEL SNAPSHOT

BEGIN TRAN

SELECT MAX(junk)
FROM dbo.Test

WAITFOR DELAY '00:00:15'

SELECT MAX(junk)
FROM dbo.Test

COMMIT


The IO stats show identical reads:

But the actual execution plan shows the scan for the second query taking far more time, due to reading the version store.

To prove to yourself that this query resulted in tempdb reads, you can use this Extended Events session (which is obviously better than Profiler), filtered to the session where the read queries are running:

CREATE EVENT SESSION [file_reads] ON SERVER 
ADD EVENT sqlserver.file_read_completed(
    ACTION(sqlserver.session_id,sqlserver.sql_text)
    WHERE ([sqlserver].[session_id]=(52)))
ADD TARGET package0.event_file(SET filename=N'file_reads')
GO


Viewing the "live data" for that XE session during the demo, you can see reads against database id 2 (tempdb), and it captures the query text of our read query as well:

Special thanks to Paul White for bringing up this issue with STATISTICS IO.

Code Snippets

--setup script
USE master
GO

CREATE DATABASE TestDB
GO

ALTER DATABASE TestDB
SET ALLOW_SNAPSHOT_ISOLATION ON
GO

USE TestDB
GO

DROP TABLE IF EXISTS dbo.Test
GO

CREATE TABLE dbo.Test (ID int identity PRIMARY KEY, junk int)

INSERT dbo.Test
SELECT TOP (100000) 1
FROM master.dbo.spt_values a
CROSS JOIN master.dbo.spt_values b
--UPDATE loop
SET NOCOUNT ON
DECLARE @stop datetime = DATEADD(SECOND, 30, GETDATE())

WHILE GETDATE() < @stop
BEGIN
    BEGIN TRAN

    UPDATE dbo.Test
    SET junk += 1

    COMMIT
END

UPDATE dbo.Test
SET junk = 1
USE TestDB
SET STATISTICS IO ON
GO

SET TRANSACTION ISOLATION LEVEL SNAPSHOT

BEGIN TRAN

SELECT MAX(junk)
FROM dbo.Test

WAITFOR DELAY '00:00:15'

SELECT MAX(junk)
FROM dbo.Test

COMMIT
CREATE EVENT SESSION [file_reads] ON SERVER 
ADD EVENT sqlserver.file_read_completed(
    ACTION(sqlserver.session_id,sqlserver.sql_text)
    WHERE ([sqlserver].[session_id]=(52)))
ADD TARGET package0.event_file(SET filename=N'file_reads')
GO

Context

StackExchange Database Administrators Q#237704, answer score: 10

Revisions (0)

No revisions yet.