7

We have been having CPU issues with one of our servers lately and while we have been looking into this we have also noticed queries running slowly with waits of PAGEIOLATCH_XX. In particular, a reindex job is seemingly always having this wait type.

In response, I have run a collect against sys.dm_io_virtual_file_stats and then broken this down into time chunk and worked out the average stall per operation. While there are spikes mostly, the disk seems to have a value of regularly under 20 ms. From what I remember, 20 ms is the recommended value(?).

Further to this I have run Glenn Barry's script:

select db_name(database_id) as DatabaseName, file_id
,io_stall_read_ms
,num_of_reads
,cast(io_stall_read_ms/(1.0+num_of_reads) as numeric(10,1)) as 'avg_read_stall_ms'
,io_stall_write_ms
,num_of_writes
,cast(io_stall_write_ms/(1.0+num_of_writes) as numeric(10,1)) as 'avg_write_stall_ms'
,io_stall_read_ms + io_stall_write_ms as io_stalls
,num_of_reads + num_of_writes as total_io
,cast((io_stall_read_ms+io_stall_write_ms)/(1.0+num_of_reads +
num_of_writes) as numeric(10,1)) as 'avg_io_stall_ms'
from sys.dm_io_virtual_file_stats(null,null) --where db_name(database_id) = 'tempdb'
order by [DatabaseName] desc'

Which calculates the average I/O stall also and this also confirms stalls less than 20 ms.

I have also looked in the following to see if any pending tasks are taking longer than recommended, but this isn't throwing up any pending I/O operations taking regularly longer than 20 ms.

SELECT db_name(database_id) as 'Database',
file_name(file_id) as 'File',
io_stall,
io_pending_ms_ticks
FROM sys.dm_io_virtual_file_stats(NULL, NULL) iovfs,
 sys.dm_io_pending_io_requests as iopior
WHERE iovfs.file_handle = iopior.io_handle

My question now is: If the issue is not disk related, why am I seeing lots of PAGEIOLATCH_XX waits? In particular, why is the reindex running extremely slowly with this wait type?

Could this be related to CPU pressure?

================================================================================

I just wanted to update the thread. After doing more analysis I have tracked down a particular proc that is causing significant reads. The proc is as follows:

ALTER PROCEDURE [dbo].[GetActiveSessionCount]
    @SessionCount   INTEGER OUTPUT
AS
SET NOCOUNT ON
BEGIN
    DECLARE @Error              INTEGER,
            @RowCount           INTEGER,
            @nExpireAfter       INTEGER
    SELECT  @nExpireAfter = ExpireSessionsAfter FROM KSYSTEM
    SELECT @Error = @@ERROR, @RowCount = @@ROWCOUNT
IF(1 <> @RowCount)
BEGIN
RAISERROR (50003, 15, 1, 'GetActiveSessionCount')
RETURN 50003
END
    IF (0 <> @Error)
    BEGIN
        RETURN @Error
    END
    SELECT  @SessionCount = COUNT(SessionID)
    FROM    KSESSION  WITH (NOLOCK)
    WHERE
    (
        (
            Expirable = 0
        )
        OR
        (
            Expirable = 1
            AND
            (   --SessionID IS NOT NULL)
                EXISTS (SELECT SessionID FROM KFILESAWAITINGCOMMIT fac WITH (NOLOCK) WHERE SessionID = fac.SessionID)
                OR
                (
                    LastAccessDateTime IS NOT NULL
                    AND GETDATE() <= (DATEADD(minute, @nExpireAfter, LastAccessDateTime))
                )
            )
        )
    )

SELECT @Error = @@ERROR
IF(@Error <> 0)
BEGIN
RETURN @Error
END
    RETURN 0
END

Using STATISTICS IO I can see the problem line is

SELECT SessionID FROM KFILESAWAITINGCOMMIT fac WITH (NOLOCK) WHERE SessionID = fac.SessionID

Looking at the execution plan it is doing a Clustered Index Scan. Now there is an non clustered index on that table already specifically for SessionID however it is not being used.

What I am finding in testing is if I run that SELECT by itself then it uses the non clustered index and performs well. But if I use a hint in the proc to force it to use the non clustered index, then it actually performs worse.

Can anyone explain?

  • I would expect to see these with a reindex process, it does not necessarily mean it is a bad wait. If you see your disk is within operational boundaries why worry about it? What other wait types show up for SQL Server? – Shawn Melton Jun 5 '15 at 11:47
  • 1
    I am interested in DB size, Memory in GB – RayofCommand Jun 5 '15 at 14:20
  • 1
    Can you try using an alias on the KSESSION table say ks and then use that in your problematic sub query: SELECT ks.SessionID FROM KFILESAWAITINGCOMMIT fac WITH (NOLOCK) WHERE ks.SessionID = fac.SessionsID? – James Anderson Jun 9 '15 at 15:11
  • I would reconsider using the NOLOCK hint too if the data returned is important – James Anderson Jun 9 '15 at 15:12
  • hmm that actually produces a different result set. – Tom Jun 9 '15 at 15:26
4

PAGEIOLATCH_XX waits are logged by SQL Server when it is waiting for data to be read from the disk. Index maintenance is a notoriously intensive operation and because of this it should be performed at your quietest times to avoid any impact on production.

You mention you have queries that are causing the same waits. If this is at the same time as the index maintenance then that is not that odd but if it's happening at other times it could be down to memory pressure (not enough room in RAM to store pages so they need to be read from the disk again), large scans or it could even indicate there is a potential problem with your disks. More investigation is needed to rule each of these out.

  • Yes but with all latency looking like its within acceptable parameters could this still be a disk issue, perhaps a SAN fabric problem. Would it makes sense to make that conclusion? – Tom Jun 5 '15 at 9:12
  • I wouldn't jump to that conclusion. If the latency is OK then your disk/SAN sounds like it's OK. The wait stat is telling you a lot of data is being read from the disk. The key is finding out why. Reindexing will cause this during the reindex operation. The queries may be doing it because of the points I mentioned above or possible somehitng else. Needs more investigation. Check the plan of the worst offending query to see what it is doing. Is it scaning very large tables? How is memory pressure on the box? – James Anderson Jun 5 '15 at 9:18
  • 1
    You could also look at queries which scan awful amount of data (logical and physical IO) - Check this post here: sqlskills.com/blogs/paul/… – Spörri Jun 5 '15 at 11:37
  • I have updated the thread with more information – Tom Jun 9 '15 at 14:44

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.