Collecting Historical IO File Statistics

In a previous post, Collecting Historical Wait Statistics, I discussed how you can easily collect historical wait stats by using the DMV sys.dm_os_wait_stats. Well today, I'd like to cover the same concept, but this time collect historical IO file stats from the DMV, sys.dm_io_virtual_files_stats. However, I wanted to improve on the code to make it even easier to implement.

The data collection process is still implemented the same way.  First, we'll need to create a history table to store the data. The data is stored in time slices with the cumulative values as well as the difference (TimeDiff_ms, NumOfReadsDiff, NumOfWritesDiff, etc) in those values since the last collection time.

CREATE TABLE dbo.IoVirtualFileStatsHistory(
  SqlServerStartTime DATETIME NOT NULL
 ,CollectionTime DATETIME NOT NULL
 ,TimeDiff_ms BIGINT NOT NULL
 ,DatabaseName NVARCHAR(128) NOT NULL
 ,DatabaseId SMALLINT NOT NULL
 ,FileId SMALLINT NOT NULL
 ,SampleMs INT NOT NULL
 ,SampleMsDiff INT NOT NULL
 ,NumOfReads BIGINT NOT NULL
 ,NumOfReadsDiff BIGINT NOT NULL
 ,NumOfBytesRead BIGINT NOT NULL
 ,NumOfBytesReadDiff BIGINT NOT NULL
 ,IoStallReadMs BIGINT NOT NULL
 ,IoStallReadMsDiff BIGINT NOT NULL
 ,NumOfWrites BIGINT NOT NULL
 ,NumOfWritesDiff BIGINT NOT NULL
 ,NumOfBytesWritten BIGINT NOT NULL
 ,NumOfBytesWrittenDiff BIGINT NOT NULL
 ,IoStallWriteMs BIGINT NOT NULL
 ,IoStallWriteMsDiff BIGINT NOT NULL
 ,IoStall BIGINT NOT NULL
 ,IoStallDiff BIGINT NOT NULL
 ,SizeOnDiskBytes BIGINT NOT NULL
 ,SizeOnDiskBytesDiff BIGINT NOT NULL
 ,FileHandle VARBINARY(8) NOT NULL
 ,CONSTRAINT PK_IoVirtualFileStatsHistory PRIMARY KEY CLUSTERED
  (CollectionTime,DatabaseName,DatabaseId,FileId)
 )WITH (DATA_COMPRESSION = PAGE);
GO

The next step will be to get the start time of SQL Server, so that we can compare it to the previous collection. If the dates are different, then we must take that into account when calculating the diff values. Because if SQL Server is restarted, then all values in the DMV are reset back to zero. At this point, we know the diff values are actually the same value as the current counters, because this is the first collection after a restart.

IF @CurrentSqlServerStartTime <> ISNULL(@PreviousSqlServerStartTime,0)
BEGIN
 -- If SQL started since the last collection, then insert starter values
 -- Must do DATEDIFF using seconds instead of milliseconds to avoid arithmetic overflow.
 INSERT INTO dbo.IoVirtualFileStatsHistory
 SELECT
   @CurrentSqlServerStartTime
  ,CURRENT_TIMESTAMP
  ,CONVERT(BIGINT,DATEDIFF(SS,@CurrentSqlServerStartTime,CURRENT_TIMESTAMP))*1000
  ,@DatabaseName
  ,@DatabaseId
  ,file_id
  ,sample_ms
  ,sample_ms
  ,num_of_reads
  ,num_of_reads
  ,num_of_bytes_read
  ,num_of_bytes_read
  ,io_stall_read_ms
  ,io_stall_read_ms
  ,num_of_writes
  ,num_of_writes
  ,num_of_bytes_written
  ,num_of_bytes_written
  ,io_stall_write_ms
  ,io_stall_write_ms
  ,io_stall
  ,io_stall
  ,size_on_disk_bytes
  ,size_on_disk_bytes
  ,file_handle
 FROM sys.dm_io_virtual_file_stats(@DatabaseId,NULL);
END
GO

You may notice the DATEDIFF is using "seconds" instead of "milliseconds".  This is because DATEDIFF only returns an INT value. The largest number it can return is equal to about 24 days before it hits an arithmetic overflow error. By converting it to seconds, we can avoid that error. All of the following data collections will do a DATEDIFF using milliseconds.

If the current start time is the same as the previous collection, then we'll grab the difference in values and insert those into the history table.

