Gathering I/O statistics down to the database file level

When managing your SQL Server environment there are many aspects that need to be reviewed to determine where the bottlenecks are occurring to ensure you are getting the best performance possible. SQL Server offers many great tools and functions to determine issues with locking, blocking, fragmentation, missing indexes, deadlocks, etc... In addition, to looking at all of these areas another area of concern is I/O. Disk I/O can be tracked at the OS level by using counters in Performance Monitor, but these counters give you an overall picture of what is occurring on the server. What other options are available to look at I/O related information down to the file level for each database?

Solution
As mentioned above, SQL Server offers many great little functions and utility programs to help you gain an insight as to what is occurring on the server. One of these tools is fn_virtualfilestats.

This function, fn_virtualfilestats allows you to get information for each physical file that is being used to hold your data including both the data and log files. The function returns read and write information as well as stall information, which is the time users had to wait for an I/O operation to complete. Each time this function is called it returns the overall numbers that SQL Server has collected since the last time the database engine was started, so to use this effectively you need to gather data from two different points of time and then do a comparison.

To run this function to get data for all databases and all files this can be done as easily as this:

SQL 2005

SELECT * FROM fn_virtualfilestats(NULL,NULL);

SQL 2000

SELECT * FROM :: fn_virtualfilestats(-1, -1)

The output for SQL 2000 and 2005 is pretty much the same, but some additional columns have been added for SQL Server 2005.

Column Name	Notes	Description
DbId		Database ID.
FileId		File ID.
TimeStamp		Database timestamp at which the data was taken.
NumberReads		Number of reads issued on the file.
BytesRead		Number of bytes read issued on the file.
IoStallReadMS	SQL2005 only	Total amount of time, in milliseconds, that users waited for the read I/Os to complete on the file.
NumberWrites		Number of writes made on the file.
BytesWritten		Number of bytes written made on the file.
IoStallWriteMS	SQL2005 only	Total amount of time, in milliseconds, that users waited for the write I/Os to complete on the file.
IoStallMS		Sum of IoStallReadMS and IoStallWriteMS.
FileHandle		Value of the file handle.
BytesOnDisk	SQL2005 only	Physical file size (count of bytes) on disk. For database files, this is the same value as size in sys.database_files, but is expressed in bytes rather than pages. For database snapshot spare files, this is the space the operating system is using for the file.

(Source SQL Server 2005 Books Online)

Sample Output

As you can see from the sample output, the Dbid and FileId columns are pretty cryptic. The Dbid can be be translated to the database name pretty easily by using the DB_NAME() function, but the fileId needs to be looked up from one of the system tables.

To lookup the filename from the system tables you can use these queries.

SQL 2005

SELECT dbid, fileid, filename FROM sys.sysaltfiles WHERE dbid = 5 and fileid in (1,2)

SQL 2000

SELECT dbid, fileid, filename FROM dbo.sysaltfiles WHERE dbid = 5 and fileid in (1,2)

Here is sample output.

From just using this function directly you can gather data from two different points in time and then do a comparison to determine the change that has occurred between these two periods of time. Here is a sample query that gathers data, waits for a period of time and then gathers data again to show you a comparison.

This example is written for SQL Server 2005, but can easily be changed for SQL 2000.

