Database File Latency: Read and Write Stalls per IO

Database file latency is the average time one read or one write waits for the disk. SQL Server records the total wait and the number of calls for every file. Divide one by the other, and you can compare files on different drives fairly.

Gouache painting of three hourglasses side by side, the first with grey sand and the other two with vermilion sand

Divide the Stall by the Calls

The view sys.dm_io_virtual_file_stats holds io_stall_read_ms, the total milliseconds that reads waited, and num_of_reads, the number of reads. The write columns work the same way. The total alone misleads. A file with a million fast reads collects a large stall total. One slow file with a few reads looks harmless.

Dividing the total by the count gives database file latency per call. Guard the division with NULLIF. A file that has had no reads would otherwise raise a divide by zero error. A companion post on the same view compares files over a window. This one reads the per-call split between reads and writes and the queued columns.

Build a Small Test Database

The demo has one data file and one log file in the default folders. The script reads those folders from the server and needs about 100 MB of free space. A table of 100,000 shipments gives the disk something to do.

DECLARE @dir nvarchar(260) = CONVERT(nvarchar(260), SERVERPROPERTY('InstanceDefaultDataPath'));
DECLARE @log nvarchar(260) = CONVERT(nvarchar(260), SERVERPROPERTY('InstanceDefaultLogPath'));
DECLARE @sql nvarchar(max) = N'CREATE DATABASE FileLatencyDemo ON PRIMARY (NAME = N''FileLatencyDemo'', FILENAME = N''' + @dir + N'FileLatencyDemo.mdf'', SIZE = 64MB) LOG ON (NAME = N''FileLatencyDemo_log'', FILENAME = N''' + @log + N'FileLatencyDemo_log.ldf'', SIZE = 32MB);';
IF DB_ID(N'FileLatencyDemo') IS NULL EXEC (@sql);
GO
USE FileLatencyDemo;
GO
CREATE TABLE dbo.Shipments (ShipmentID int IDENTITY(1,1) PRIMARY KEY, CustomerID int NOT NULL, Note char(200) NOT NULL DEFAULT 'standard shipment');
INSERT INTO dbo.Shipments (CustomerID) SELECT TOP (100000) ABS(CHECKSUM(NEWID())) % 500 FROM sys.all_objects AS a CROSS JOIN sys.all_objects AS b;
CHECKPOINT;

Next comes a workload. Taking the database offline and online again resets the counters and the cache, so the reads must come from disk. The workload scans the table once and updates half of the rows. Run the offline step only on a test database.

USE master;
ALTER DATABASE FileLatencyDemo SET OFFLINE WITH ROLLBACK IMMEDIATE;
ALTER DATABASE FileLatencyDemo SET ONLINE;
GO
USE FileLatencyDemo;
GO
SELECT COUNT(*) AS Shipments FROM dbo.Shipments;
UPDATE dbo.Shipments SET Note = 'delivered on time' WHERE ShipmentID % 2 = 0;
CHECKPOINT;

Read the Latency per File

The query keeps read and write latency apart, because the two tell different stories. It adds a combined figure, AvgStallMs, for ranking. The last four columns are the raw totals, which let you check the division by hand.

SELECT mf.name AS LogicalName, mf.type_desc AS FileType,
       vfs.num_of_reads AS Reads,
       CAST(vfs.io_stall_read_ms * 1.0 / NULLIF(vfs.num_of_reads, 0) AS decimal(9, 2)) AS AvgReadMs,
       vfs.num_of_writes AS Writes,
       CAST(vfs.io_stall_write_ms * 1.0 / NULLIF(vfs.num_of_writes, 0) AS decimal(9, 2)) AS AvgWriteMs,
       CAST(vfs.io_stall * 1.0 / NULLIF(vfs.num_of_reads + vfs.num_of_writes, 0) AS decimal(9, 2)) AS AvgStallMs,
       vfs.io_stall_read_ms, vfs.io_stall_write_ms, vfs.io_stall_queued_read_ms, vfs.io_stall_queued_write_ms
FROM sys.dm_io_virtual_file_stats(DB_ID(), NULL) AS vfs
INNER JOIN sys.master_files AS mf ON mf.database_id = vfs.database_id AND mf.file_id = vfs.file_id
ORDER BY AvgStallMs DESC;
LogicalNameFileTypeReadsAvgReadMsWritesAvgWriteMsAvgStallMs
FileLatencyDemoROWS880.43490.370.41
FileLatencyDemo_logLOG80.381230.120.14

This is one run on a solid state drive, so every figure is well under a millisecond. Your drive will give other numbers. The shape is what matters. The data file waited longer per call than the log file in every run. Log writes were the fastest calls. Whether data reads or data writes wait longer changes from run to run. The log file wrote 123 times at about a tenth of a millisecond.

The two queued columns stayed at zero. They count time that a call waited in a queue created by Resource Governor, which limits IO per volume. They are zero unless you use that limit, so ignore them otherwise. The view needs VIEW SERVER STATE, or VIEW SERVER PERFORMANCE STATE on SQL Server 2022 and later.

What Counts as Slow

No single number fits every system. A common rule of thumb asks questions when data reads average above 20 milliseconds. For log writes the line is 5. Treat those as prompts, not limits. Compare a file with its own history first. A file that averaged 2 milliseconds last month and averages 18 now has changed, even though 18 passes the rule.

The database file latency tally covers everything since the instance started or the database opened. A slow hour at 200 milliseconds can vanish into a quiet month. To see one hour, read the view twice and subtract. The post IO Stalls by Database File: Find the File to Move shows that method step by step.

Before You Buy a Faster Disk

A slow file has three possible answers. Reduce the work the database does on that file. Make the queries that touch it cheaper. Or move the file to a faster drive. The first two cost less than hardware, so try them first. Before any of them, check how much of the total traffic the file carries. The post Reads and Writes per File: Rank Files by Bytes Moved ranks files by volume. A slow file that carries almost nothing is not your bottleneck.

You could argue that an average hides the damage. A file with a 0.4 millisecond average can still stall for 200 milliseconds a few times an hour. That is true, and the view cannot show it. Use it to find the files worth a closer look.

What to Remember

Compute database file latency as stall milliseconds divided by calls, for reads and writes separately. Guard the division, and compare each file with its own history. Read the figures since the last restart with care, and subtract two readings for a recent window. When you finish, remove the demo database.

USE master;
GO
ALTER DATABASE FileLatencyDemo SET SINGLE_USER WITH ROLLBACK IMMEDIATE;
DROP DATABASE FileLatencyDemo;

A big stall total is not a slow disk, it is a slow disk only when each call waits.

Published by Pinal Dave on SQLAuthority. More of my work at pinaldave.com.


Discover more from SQL Authority with Pinal Dave

Subscribe to get the latest posts sent to your email.

Disk, SQL DMV, SQL Performance, SQL Scripts
Previous Post
Query Store Interval Length: Choosing How Fine Your History Is
Next Post
Long Running Queries in MySQL: Find Them in Two Ways

Related Posts

Leave a Reply

Your email address will not be published. Required fields are marked *

Fill out this field
Fill out this field
Please enter a valid email address.