WITH CurrentIoVirtualFileStats AS
(
 SELECT
   CURRENT_TIMESTAMP AS 'CollectionTime'
  ,@DatabaseName AS 'DatabaseName'
  ,*
 FROM sys.dm_io_virtual_file_stats(@DatabaseId,NULL)
)
INSERT INTO dbo.IoVirtualFileStatsHistory
SELECT
  @CurrentSqlServerStartTime
 ,CURRENT_TIMESTAMP
 ,CONVERT(BIGINT,DATEDIFF(MS,@PreviousCollectionTime,curr.CollectionTime))
 ,@DatabaseName
 ,@DatabaseId
 ,file_id
 ,sample_ms
 ,curr.sample_ms - hist.SampleMs
 ,num_of_reads
 ,curr.num_of_reads - hist.NumOfReads
 ,num_of_bytes_read
 ,curr.num_of_bytes_read - hist.NumOfBytesRead
 ,io_stall_read_ms
 ,curr.io_stall_read_ms - hist.IoStallReadMs
 ,num_of_writes
 ,curr.num_of_writes - hist.NumOfWrites
 ,num_of_bytes_written
 ,curr.num_of_bytes_written - hist.NumOfBytesWritten
 ,io_stall_write_ms
 ,curr.io_stall_write_ms - hist.IoStallWriteMs
 ,io_stall
 ,curr.io_stall - hist.IoStall
 ,size_on_disk_bytes
 ,curr.size_on_disk_bytes - hist.SizeOnDiskBytes
 ,file_handle
FROM CurrentIoVirtualFileStats curr INNER JOIN dbo.IoVirtualFileStatsHistory hist
 ON (curr.DatabaseName = hist.DatabaseName
  AND curr.database_id = hist.DatabaseId
  AND curr.file_id = hist.FileId)
  AND hist.CollectionTime = @PreviousCollectionTime;
GO

At this point, we're through collecting the raw data. However, as I mentioned earlier, I added a lot of functionality into this script. The script is actually a stored procedure that can run all of this code for you; including creation of the history table, data collection, historical data purging and finally reporting.

The stored procedure has 5 input parameters.

@Database - This is used to specify a single database, a list of databases, or a wildcard.

• '*' is the default value which selects all databases
• 'MyDatabase1'  will process only that single database
• 'MyDatabase1,MyDatabase2,MyDatabase3' Comma delimited list of databases
• 'USER_DATABASES' used to process all user databases
• 'SYSTEM_DATABASES' used to process only the system databases.

@GenerateReport - Flag. When off, the stored procedure will collect data. When on, it will generate an aggregated report of the historical data.

@HistoryRetention - The is the number of days to keep in the history table. Default is 365.

@ExcludedDBs - Is a comma delimited list of databases to exclude from processing. It should be used when @Database is set to '*'.

@Debug - Flag. When on, it will output TSQL commands that being executed.

Examples:

1. Collect data for all databases.

EXEC dbo.sp_CollectIoVirtualFileStats
 @Database = '*';
GO

2. Collect data for all databases except for AdventureWorks, and output all debug commands.

EXEC dbo.sp_CollectIoVirtualFileStats
  @Database = '*'
 ,@ExcludedDBs = 'AdventureWorks'
 ,@Debug = 1;
GO

3. Output an aggregated report of data collected so far for tempdb.

EXEC dbo.sp_CollectIoVirtualFileStats
  @Database = 'tempdb'
 ,@GenerateReport = 1;
GO

The report would look like this.

Finally, you can copy this report data into Excel and generate some easy to read charts.

From the chart, we can see there was a spike in write latency between 3PM and 4PM for tempdb. If we collect this data over time and identify a similar spike each day then we'd want to investigate further to find out what is causing it. But that can only be done if you're collecting these metrics and storing them for historical analysis. Hopefully, this stored procedure will help you be more proactive in collecting performance metrics for each of your servers.

The entire script is available on the resources page.

Collecting Historical Wait Statistics

As a DBA, I'm sure you've heard many times to always check the sys.dm_os_wait_stats DMV to help diagnose performance issues on your server. The DMV returns information about specific resources SQL Server had to wait for while processing queries. The counters in the DMV are cumulative since the last time SQL Server was started and the counters can only be reset by a service restart or by using a DBCC command. Since DMVs don't persist their data beyond a service restart, we need to come up with a way to collect this data and be able to run trending reports over time.