USE master GO -- create table IF NOT EXISTS (SELECT * FROM sys.objects WHERE OBJECT_ID = OBJECT_ID(N'[dbo].[filestats]') AND type IN (N'U')) BEGIN CREATE TABLE filestats (dbname VARCHAR(128), fName VARCHAR(2048), timeStart datetime, timeEnd datetime, timeDiff bigint, readsNum1 bigint, readsNum2 bigint, readsBytes1 bigint, readsBytes2 bigint, readsIoStall1 bigint, readsIoStall2 bigint, writesNum1 bigint, writesNum2 bigint, writesBytes1 bigint, writesBytes2 bigint, writesIoStall1 bigint, writesIoStall2 bigint, ioStall1 bigint, ioStall2 bigint ) END -- clear data TRUNCATE TABLE dbo.filestats -- insert first segment counters INSERT INTO dbo.filestats (dbname, fName, TimeStart, readsNum1, readsBytes1, readsIoStall1, writesNum1, writesBytes1, writesIoStall1, IoStall1 ) SELECT DB_NAME(a.dbid) AS Database_name, b.filename, GETDATE(), numberReads, BytesRead, IoStallReadMS, NumberWrites, BytesWritten, IoStallWriteMS, IoStallMS FROM fn_virtualfilestats(NULL,NULL) a INNER JOIN sysaltfiles b ON a.dbid = b.dbid AND a.fileid = b.fileid ORDER BY Database_Name /*Delay second read */ WAITFOR DELAY '000:01:00' -- add second segment counters UPDATE dbo.filestats SET timeEnd = GETDATE(), readsNum2 = a.numberReads, readsBytes2 = a.BytesRead, readsIoStall2 = a.IoStallReadMS , writesNum2 = a.NumberWrites, writesBytes2 = a.BytesWritten, writesIoStall2 = a.IoStallWriteMS, IoStall2 = a.IoStallMS, timeDiff = DATEDIFF(s,timeStart,GETDATE()) FROM fn_virtualfilestats(NULL,NULL) a INNER JOIN sysaltfiles b ON a.dbid = b.dbid AND a.fileid = b.fileid WHERE fName= b.filename AND dbname=DB_NAME(a.dbid) -- select data SELECT dbname, fName, timeDiff, readsNum2 - readsNum1 AS readsNumDiff, readsBytes2 - readsBytes2 AS readsBytesDiff, readsIoStall2 - readsIOStall1 AS readsIOStallDiff, writesNum2 - writesNum1 AS writesNumDiff, writesBytes2 - writesBytes2 AS writesBytesDiff, writesIoStall2 - writesIOStall1 AS writesIOStallDiff, ioStall2 - ioStall1 AS ioStallDiff FROM dbo.filestats

Summary
One problem that you may be faced with though is that not all files are stored on their own physical disks, so you may have a case where you want to look at things from a drive perspective vs. at an individual file level. Here is a previous article written by Andy Novick that has the entire process broken down into functions, so you can aggregate things to a drive perspective. The article can be found here, Examining SQL Server's I/O Statistics

Ways to get I/O Statistics

Reading and writing to the disk is the heart of what any database management system does, SQL Server included. Input/Output (I/O) performance can make or break an application. This article discusses the diagnostic tools that can be used to examine SQL Server's I/O statistics so that you can make fact-based judgments about disk configurations.

There are several ways to request I/O statistics from SQL Server such as the System Statistical functions, sp_monitor, and fn_virtualfilestats. Each method has its advantages and disadvantages. I'll show you how they work and their pros and cons.

I rely primarily on fn_virtualfilestats because it gives the most detailed information. The other methods aggregate information at the instance level. The instance level may be the only meaningful alternative when 'you are accounting for the CPU, but when working with file I/O having the detailed breakdown is helpful.

One of the limitations of all of system statistical functions and fn_virtualfilestats is that their reports are always based on the resources consumed since the instance started. This includes both peak usage times and low usage times. If your instance has been running through several cycles of peak to low usage these overall aggregates may be of some interest, but they are usually most interesting during times of peak usage. After we discuss the various methods for statistics gathering, I will show you a stored procedure for gathering I/O statistics during peak time periods.

Ways to get I/O Statistics

Although the statistics are nearly identical, there are several ways to request them from SQL Server 2000. The methods are:

• The system statistical functions such as @@CPU_BUSY
• sp_monitor
• fn_virtualfilestats

The first two methods give you information that is aggregated at the instance level. Let's take a look at them first.

Using the System Statistical Functions

The system statistical functions cover I/O, network and CPU resource utilization. Table 1 lists them.

Table 1 System Statistical Functions

Function	Description
@@CONNECTIONS	The number of connections or attempted connections.
@@CPU_BUSY	Timer ticks that the CPU has been working for SQL Server.
@@IDLE	Time in timer ticks that SQL Server has been idle.
@@IO_BUSY	Timer ticks that SQL Server has spent performing I/O operations.
@@PACKET_ERRORS	Number of network packet errors that have occurred.
@@PACK_RECEIVED	Number of packets read from the network.
@@PACK_SENT	Number of packets written to the network.
@@TIMETICKS	Number of millionths of a second in a timer tick.
@@TOTAL_ERRORS	Number of read/write errors during I/O operations.
@@TOTAL_READ	Number of disk reads.
@@TOTAL_WRITE	Number of disk writes.

