Searching Every Error Log for Slow I/O Warnings

Slow I/O warnings often sit in an old error log, not the current one. If you search only the log you can see right now, you may miss the day your storage stalled.

The slow Friday

Users say everything was slow on Friday afternoon. It is Monday now, and you are asked whether the storage was the problem. You open the error log in SSMS and find nothing. Case closed?

Not quite. SQL Server starts a new error log each time the service restarts, and it keeps only a handful of older ones. The warning you want may be in an archive that the current view does not show. The warning reads something like “SQL Server has encountered some occurrence(s) of I/O requests taking longer than 15 seconds to complete on file” followed by a file name. That is the phrase we will search for.

List the logs you have

First, find out how many logs exist. The procedure sp_enumerrorlogs lists them. Archive number 0 is the current log, and higher numbers are older. I load the list into a temp table so the next step can walk it.

DROP TABLE IF EXISTS #ErrorLogs;
CREATE TABLE #ErrorLogs (ArchiveNumber int, LogDate datetime, LogBytes bigint);
INSERT #ErrorLogs EXEC master.sys.sp_enumerrorlogs;

SELECT COUNT(*) AS ArchivesEnumerated FROM #ErrorLogs;
SELECT ArchiveNumber, LogDate FROM #ErrorLogs ORDER BY ArchiveNumber;

On my test server this reported 7 logs: the current one and six archives. Yours will differ with how often the service restarts and how many logs you keep. The dates show how far back your trail goes. If the oldest date is after your incident, the evidence has already rolled away.

Search every archive

Now loop through each archive and read it with xp_readerrorlog. The first parameter is the archive number. The second, 1, picks the SQL Server log instead of the Agent log. The third is the text to look for. Reading logs needs a high server permission, so ask your admin if the call is refused.

Each archive runs in its own TRY block. If one log is locked or damaged, the loop records the failure and moves on. A search that quietly skips a log would give you false comfort.

DROP TABLE IF EXISTS #IoHistory;
DROP TABLE IF EXISTS #Failures;
CREATE TABLE #IoHistory (ArchiveNumber int, LogDate datetime, ProcessInfo nvarchar(50), [Text] nvarchar(max));
CREATE TABLE #Failures (ArchiveNumber int, ErrorText nvarchar(4000));

DECLARE @Archive int = 0, @Last int = (SELECT MAX(ArchiveNumber) FROM #ErrorLogs);

WHILE @Archive <= @Last
BEGIN
    BEGIN TRY
        INSERT #IoHistory (LogDate, ProcessInfo, [Text])
        EXEC master.dbo.xp_readerrorlog @Archive, 1, N'occurrence(s) of I/O requests';

        UPDATE #IoHistory SET ArchiveNumber = @Archive WHERE ArchiveNumber IS NULL;
    END TRY
    BEGIN CATCH
        INSERT #Failures (ArchiveNumber, ErrorText) VALUES (@Archive, ERROR_MESSAGE());
    END CATCH;

    SET @Archive += 1;
END;

Read the matches and the failures together

The next block shows three things. The first grid lists the matching warnings and the archive each came from. The second lists any logs that could not be read. The third looks at I/O requests that are outstanding right now.

SELECT ArchiveNumber, LogDate, ProcessInfo, [Text]
FROM #IoHistory
ORDER BY LogDate, ArchiveNumber;

SELECT ArchiveNumber, ErrorText
FROM #Failures
ORDER BY ArchiveNumber;

SELECT io_type, io_pending, io_pending_ms_ticks
FROM sys.dm_io_pending_io_requests
ORDER BY io_pending_ms_ticks DESC, io_type;

In my run, no warning matched, and the failure list was empty. That tells me about this search and the logs I had. It does not prove the storage was always healthy. Always read the failure grid before you trust an empty match grid.

The outstanding I/O view is a live snapshot. It is usually empty, and by Monday it cannot describe Friday. Treat it as a “right now” check, not as history.

When a warning does show up

Keep the whole message. It names the file, the database and how long the request waited. The count in each message covers a reporting interval, so do not add the numbers up as if each were a separate request. I did not cause any slow I/O in this demo, so I cannot show you a real match, and I will not invent a threshold from a clean run.

Two habits help. Copy the messages somewhere safe before more restarts push them out. And consider keeping more archived logs, so a Friday problem is still there on Monday. The last block removes the temp tables.

DROP TABLE IF EXISTS #Failures;
DROP TABLE IF EXISTS #IoHistory;
DROP TABLE IF EXISTS #ErrorLogs;

Before you blame a query, read the logs that came before today’s.

A clean current log is not a clean history, it is only the newest page.

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