Collecting the data seems easy enough by simply selecting all rows into a permanent table. However, that raw data won't help us determine the time in which a particular wait type occurred. Think about it for a minute. If the raw data for the counters is cumulative, then how can you tell if a bunch of waits occurred within a span of a few minutes or if they occurred slowly over the past 6 months that SQL Server has been running. This is where we need to collect the data in increments.

First, we need to create a history table to store the data. The table will store the wait stat values as well as the difference (TimeDiff_ms, WaitingTasksCountDiff, WaitTimeDiff_ms, SignalWaitTimeDiff_ms) in those values between collection times.

CREATE TABLE dbo.WaitStatsHistory
(
     SqlServerStartTime DATETIME NOT NULL
    ,CollectionTime DATETIME NOT NULL
    ,TimeDiff_ms INT NOT NULL
    ,WaitType NVARCHAR(60) NOT NULL
    ,WaitingTasksCountCumulative BIGINT NOT NULL
    ,WaitingTasksCountDiff INT NOT NULL
    ,WaitTimeCumulative_ms BIGINT NOT NULL
    ,WaitTimeDiff_ms INT NOT NULL
    ,MaxWaitTime_ms BIGINT NOT NULL
    ,SignalWaitTimeCumulative_ms BIGINT NOT NULL
    ,SignalWaitTimeDiff_ms INT NOT NULL
    ,CONSTRAINT PK_WaitStatsHistory PRIMARY KEY CLUSTERED (CollectionTime, WaitType)
)WITH (DATA_COMPRESSION = PAGE);
GO

Next, we need to get a couple of timestamps when we collect each sample. The first will be the SQL Server start time. We need the SQL Server start time, so we can identify when the service was restarted.

SELECT @CurrentSqlServerStartTime = sqlserver_start_time FROM sys.dm_os_sys_info;
GO

The second set is the previous start time and previous collection time, if they exist in the history table.

SELECT
     @PreviousSqlServerStartTime = MAX(SqlServerStartTime)
    ,@PreviousCollectionTime = MAX(CollectionTime)
FROM msdb.MSDBA.WaitStatsHistory;
GO

The last timestamp is the collection time. We’ll also use this timestamp to calculate the difference in wait stat values between each collection.

SELECT GETDATE() AS 'CollectionTime',* FROM sys.dm_os_wait_stats;
GO

We need to compare the current SQL Server start time to the previous start time from the history table. If they don’t equal, then we assume the server was restarted and insert “starter” values. I call them starter values, because we just collect the current wait stat values and insert 0 for each of the diff columns.

IF @CurrentSqlServerStartTime <> ISNULL(@PreviousSqlServerStartTime,0)
BEGIN
    -- Insert starter values if SQL Server has been recently restarted
    INSERT INTO dbo.WaitStatsHistory
    SELECT
         @CurrentSqlServerStartTime
        ,GETDATE()
        ,DATEDIFF(MS,@CurrentSqlServerStartTime,GETDATE())
        ,wait_type
        ,waiting_tasks_count
        ,0
        ,wait_time_ms
        ,0
        ,max_wait_time_ms
        ,signal_wait_time_ms
        ,0
    FROM sys.dm_os_wait_stats;
END
GO

If the timestamps are the same, we will collect the current wait stats and calculate the difference (in milliseconds) in collection time as well as the difference in values.

INSERT msdb.MSDBA.WaitStatsHistory
SELECT
     @CurrentSqlServerStartTime
    ,cws.CollectionTime
    ,DATEDIFF(MS,@PreviousCollectionTime,cws.CollectionTime)
    ,cws.wait_type
    ,cws.waiting_tasks_count
    ,cws.waiting_tasks_count - hist.WaitingTasksCountCumulative
    ,cws.wait_time_ms
    ,cws.wait_time_ms - hist.WaitTimeCumulative_ms
    ,cws.max_wait_time_ms
    ,cws.signal_wait_time_ms
    ,cws.signal_wait_time_ms - hist.SignalWaitTimeCumulative_ms
FROM CurrentWaitStats cws INNER JOIN MSDBA.WaitStatsHistory hist
    ON cws.wait_type = hist.WaitType
    AND hist.CollectionTime = @PreviousCollectionTime;
GO

You could filter the collection to only specific wait stat counters that you want to track by just a where clause, but I prefer to collect them all and then filter at the reporting end.

At this point, we’re ready to schedule the job. The script could be run at any interval, but I usually leave it to collect data once a day. If I notice a spike in a specific wait stat counter, then I could easily increase the job frequency to once every few hours or even once an hour. Having those smaller, more granular data samples will allow us to isolate which time frame we need to concentrate on.