For monitoring I/O the most interesting numbers are @@IO_BUSY, @@Total_READ and @@TOTAL_WRITE. Here is a simple query that shows the raw statistics:

-- Take a look at raw I/O Statistics
SELECT @@TOTAL_READ [Total Reads]
    , @@TOTAL_WRITE as [Total Writes]
    , CAST(@@IO_BUSY as FLOAT) * @@TIMETICKS / 1000000.0 as [IO Sec]
GO

(Results)

Total Reads Total Writes IO Sec 
----------- ------------ -----------
     85336       322109      25.375

When using the functions @@IO_BUSY, @@CPU_BUSY, and @@IDLE, the function returns clock ticks. To convert ticks to seconds, multiply by @@TIMERTICKS and then divide by one million. Be sure to convert the quantities to floating point, numeric, or bigint to avoid integer overflow during intermediate calculations.

The raw numbers alone aren't very interesting. 'It is more informative to turn the numbers into rates. To do that you need to know how long the instance has been running. This next script uses a user-defined function (UDF), udf_SQL_StartDT, which uses the start time of the Lazy Writer process as a proxy for the start time of the instance. udf_SQL_StartDT is available from my free T-SQL UDF of the Week Newsletter Volume 1 #11.

The start time is turned into a number of seconds and the script performs the division, being careful to CAST to data types that 'will not lose information due to rounding or integer division:

-- Turn the raw statistics into rates
DECLARE @SecFromStart bigint
SET @SecFromStart = DATEDIFF(s, dbo.udf_SQL_StartDT(), getdate())

SELECT CAST(CAST(@@TOTAL_READ as Numeric (18,2))/@SecFromStart
              as Numeric (18,2))  as [Reads/Sec]
    , CAST(CAST(@@TOTAL_WRITE as Numeric (18,2))/@SecFromStart
              as Numeric (18,2)) as [Writes/Sec]
    , CAST(@@IO_BUSY * @TIMETICKS/10000.0/@SecFromStart
              as Numeric (18,2)) as [Percent I/O Time]
GO

(Results)

Reads/Sec            Writes/Sec           Percent I/O Time    
-------------------- -------------------- --------------------
              24.34                92.53                  .42

The read and write rates are often in the tens or hundreds, at least over short time spans. You might ask, "Why do you bother to retain even two digits to the right of the decimal?" Most of the time these extra two digits do not come into play. However, when a system has been idle for a long time, let's say over the weekend after being restarted on Friday night, it's possible to have rates that are less than one. Showing zero for the rates is confusing, so I have tried to be sure that at least a small number shows up.

Showing rates from the time the instance started until the query is run forces you to average over a long time period. SQL Server supplies a stored procedure that shows the values of the system statistical functions since it was last run, this let's you get a quick snapshot of your I/O rates.

sp_monitor is a system stored procedure that produces four recordsets that display the values of system statistical functions since sp_monitor was last run. It also shows the last_run time, the current_run time, and the number of seconds in the measurement. There are no parameters to sp_monitor. Here is a short script to see its output:

-- run sp_monitor
sp_monitor
go

(Results)

last_run                       current_run                    seconds    
------------------------------ ------------------------------ -------
2003-08-03 13:52:50.000        2003-08-03 13:52:53.000        3

cpu_busy          io_busy         idle              
----------------- --------------- ------------------
498(0)-0%         773(0)-0%       276153(2)-66%

packets_received   packets_sent       packet_errors   
------------------ ------------------ ----------------
826(1)             1741(1)            0(0)

total_read    total_write   total_errors   connections  
------------- ------------- -------------- -------------
139818(0)     392372(1)     0(0)           52(0)

sp_monitor uses the system statistical functions discussed in the previous section to get its information. It stores the value from the last time the procedure was invoked in the table spt_monitor in the master database.

