Quick Scan Report – Log File Slow IO

What this check looks for

Average I/O stall per operation for files where type_desc is LOG, from sys.dm_io_virtual_file_stats(NULL, NULL) joined to sys.master_files. Read and write stall are computed per operation, in milliseconds.

Why it matters

A log write is synchronous. The transaction cannot commit until the log record is on disk, so log latency is added to the duration of every write transaction, one for one.

This is the property that makes log storage different from data storage. A slow data file costs you on the queries that miss the buffer pool. A slow log file costs you on every commit, including the fastest, smallest transactions, which are the ones a busy OLTP system is made of. Ten milliseconds of log latency caps you at roughly a hundred commits per second per session no matter how fast everything else is.

The wait type is WRITELOG, and on an instance with a log latency problem it is usually at or near the top of the wait statistics.

Targets are tighter than for data files:

Average write Reading
Under 1 ms Excellent. NVMe or a write-back cache.
1 to 5 ms Good.
5 to 10 ms Acceptable but worth a look.
Over 10 ms A problem for an OLTP workload.
Over 20 ms Users will feel it.

And there is a second cause that is not the storage at all. The check’s own description names it: transactions that commit too often, or not often enough.

  • Too often. A loop inserting a million rows one at a time produces a million commits and a million log flushes. The storage is fine; the application is asking it to flush constantly. Batching into transactions of a few thousand rows removes nearly all of it.
  • Not often enough. One enormous transaction generates one enormous log flush and holds everything else up behind it.

Log file placement is the other usual cause. After tempdb, log files want the next fastest storage, and they want to be separate from data files. A log file shares a volume with data files and the sequential write pattern of the log is interleaved with the random read pattern of the data, which suits neither.

How to confirm it yourself

SELECT DB_NAME(vfs.[database_id])                                        AS [database_name],
       mf.[name]                                                         AS [logical_name],
       vfs.[num_of_writes],
       CAST(vfs.[io_stall_write_ms] * 1.0 / NULLIF(vfs.[num_of_writes], 0) AS DECIMAL(10,2)) AS [avg_write_ms],
       CAST(vfs.[io_stall_read_ms]  * 1.0 / NULLIF(vfs.[num_of_reads], 0)  AS DECIMAL(10,2)) AS [avg_read_ms],
       CAST(vfs.[num_of_bytes_written] / 1073741824.0 AS DECIMAL(12,1))   AS [gb_written],
       mf.[physical_name]
  FROM sys.dm_io_virtual_file_stats(NULL, NULL) AS vfs
 INNER JOIN sys.master_files AS mf WITH (NOLOCK)
         ON mf.[database_id] = vfs.[database_id] AND mf.[file_id] = vfs.[file_id]
 WHERE mf.[type_desc] = 'LOG'
 ORDER BY [avg_write_ms] DESC;

Whether it is actually costing you, which is the WRITELOG wait:

SELECT [wait_type], [waiting_tasks_count],
       [wait_time_ms] / 1000                            AS [wait_seconds],
       [wait_time_ms] * 1.0 / NULLIF([waiting_tasks_count], 0) AS [avg_ms]
  FROM sys.dm_os_wait_stats WITH (NOLOCK)
 WHERE [wait_type] IN ('WRITELOG', 'LOGBUFFER', 'LOGMGR_FLUSH', 'LOGMGR_QUEUE')
 ORDER BY [wait_time_ms] DESC;

And whether the commit pattern is the cause, by looking at the number of writes against the bytes written. A very high write count with a low average size means many tiny flushes, which points at the application rather than the disk:

SELECT DB_NAME(vfs.[database_id])                                         AS [database_name],
       vfs.[num_of_writes],
       CAST(vfs.[num_of_bytes_written] * 1.0 / NULLIF(vfs.[num_of_writes], 0) AS DECIMAL(12,0)) AS [avg_bytes_per_write]
  FROM sys.dm_io_virtual_file_stats(NULL, NULL) AS vfs
 INNER JOIN sys.master_files AS mf WITH (NOLOCK)
         ON mf.[database_id] = vfs.[database_id] AND mf.[file_id] = vfs.[file_id]
 WHERE mf.[type_desc] = 'LOG'
 ORDER BY [num_of_writes] DESC;

An average of a few hundred bytes per write is a workload committing row by row.

How to fix it

Three causes, and the fix is different for each.

1. The storage is slow.

  • Move the log to fast, separate storage. Log writes are sequential, so they benefit enormously from not sharing a volume with random data reads. This is the biggest single win available and it needs a maintenance window.
  • Check antivirus exclusions. .ldf should be excluded from real time scanning.
  • Check write caching. A battery backed or flash backed write cache on the controller turns log latency from milliseconds into microseconds, and a cache that has dropped to write-through because its battery failed is a classic overnight regression.

2. The commit pattern is wrong.

  • Batch row by row inserts into transactions of a few thousand.
  • Look at the top queries by execution count rather than by duration; the offender is usually something small running constantly.
  • Consider delayed durability for a workload that can tolerate losing the last few milliseconds of transactions on a crash. It is a real trade rather than a free win:
ALTER DATABASE [YourDatabase] SET DELAYED_DURABILITY = ALLOWED;

3. The log file is fragmented or badly sized. A log with tens of thousands of VLFs is slower to write, slower to back up and slower to recover. That has its own check, and the fix is one deliberate shrink and regrow in large steps.

Check the number of log files while you are there. More than one log file gives no performance benefit, because SQL Server writes to them sequentially rather than in parallel, and it has its own check.

How long it takes

About four hours to identify which cause and gather the evidence. Moving the log to different storage needs a window.


Report Why you would go there
I/O by Drive Every volume’s latency, to compare.
Disk Latency by Hour by Day Whether it has a daily shape.
Waits WRITELOG against everything else.
VLFs Log fragmentation, which adds to this.
Files Where the log files are and how big.
Open Transactions Very large transactions producing huge flushes.
Top Queries Needing Params High execution count queries committing constantly.
Check
TempDB file shows slow IO The same measurement on tempdb.
Slow Disk Reads The same across all files.
High VLF count Fragmentation that makes log writes worse.
Data and log files on the same drive The placement cause.
Database with multiple log files Extra log files that do not help.
Log truncation is blocked A different log problem with a different cause.

Frequently asked questions

Why is log latency worse than data latency? Because it is synchronous at commit. A data read happens when a query needs a page; a log write happens before any write transaction can finish.

Our log is on the same fast SSD as the data files. Is that fine? Better than a slow disk, and separating them still helps, because sequential log writes and random data reads interfere with each other.

What about multiple log files for more throughput? They do not provide it. SQL Server writes log files sequentially, filling one before moving to the next.

Is delayed durability safe? It is a deliberate trade: transactions commit before the log reaches disk, so a crash can lose the most recent ones. Right for some workloads, wrong for anything where losing a committed transaction is unacceptable.