For example, if we notice the CXPACKET wait suddenly spikes when collecting the data each day, then we could schedule the collection every hour to see if it’s happening during a specific window.

SELECT * FROM msdb.MSDBA.WaitStatsHistory
WHERE WaitType = 'CXPACKET';
GO

Finally, we can use Excel to format this raw data into an easy to read chart.

From this chart, we can see at 5PM there was a spike in CXPACKET waits, but a low number of tasks that waited. In this case, I would be assume there is a single process running in parallel that caused these waits and from there I could dig further into finding the individual query.

Data compression is enabled on this table to help keep it small. It can easily turn it off for the table by removing WITH (DATA_COMPRESSION = PAGE) from the CREATE TABLE statement. However, with page compression enabled, 24 collections (one per hour) only takes up 775KB of space. Without compression, the same sample of data consumes about 2.2MB. If you plan to keep a lot of history, then it's best to leave page compression enabled.

Hopefully, this script will help you keep track of your historical wait statistics, so you can have better knowledge of what has happened to your environment over time. The entire script is posted below. If you want to read further into what each wait statistics means, then check out Paul Randal’s article about wait stats. Additionally, if you want more info on using DMVs, check out Glenn Berry’s diagnostic queries.

/***********************************************
    Create the historical table
***********************************************/

USE msdb;
GO

-- Create the history table if it does not exist
IF OBJECT_ID('dbo.WaitStatsHistory') IS NULL
BEGIN
    CREATE TABLE dbo.WaitStatsHistory
    (
         SqlServerStartTime DATETIME NOT NULL
        ,CollectionTime DATETIME NOT NULL
        ,TimeDiff_ms INT NOT NULL
        ,WaitType NVARCHAR(60) NOT NULL
        ,WaitingTasksCountCumulative BIGINT NOT NULL
        ,WaitingTasksCountDiff INT NOT NULL
        ,WaitTimeCumulative_ms BIGINT NOT NULL
        ,WaitTimeDiff_ms INT NOT NULL
        ,MaxWaitTime_ms BIGINT NOT NULL
        ,SignalWaitTimeCumulative_ms BIGINT NOT NULL
        ,SignalWaitTimeDiff_ms INT NOT NULL
        ,CONSTRAINT PK_WaitStatsHistory PRIMARY KEY CLUSTERED (CollectionTime, WaitType)
    )WITH (DATA_COMPRESSION = PAGE);
END
GO

/***********************************************
    Schedule this section as an on-going job
***********************************************/

DECLARE
     @CurrentSqlServerStartTime DATETIME
    ,@PreviousSqlServerStartTime DATETIME
    ,@PreviousCollectionTime DATETIME;

SELECT @CurrentSqlServerStartTime = sqlserver_start_time FROM sys.dm_os_sys_info;

-- Get the last collection time
SELECT
     @PreviousSqlServerStartTime = MAX(SqlServerStartTime)
    ,@PreviousCollectionTime = MAX(CollectionTime)
FROM msdb.dbo.WaitStatsHistory;

IF @CurrentSqlServerStartTime <> ISNULL(@PreviousSqlServerStartTime,0)
BEGIN
    -- Insert starter values if SQL Server has been recently restarted
    INSERT INTO dbo.WaitStatsHistory
    SELECT
         @CurrentSqlServerStartTime
        ,GETDATE()
        ,DATEDIFF(MS,@CurrentSqlServerStartTime,GETDATE())
        ,wait_type
        ,waiting_tasks_count
        ,0
        ,wait_time_ms
        ,0
        ,max_wait_time_ms
        ,signal_wait_time_ms
        ,0
    FROM sys.dm_os_wait_stats;
END
ELSE
BEGIN
    -- Get the current wait stats
    WITH CurrentWaitStats AS
    (
        SELECT GETDATE() AS 'CollectionTime',* FROM sys.dm_os_wait_stats
    )
    -- Insert the diff values into the history table
    INSERT msdb.dbo.WaitStatsHistory
    SELECT
         @CurrentSqlServerStartTime
        ,cws.CollectionTime
        ,DATEDIFF(MS,@PreviousCollectionTime,cws.CollectionTime)
        ,cws.wait_type
        ,cws.waiting_tasks_count
        ,cws.waiting_tasks_count - hist.WaitingTasksCountCumulative
        ,cws.wait_time_ms
        ,cws.wait_time_ms - hist.WaitTimeCumulative_ms
        ,cws.max_wait_time_ms
        ,cws.signal_wait_time_ms
        ,cws.signal_wait_time_ms - hist.SignalWaitTimeCumulative_ms
    FROM CurrentWaitStats cws INNER JOIN dbo.WaitStatsHistory hist
        ON cws.wait_type = hist.WaitType
        AND hist.CollectionTime = @PreviousCollectionTime;