Each of the measurements, such as cpu_busy and total_read, are character strings that have several parts. The first number is the measurements from when the instance started. The second number, the one in parenthesis, is the measurement since the last time sp_monitor was run. Finally, for the CPU related measurements in the second recordset, the percentage of time in the column's category follows.

I generally find the sp_monitor is the best way to get a quick picture of what is happening to your system; just: run it, wait 10 to 100 seconds and run it again. The result is a snapshot of your system activity.

Other than getting a quick look at your system, several factors weigh against trying to use sp_monitor for long-term information gathering:

• There is only one set of statistics that can be saved at a time. If someone else runs sp_monitor while you're waiting, you see the results since anyone last ran it.
• The four recordsets of output are difficult to work with in T-SQL.
• Combining the measurement from the instance startup time with the current measurement, and possibly a percentage also makes the output difficult to work with from a program.
• The numbers are aggregated to the instance level.

These factors combine to limit the usefulness of the procedure. I generally use a system build-in function, fn_virtualfilestats, to get a more detailed look at Input/Output statistics.

Using fn_virtualfilestats to Get I/O Statistics

fn_virtualfilestats returns a table of I/O statistics at the file level. It takes two parameters: the Db_ID of a database to retrieve information for and the file_id of the file to retrieve information for. Supplying -1 to either of the parameters asks for all information about the dimension. For example, executing this query:

     select * from ::fn_virtualfilestats(-1, -1)

asks for information about all files in all databases.  Executing

    select * from ::fn_virtualfilestats(-1, 2)

asks for information about file number 2, usually the first log file, for all databases.

Table 2 lists the output columns for fn_virtualfilestasts. All measurements are "since the instance started."

Table 2 Output columns from fn_virtualfilestats

Column	Data Type	Description
Dbid	Smallint	Database ID from master..sysdatabases
FileID	Smallint	File ID from sysfiles
Timestamp	Int	Number of seconds since the instance started.
NumberReads	Bigint	Number of reads.
NumberWrites	Bigint	Writes.
BytesRead	Bigint	Bytes read.
BytesWritten	Bigint	Bytes written.
IoStallMS	Bigint	Milliseconds users waited for I/O complete on the file.

Here is a short query that shows the I/O statistics for the current database with sample output:

-- Get information about the current files
DECLARE @myDBID int
SET @myDBID = db_id()
SELECT * FROM ::fn_virtualfilestats (@myDBID, -1)
go

(Results)

DbId FileId TimeStamp NumberReads NumberWrites BytesRead  BytesWritten IoStallMS
---- ------ --------- ----------- ------------ ---------- ------------ ---------
 16      1 288070359      134585       195377 6172327936   8675352576    833376
 16      2 288070359         390       191536    2158592  11449939968      6384 

The raw numbers are useful, but they are even more interesting when aggregated in different ways. Some of the ways that you might want to aggregate are:

• For the system as a whole
• By database
• By drive
• By log files vs. data files

The following UDF, udf_Perf_FS_ByDriveTAB, aggregates the files by drive letter. It uses information in master..sysaltfiles to get the path to the physical file. Here is the CREATE FUNCTION script:

SET QUOTED_IDENTIFIER OFF
SET ANSI_NULLS OFF
GO

CREATE   FUNCTION dbo.udf_Perf_FS_ByDriveTAB (

   @DriveLetter CHAR(1) = NULL -- Drive or NULL for all
)   RETURNS  TABLE
/*
* Returns a table of statistics by Drive letters for all drives
* with database files in this instance. They must match
* @Driveletter (or NULL for all).  Returns one row for each
* Drive. Information about physical files is taken from
* master..sysaltfiles which has the physical file name needed.
* Warning: Drive letters do not always correspond to physical
* disk drives.
*         
* Example:
select * from dbo.udf_Perf_FS_ByDriveTAB (default)
****************************************************************/
AS RETURN

SELECT TOP 100 PERCENT WITH TIES
      LEFT(saf.[Filename], 1) + ':' as DriveLetter
    , Count(saf.FileID) as NumFiles
    , CAST (Sum(saf.[size] / 128.0) as numeric(18,3)) as SizeMB
             -- convert to Megabytes from 8-k pages
    , Sum(NumberReads) as NumberReads
    , Sum(NumberWrites) as NumberWrites
    , Sum(BytesRead) as BytesRead
    , Sum(BytesWritten) as BytesWritten
    , Sum(IoStallMS) as IoStallMS
    , Avg(vfs.[TimeStamp]/1000) as SecondsInMeasurement
   FROM ::fn_virtualfilestats(-1, -1) vfs -- -1 = all db & files
        inner join master..sysaltfiles saf
            on vfs.DbId = saf.DbId
              and vfs.FileID = saf.FileID
   WHERE (@DriveLetter is NULL
       OR LEFT(saf.[Filename], 1) = @DriveLetter)
   GROUP BY LEFT(saf.[Filename], 1) + ':'
   ORDER BY DriveLetter asc -- by Drive letter C, D, ....
GO

The parameter to udf_Perf_FS_ByDriveTAB is a drive letter, which you can use if you are only interested in information about a single drive. Otherwise, use NULL to retrieve information for all drives that have SQL Server data or log files.

Here is the result of executing it on a test server:

-- Get input output by drive
SELECT DriveLetter as Drive, NumFiles as Files, SizeMB
    , NumberReads as Reads, NumberWrites as Writes
    , BytesRead, BytesWritten, IOStallMS
    , SecondsInMeasurement as Sec
   FROM dbo.udf_Perf_FS_ByDriveTAB (default)
GO

(Results)

Drive Files SizeMB     Reads    Writes  BytesRead  BytesWritten IoStallMS Sec
----- ----- ---------- -------- ------- ---------- ------------ --------- -------
D:       47   5032.625   140293  392340 6258849792  20267508224  11024112  290955

E:       21   6004.125   340876  882233 9558932367  43481143983  13666091  290955  

The most important factor needed to analyze these numbers is knowledge of the disk configuration that is associated with each drive letter. Is it a single drive? Is there a RAID configuration? If so, which one? Are there multiple partitions on any of the drives? A SAN? The answers to all of these questions make a big difference in how you evaluate the results. Different configurations, such as RAID 0 vs. RAID 5, have different capacities and you will have to know your configuration to make meaningful comparisons.

There are other ways to aggregate the output of fn_virtuafilestasts. You will find one such alternative in a user-defined function udf_Perf_FS_byDBTab

A problem with the numbers produced by fn_virtualfilestats is that they include information from the start of the instance. The numbers during peak usage are more interesting and the next section develops a solution to gathering them that is similar to the solution used by sp_monitor.

Optimize Parameter Driven Queries with the OPTIMIZE FOR Hint

SQL Server doesn't always select the best execution plan for your queries and thankfully there are several different hints that can be used to force SQL Server into using one execution plan over another. One issue that you may be faced with is when using parameters in your WHERE clause, sometimes the query runs great and other times it runs really slow. I recently had a situation where the hard coded values in the WHERE clause worked great, but when I changed the values to parameters and used the exact same values for the parameters the execution plan drastically changed and the overall time it took to run the query increased by about 5 times. This situation is referred to as parameter sniffing where SQL Server stores the values used as part of the execution plan and therefore other queries with different values may act totally different. So what options are there to get around this.

Solution
As mentioned above, SQL Server offers many hints that can be used to force how an execution plan is put together. The option that we are interested in is the OPTIMIZE FOR option. This will allow us to specify what parameter value we want SQL Server to use when creating the execution plan. This is a SQL Server 2005 hint.

Let's take a look at a few examples. These were all done against the AdventureWorks database.

Example 1

This first example is a straight query using a parameter without the OPTIMIZE FOR hint.

DECLARE @Country VARCHAR(20) SET @Country = 'US' SELECT * FROM Sales.SalesOrderHeader h, Sales.Customer c, Sales.SalesTerritory t WHERE h.CustomerID = c.CustomerID AND c.TerritoryID = t.TerritoryID AND CountryRegionCode = @Country

The following is the actual execution plan that is generated to execute this query.

The overall cost for this query is 1.31871.

Example 2