END
GO

An Alternative to SELECT COUNT(*) for Better Performance

Sometimes rapid code development doesn't always produce the most efficient code.  Take the age old line of code SELECT COUNT(*) FROM MyTable.  Obviously this will give you the row count for a table, but at what cost? Doing any SELECT * from a table will ultimately result in a table or clustered index scan.

USE AdventureWorksDW2012;

SELECT COUNT(*) FROM dbo.FactProductInventory;

GO

Turning on STATISTICS IO on reveals 5753 logical reads just to return the row count of 776286.

Table 'FactProductInventory'. Scan count 1, logical reads 5753, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

Starting with SQL Server 2005, Microsoft introduced a DMV, sys.dm_db_partition_stats, that provides you with the same information at a fraction of the cost.  It requires a little more coding, but once you turn on STATISTICS IO, you will see the performance benefit.

USE AdventureWorksDW2012;

SELECT

        s.name AS 'SchemaName'

       ,o.name AS 'TableName'

       ,SUM(p.row_count) AS 'RowCount'

FROM sys.dm_db_partition_stats p

       JOIN sys.objects o ON o.object_id = p.object_id

       JOIN sys.schemas s ON o.schema_id = s.schema_id

WHERE p.index_id < 2 AND o.type = 'U'

       AND s.name = 'dbo'

       AND o.name = 'FactProductInventory'

GROUP BY s.name,o.name

ORDER BY s.name,o.name;

GO

Since we're querying a DMV, we never touch the base table.  We can see here we only need 16 logical reads to return the same row count of 776286, and the FactProductInventory table is nowhere in our execution plan.

Table 'sysidxstats'. Scan count 1, logical reads 10, physical reads 0, read-ahead reads 8, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

Table 'sysschobjs'. Scan count 0, logical reads 4, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

Table 'sysclsobjs'. Scan count 0, logical reads 2, physical reads 1, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

By using the DMV, we have improved the query performance and reduced the total I/O count by nearly 100%. Another added benefit of using the DMV, is we won't need locks on the base table and therefore will avoid the possibility of blocking other queries hitting that table.

This is just one simple example of how you can easily improve the performance of an application.

Dealing with a Fragmented Heap

Just for the record, this happens to be one of my favorite interview questions to ask candidates.

At some point in time, there will be a database containing tables without clustered indexes (a heap) that you will be responsible for maintaining.  I personally believe that every table should have a clustered index, but sometimes my advice is not always followed.  Additionally there can be databases from a 3rd party vendor that have this same design.  Depending on the what those heap tables are used for, over time it's possible they can become highly fragmented and degrade query performance.  A fragmented heap is just as bad as a fragmented index.  To resolve this issue, I'd like to cover four ways we can defragment a heap. 

To start with, we will need a sample database with a highly fragmented heap table.  You can download the FRAG database (SQL2012) from here.  Let's use the sys.dm_db_index_physical_stats DMV to check the fragmentation level.

USE FRAG;

GO

SELECT

     index_id

    ,index_type_desc

    ,index_depth

    ,index_level

    ,avg_fragmentation_in_percent

    ,fragment_count

    ,page_count

    ,record_count

FROM sys.dm_db_index_physical_stats(

     DB_ID('FRAG')

    ,OBJECT_ID('MyTable')

    ,NULL

    ,NULL

    ,'DETAILED');

GO

As you can see, the heap is 93% fragmented, and both non-clustered indexes are 99% fragmented.  So now we know what we're dealing with. 

Repair options in order of my preference:

1. ALTER TABLE...REBUILD (SQL 2008+).
2. CREATE CLUSTERED INDEX, then DROP INDEX.
3. CREATE TABLE temp, INSERT INTO temp, DROP original table, sp_rename temp to original, recreate the non-clustered indexes.
4. BCP out all data, drop the table, recreate the table, bcp data in, recreate the non-clustered indexes.

Option 1 is the easiest and the most optimal way to remove heap fragmentation; however, this option was only introduced in SQL Server 2008, so it's not available for all versions.  This is a single command that will rebuild the table and any associated indexes; yes, even clustered indexes.  Keep in mind, this command will rebuild the heap as well as all of the non-clustered indexes.