In this example we are specifying the OPTIMIZE FOR hint which is shown in the last line of this query. The first part is identical to the query in Example 1. In this example we are telling SQL Server to optimize this execution plan for this query using "CA" as the parameter value.

DECLARE @Country VARCHAR(20) SET @Country = 'US' SELECT * FROM Sales.SalesOrderHeader h, Sales.Customer c, Sales.SalesTerritory t WHERE h.CustomerID = c.CustomerID AND c.TerritoryID = t.TerritoryID AND CountryRegionCode = @Country OPTION (OPTIMIZE FOR (@Country = 'CA'))

The following is the actual execution plan that is generated to execute this query. For the most part this query plan looks the same as the query plan above, except that the percentages in some tasks are a bit different.

The overall cost for this query is 1.1805 which is better then example 1.

Example 3

In this example we have changed the OPTIMIZE FOR value to be "US" instead of "CA", everything else is the same.

DECLARE @Country VARCHAR(20) SET @Country = 'US' SELECT * FROM Sales.SalesOrderHeader h, Sales.Customer c, Sales.SalesTerritory t WHERE h.CustomerID = c.CustomerID AND c.TerritoryID = t.TerritoryID AND CountryRegionCode = @Country OPTION (OPTIMIZE FOR (@Country = 'US'))

The following is the actual execution plan that is generated to execute this query. As you can see SQL Server has changed this quite a bit from examples 1 and 2.

The overall cost for this query is 1.160652 which is not as good as the first two examples.

Client Stats

In addition to the above, we also captured the client statistics with each execution. The trial # corresponds with the example #. In the below grid we can see the Total Execution time increased with each run. For example1 the total time was 328, for example2 was 406 and for example3 it was 468. This shows that for this query SQL Server seems to be picking the best query plan.

Note: the procedure cache was not cleared between each run.

Summary

As you can see from this simple test when using parameters, using the OPTIMIZE FOR hint can change the query plan. This may have a positive impact or a negative impact, but this gives you another option to adjust how your queries execute especially if things start performing poorly when using parameters in your queries.

As I mentioned above, the dataset I was working on had tables with 20+ million rows. Here are the query plan costs that I had for each option:

• hard coded values - 4.44821
• parameters with same values - 2722.9
• using OPTIMIZE hint - 4.44649

Without the OPTIMIZE hint some executions were fast and others took a long time. So depending on your dataset and the task at hand this option may or may not help.

Storing I/O Stats at Meaningful Intervals

Analyzing I/O statistics gathered during peak usage is much more informative than trying to work with numbers that included both peak and off-peak times of day. The solution presented in this section stores the raw information provided by fn_virtualfilestats in a way that provides information in a user selected time slice. To accomplish this task, I have created a table, dbaFilestats, and a stored procedure usp_Perf_FilestatGathering that I run every day as a scheduled job.

DbaFilestats is a table that I keep in my DBA database for gathering the statistics. Here is the CREATE TABLE script:

CREATE TABLE dbo.dbaFilestats (
 ID int IDENTITY (1, 1) NOT NULL ,
 dbid int NOT NULL ,
 fileid int NOT NULL ,
 Reads bigint NULL ,
 Reads_FromStart bigint NULL ,
 Writes bigint NULL ,
 Writes_FromStart bigint NULL ,
 BytesRead bigint NULL ,
 BytesRead_FromStart bigint NULL ,
 BytesWritten bigint NULL ,
 BytesWritten_FromStart bigint NULL ,
 IostallMS bigint NULL ,
 IostallMS_FromStart bigint NULL ,
 RecordedDT datetime NULL ,
 timestamp bigint NULL ,
 IntervalMSec bigint NULL ,
 FirstMeasure_FromStart bit NULL 
)

I've chosen to keep both the interval measures, such as Reads and BytesWritten, and the measures from the instance startup (%_FromStart). It is possible to do away with the _FromStart numbers by keeping them in a temporary table as the stored procedure runs, but I have found that every so often, I want to see them.

The stored procedure to perform the information gathering is dba_Perf_FilestatGathering. It takes four parameters, which are listed in Table 3.

Table 3 Parameters to dba_Perf_FilestatGathering

Parameter	Data Type	Description
@Duration	Datetime	The amount of time to collect data.
@IntervalSec	Int	The interval in seconds between data gathering.
@WhichDB	Int	DB_ID of the database to gather for. -1 for all databases.
@WhichFile	Int	File_ID to gather information for. -1 for all files.

To create the procedure on your system, you will need a UDF, udf_DT_AddTime, which you will find at this URL: http://www.novicksoftware.com/UDFofWeek/Vol1/T-SQL-UDF-Volume-1-Number-38-udf_DT_Addtime.htm. Here is the CREATE PROC script:

CREATE PROC dbo.dba_Perf_FilestatGathering

   @Duration    datetime = '01:00:00' -- Duration of data collection
                                      -- long time gathers forever
 , @IntervalSec int = 600 -- Approx sec in the gathering interval
 , @WhichDB     int = -1 -- DB_ID to monitor, -1 for all
 , @WhichFile   int = -1 -- File_ID of file to monitor, -1 for all
/*
* Procedure to monitor fn_virtualfilestats and record their value at
* intervals in the dbaFilestats table. 
*
* Example:
-- TRUNCATE TABLE DBAFILESTATS
DECLARE @RC int, @StartTime datetime, @thisDBID int
SELECT @StartTime = getdate(), @thisDBID = db_id()
EXEC @RC = dba_Perf_FilestatGathering '00:10:21', 60, @ThisDBID , 1
select * from dbafilestats where RecordedDT > @StartTime
     and dbid=@thisDBID  and fileid = 1 Order by ID
********************************************************************/
AS

DECLARE @TerminateGatheringDT  datetime -- when to stop gathering
     , @WaitFor_Interval datetime
     , @LastRecordingDT datetime
     , @RecordingDT datetime
     , @myDBID int
     , @myError int            -- Local copy of @@ERROR
     , @myRowCount int         -- Local copy of @@RowCount
     , @msgText nvarchar(4000) -- for error messages


SELECT @WaitFor_Interval = DATEADD (s, @IntervalSec
                              , CONVERT (datetime, '00:00:00', 108)
                                )
    , @TerminateGatheringDT =
                dbo.udf_DT_AddTime (getdate(), @Duration)
    , @myDBID = db_id()

WHILE getdate() <= @TerminateGatheringDT BEGIN

   SELECT @LastRecordingDT = @RecordingDT
   SELECT @RecordingDT = getdate() --
  
   -- Get Stats for All files
   INSERT INTO dbo.dbaFilestats (
               dbid
             , fileid
             , Reads
             , Reads_FromStart
             , Writes
             , Writes_FromStart
             , BytesRead
             , BytesRead_FromStart
             , BytesWritten
             , Byteswritten_FromStart
             , IOStallMS
             , iostallMs_FromStart
             , RecordedDT
             , [timestamp]
             , IntervalMSec
             , FirstMeasure_FromSTart
               )
       SELECT vfs.dbid -- Database ID
            , vfs.fileid  -- File ID
            , vfs.numberreads - dbaf.reads_fromstart as Reads
            , vfs.numberreads as Reads_FromStart
            , vfs.numberwrites - dbaf.writes_fromstart
                                                    as Writes
            , vfs.numberwrites as Writes_FromStart
            , vfs.bytesread - dbaf.bytesRead_FromStart
                                                    as BytesRead
            , vfs.bytesread as BytesRead_FromStart
            , vfs.bytesWritten - dbaf.BytesWritten_FromStart
                                                    as BytesWritten
            , vfs.byteswritten as BytesWritten_FromStart
            , vfs.IOStallMS - dbaf.IOStallMS_FromStart
                                                    as IOStallMS
            , vfs.iostallms  as IOStallMS_FromStart
            , @RecordingDT
            , vfs.[timestamp]
            , CASE WHEN @LastRecordingDT IS NULL
                  THEN NULL
                  ELSE DATEDIFF(ms, dbaf.RecordedDT, @RecordingDT)
                   END as IntervalMSec
            , CASE WHEN @LastRecordingDT IS NULL THEN 1 ELSE 0 END
                                         as FirstMeasure_FromStart
          FROM ::fn_virtualfilestats(@WhichDB , @WhichFile) vfs
              LEFT OUTER JOIN dbaFilestats dbaf
                 ON vfs.dbid = dbaf.dbid and vfs.fileid = dbaf.fileid
          WHERE (@LastRecordingDT IS NULL
                      OR dbaf.RecordedDT = @LastRecordingDT)
   SELECT @myError = @@Error, @myRowCount = @@RowCount
   IF @myError != 0 BEGIN
      SET @msgText = 'Error ' + CONVERT(varchar(9), @myError)
                   + ' in usp_FileStatGathering during INSERT'
      RAISERROR (@msgText, 16, 1) WITH LOG
      RETURN @myError
   END

   WAITFOR DELAY @WaitFor_Interval   -- delay     