ALTER TABLE dbo.MyTable REBUILD;

GO

Option 2 is almost as quick, but involves a little bit of planning.  You will need to select a column to create the clustered index on, keeping in mind this will reorder the entire table by that key.  Once the clustered index has been created, immediately drop it.

CREATE CLUSTERED INDEX cluIdx1 ON dbo.MyTable(col1);

GO

DROP INDEX cluIdx1 ON dbo.MYTable;

GO

Option 3 requires manually moving all data to a new temporary table.  This option is an offline operation and should be done during off-hours.  First you will need to create a new temporary table with the same structure as the heap, and then copy all rows to the new temporary table.

CREATE TABLE dbo.MyTable_Temp(col1 INT,col2 INT);

GO

INSERT dbo.MyTable_Temp

SELECT * FROM dbo.MyTable;

GO

Next, drop the old table, rename the temporary table to the original name, and then create the original non-clustered indexes.

DROP TABLE dbo.MyTable;

GO

EXEC sp_rename 'MyTable_Temp','MyTable';

GO

CREATE NONCLUSTERED INDEX idx1 ON dbo.MyTable(col1);

GO

CREATE NONCLUSTERED INDEX idx2 ON dbo.MyTable(col2);

GO

Option 4 is by far to the least efficient way to complete this task.  Just like option 3, this option is an offline operation and should be done during off-hours.  First we need to use the BCP utility to bulk copy out all of the data to a data file.  Using BCP will require a format file to define the structure of what we're bulk copying.  In this example, I am using an XML format file.  More information on format files can be found here.

BCP FRAG.dbo.MyTable OUT D:\MyTable.dat -T -STRON\TEST1 -fD:\MyTableFormat.xml

Once that is complete, we need to drop and recreate the table.

DROP TABLE dbo.MyTable;

GO

CREATE TABLE dbo.MyTable(col1 INT,col2 INT);

GO

Next, we need to use the BCP utility to bulk copy all of the data back into the table.

BCP FRAG.dbo.MyTable IN D:\MyTable.dat -T -STRON\TEST1 -fD:\MyTableFormat.xml

Finally, we can create the original non-clustered indexes.

CREATE NONCLUSTERED INDEX idx1 ON dbo.MyTable(col1);

GO

CREATE NONCLUSTERED INDEX idx2 ON dbo.MyTable(col2);

GO

Options 1 and 2 do not require any downtime for the table; however, they will cause blocking during the rebuild stage.  You can use the WITH ONLINE option but that will require enough free space in tempdb for the entire table.  Both options 3 and 4 will require downtime and will potentially impact any foreign key constraints or other dependent objects.  If you're running SQL Server 2008 or higher, I highly recommend using option 1.

As you've seen, there are multiple ways of dealing with heap fragmentation.  However, the best way is to avoid heaps altogether in your database design.

The Performance Impact to Prefix Stored Procedures with sp_

Last week I ran across a blog post by Axel Achten (B|T) that outlined a few reasons why you should not use SELECT * in queries.   In the post, Axel used the SQLQueryStress tool by Adam Machanic (B|T) to stress-test a simple query using SELECT * and SELECT col1, col2,...  This gave me an idea to use the same SQLQueryStress tool to benchmark a stored procedure that's prefixed with sp_.

All DBAs know, or should know, you should not prefix stored procedures with sp_.  Even Microsoft mentions the sp_ prefix is reserved for system stored procedures in Books Online.

I'm not going to discuss the do's and don'ts of naming conventions.  What I want to know is there still a performance impact of using the sp_ prefix. 

For our test, we'll use the AdventureWorks2012 database.  First we need to create two new stored procedures that selects from the Person.Person table.

USE AdventureWorks2012;

GO

CREATE PROCEDURE dbo.sp_SelectPerson AS SELECT * FROM Person.Person;

GO

CREATE PROCEDURE dbo.SelectPerson AS SELECT * FROM Person.Person;

GO

Next, we'll clear the procedure cache, and then execute each procedure once to compile it and to ensure all the data pages are in the buffer.

DBCC FREEPROCCACHE;

GO

EXEC dbo.sp_SelectPerson;

GO

EXEC dbo.SelectPerson;

GO

Next, we'll run execute each stored proc 100 times using SQLQueryStress and compare the results.

Total time to execute sp_SelectPerson was 3 minutes 43 seconds, and only 3 minutes 35 seconds to execute SelectPerson.  Given this test run was only over 100 iterations, 8 seconds is huge amount of savings.

We can even query sys.dm_exec_procedure_stats to get the average worker time in seconds and average elapsed time in seconds for each procedure.

SELECT

     o.name AS 'object_name'

    ,p.execution_count

    ,p.total_worker_time AS 'total_worker_time(μs)'

    ,(p.total_worker_time/p.execution_count)*0.000001 AS 'avg_worker_time(s)'

    ,p.total_elapsed_time AS 'total_elapsed_time(μs)'

    ,(p.total_elapsed_time/p.execution_count)*0.000001 AS 'avg_elapsed_time(s)'

FROM sys.dm_exec_procedure_stats p

JOIN sys.objects o ON p.object_id = o.object_id;

GO

As you can see, the average time per execution is very minimal, but it does add up over time.  This could easy scale into a much larger difference if all stored procedures begin with sp_.

sp_PerformanceCounters - Get a Health Check of SQL Server's Performance

During your career as a DBA, you'll run across articles by SQL experts or other DBAs that just give you an idea.  A few years ago I found an article, or a poster to be more precise, that explains SQL Server performance counters.  It was written by Kevin Kline, Brent Ozar, Christian Bolton, Bob Ward, Rod Colledge, and Raoul Illyaos.

http://www.quest.com/backstage/images/promotions/SQLServer-Perfmonance-Poster.pdf

I was thinking this would be a nice poster for any DBA to hang up in their cubical.  But as I read down near the bottom, I saw they also mentioned getting performance counters from within SQL Server via sys.dm_os_performance_counters.  Ah ha!  My light bulb just turned on!

In an earlier post, I had discussed how to get performance counters from within SQL Server, so for this post I want to share a stored procedure that pulls the counters as described in the poster as well a few more.

The procedure is sp_PerformanceCounters, and it will aggregate overall performance data that is available in the sys.dm_os_performance_counters DMV.  The metrics are gathered for various counters and objects and displayed in 7 columns.

1. PerformanceObject - The counter category.
2. CounterName - Name of the counter.
3. InstanceName - The specific instance of the counter; often the database name.
4. TimeFrame - The timeframe of the counter.
5. ActualValue - The value of the counter.
6. IdealValue - A generalized optimal value for the counter.
7. Description - A brief description of the counter.

The most important thing to understand from the output is to understand the timeframe of the metrics, and how that impacts the actual value.  There are three possible TimeFrames: Current, Total since SQL startup, and Avg since SQL startup.

For the TimeFrames that are "Current", those are counter type 65792 and are the absolute values that do not need any special definition.  For example, you can select the number of database pages in the buffer pool, and the value returned is the current value.

SELECT * FROM sys.dm_os_performance_counters

WHERE object_name = 'MSSQL$TEST1:Buffer Manager'

AND counter_name = 'Database Pages';

The second TimeFrame "Total since SQL startup" is also easy to interpret.  This counter is also of type 65792, and it's just the accumulated total of a counter since SQL was started up.  For example, you can select the number of log growths from the databases counter which would tell you the total number of log growths for all databases since SQL Server was last started.

SELECT * FROM sys.dm_os_performance_counters

WHERE object_name = 'MSSQL$TEST1:Databases'

AND counter_name = 'Log Growths'

ORDER BY instance_name;

The last and most common TimeFrame is "Avg since SQL startup", which is for counters of type 272696576.  The value of these counters get incremented every time that event is fired and are mostly related to "per second" counters.  To figure out the per second value we have to divide by the total uptime (in seconds) of SQL Server.  This will give us the output displayed in the ActualValue column.  This is also one reason why the SQL Server startup time is the first row displayed in the output.  The SQL Server startup time is taken from the sys.dm_os_sys_info DMV.

SELECT * FROM sys.dm_os_performance_counters

WHERE object_name = 'MSSQL$TEST1:SQL Statistics'

AND counter_name = 'Batch Requests/sec';

Most counter names will match exactly what you see in sys.dm_os_performance_counters; however, there will be a few that are calculated as a ratio. One example is the Page Lookup / Batch Request.  This counter will show you the average number page lookups that occurred per batch request.  Both of these individual counters are of type 272696576 which means they are "per second counters".  However, for this ratio counter we don't care about the per second value, we just want total of Page Lookups divided by the total of Batch Requests.

DECLARE @TempValue1 DECIMAL(25,5), @TempValue2 DECIMAL(25,5)

SELECT @TempValue1 = cntr_value

FROM sys.dm_os_performance_counters

WHERE object_name = 'MSSQL$TEST1:Buffer Manager'