END 

I usually run for 10 minutes and 21 seconds ('00:10:21'), gathering information every 60 seconds for all databases (-1) and all files (-1). The reason for adding the 21 seconds to the 10 minutes is that I want 10 measurements and the 21 seconds allows for the time that it takes to make and store the measurements.

Let's take a look at some of the raw data from a run against my database 16, which had a fairly heavy load at the time:

SELECT Top 5 [ID], dbid, [fileid] as [File]
      , Reads, Writes, BytesRead, BytesWritten, IOStallMS
      , IntervalMSec as [MSec]
   FROM dbaFilestats
   WHERE FirstMeasure_FromStart = 0
   ORDER BY [ID]
Go

(Results)

ID   dbid File   Reads Writes BytesRead BytesWritten IOStallMS MSec
---- ---- ----- ------ ------ --------- ------------ --------- ------     
  2   16     1   1243    564  35774464     25452544     74530  72846     
  3   16     1   1911    847  75489280     48136192     62485  64186     
  4   16     1    244   1356  37617664     53551104      3890  62263     
  5   16     1   1393   1315  64258048     38379520     40297  63500     
  6   16     1    152   1485  13426688     66273280      4733  62703     

As you can see from the MSec column, it took longer than 60 seconds to get through each of the measurements. The actual time will depend on the load on the system and the number of databases.

Looking at the raw numbers from dbaFilestats is helpful. However, I find the most useful use of the information is to turn most of the measurements into rates. This query does the job:

SELECT Top 5 
      CAST(Reads/(IntervalMSec/1000.0) as Numeric (18,2))
                                                 as [Reads/Sec]
    , CAST(Writes/(IntervalMsec/1000.0) as Numeric (18,2))
                                                 as [Writes/Sec]
    , (Reads+Writes) as [I/O Count]
    , CAST((Reads+Writes)/(IntervalMsec/1000.0) as Numeric(18,2))
                                                 as [I/O /sec]
    , Iostallms/CASE WHEN (reads+writes)>0
                     THEN reads+writes
                     ELSE 1 END AS [IoStallMS/Op]
   FROM dbaFilestats
   WHERE FirstMeasure_FromStart = 0
      AND  dbid = 16  and fileid=1
   ORDER BY [id]
GO

(Results)

Reads/Sec   Writes/Sec   I/O Count  IO /sec    IoStallMS/Op
----------- ------------ ---------  ---------- ------------
     17.06         7.74      1807       24.81           41
     29.77        13.20      2758       42.97           22
      3.92        21.78      1600       25.70            2
     21.94        20.71      2708       42.65           14
      2.42        23.68      1637       26.11            2

These rates indicate that there may be a problem with the disk(s) that database 16 is using. I know that because of the high IoStallMS/Op measurement (IoStall Milliseconds per I/O operation). Anything over twenty indicates that there is some type of problem. That is in spite of the fact that the I/O rates are moderate, in the range of 25-43 per second. A modern server disk should be able to achieve 85 to 100 operations per second. The situation warrants further investigation.

Conclusion

Input/Output is at the heart of what SQL Server does. This article has shown several methods for getting I/O statistics from SQL Server as an aid in diagnosing performance issues. I find that the most useful technique is to gather statistics during peak usage at one-minute intervals. The key indicators are the I/O operations per second and the IoStallMS/Op. You might want to investigate other ratios for your server.