AND counter_name = 'Page lookups/sec';

SELECT @TempValue2 = cntr_value

FROM sys.dm_os_performance_counters

WHERE object_name = 'MSSQL$TEST1:SQL Statistics'

AND counter_name = 'Batch Requests/sec';

-- This is to avoid divide by zero.

IF @TempValue2 <> 0

    SELECT @TempValue1/@TempValue2 AS 'Page lookups/Batch Requests';

ELSE

    SELECT 0;

All aggregated data is stored in a temporary table #PerformanceCounters and then displayed at the end, and is best viewed using the "Results to Grid" output in SSMS.

EXEC master.dbo.sp_PerformanceCounters;

GO

Most of the ideal values and descriptions were taken from the poster mentioned above.  My disclaimer with that is the real ideal value will always depend on your specific application and setup.  This stored procedure was created to be used an overall health check for a server.  It's especially useful if another DBA just handed you a new SQL Server to support, and you need a quick way to see a brief history of its performance.

The stored procedure was written for SQL Server 2005 and 2008.  It will work on SQL Server 2012, but there were a lot of changes with the counters so I will have an updated officially supported version for 2012 soon.

Click here to download the full script.

SQL Server has encountered % occurence(s) of cachestore flush for the % cachestore (part of plan cache) due to some database maintenance or reconfigure operations

Have you seen this type of an informational message in your SQL errorlog before?  If so, then I hope the timestamp associated with it was not during the middle of your peak processing time.  This is a good indication that someone has been tinkering with some of the SQL configuration settings.

SQL Server offers a lot of wonderful configuration options; many of which can be changed dynamically using sp_configure without the need of restarting the SQL Server service.  The downside to the dynamic changes is sometimes they can have a detrimental effect on performance, and that's what this "informational" message is tell you.  Let's look at an example.

First, let's get our starting numbers for the cachestores.

SELECT

      COUNT(*) AS 'Total Cached Plans'

FROM sys.dm_exec_cached_plans;

GO

SELECT

       name AS 'Cache Name'

      ,single_pages_kb

      ,multi_pages_kb

      ,entries_count

FROM sys.dm_os_memory_cache_counters

WHERE name IN ('Object Plans','SQL Plans','Bound Trees');

GO

As you can see, we have 160 total plans in cache using up the amount of single and multi-page allocations for each entry.

Now let's say your system administrator came to you today and said he hot-added extra ram to the SQL box because of how much you had been complaining about memory shortages.  You are so excited about this, you login to the server and execute the following query to bump SQL's maximum memory up to 4GB.

EXEC sys.sp_configure N'max server memory (MB)', N'4000';

GO

RECONFIGURE;

GO

Now you look in the SQL errorlog to valid the changes.

You are excited to see this message.

Configuration option 'max server memory (MB)' changed from 2000 to 4000. Run the RECONFIGURE statement to install.

And not so excited about these.

SQL Server has encountered 1 occurrence(s) of cachestore flush for the 'Object Plans' cachestore (part of plan cache) due to some database maintenance or reconfigure operations.
SQL Server has encountered 1 occurrence(s) of cachestore flush for the 'SQL Plans' cachestore (part of plan cache) due to some database maintenance or reconfigure operations.
SQL Server has encountered 1 occurrence(s) of cachestore flush for the 'Bound Trees' cachestore (part of plan cache) due to some database maintenance or reconfigure operations.

Let's run our cachestore query again and look at the results.

Ah proof that we just cleared the entire procedure cache.  Having these cachestores cleared out means you just lost all compiled plans for stored procedures, functions, triggers, views, adhoc plans, prepared plans, etc.  The next time any query runs, its plan will have to be compiled costing extra CPU cycles and potentially degraded performance.

As it turns out, for certain configuration settings when you execute the RECONFIGURE command it essentially does what amounts to DBCC FREEPROCCACHE.

The whole procedure cache is cleared if one of the following server options is changed by the RECONFIGURE statement:

• cross db ownership chaining
• index create memory (KB)
• remote query timeout (s)
• user options
• max text repl size (B)
• cost threshold for parallelism
• max degree of parallelism
• min memory per query (KB)
• query wait (s)
• min server memory (MB)
• max server memory (MB)
• query governor cost limit

This is a very good example of why you should NOT make configuration changes during peak processing times.  You wouldn't run DBCC FREEPROCCACHE during the middle of your peak processing, so why would you play around with configuration settings during that same time?

For further reading:  http://support.microsoft.com/kb/917828