Use dm_io_virtual_file_stats to Monitor tempdb

I’ve been watching some Webcasts by Ramesh Meyyappan at SQL Workshops on query performance tuning.  This guy is a wizard… inspiring.

Many of his techniques, which he just does like second nature, may require someone to slow things down to really articulate what he does.  Sort of like watching an instant replay during a sports event.  How do those umpires get it so right (most of the time)?  There’s just a huge difference between real-time and the slow-mo, frame-by-frame review.

So here’s my instant replay of one of Ramesh’s techniques…  monitoring tempdb to determine if a query is spilling during a sort or JOIN operation.  In particular we will do so using one of the SQL Server Dynamic Management (DM) functions, sys.dm_io_virtual_file_stats.

If you prefer to use PROFILER to monitor tempdb for sort spills you can do so simply by turning on the  Errors and Warnings Events Selection subcategory.

Sort Warning to monitor tempdb spills

I also highlighted the Hash Warning event which identifies when SQL Server goes into a hash recursion (bad) or hash bailout (very, very bad) during a hash operations such as a hash join or aggregation.

OK, back to the topic…

According to BoL, our DM function accepts 2 input arguments, the ID of the database and the File ID of the file for the database that we are interested in.

If we’re not exactly sure how to determine those input arguments we can wing it by supplying NULL values for the input.

<span class="kwrd">SELECT</span>    *
<span class="kwrd">FROM</span>    sys.dm_io_virtual_file_stats (<span class="kwrd">NULL</span>, <span class="kwrd">NULL</span>);

The output of this query will give us the file stats for every database file on the SQL instance.  Even on my lowly laptop the output is rather daunting if you don’t have any clue about which database is being presented:

sys.dm_io_virtual_file_stats output

When working with DM functions and views there are a few Metadata Functions that will serve to make our life easier.  In our case db_name and file_name.

Let’s modify our query to help us figure out which database and file we need to look at:

<span class="kwrd">SELECT</span>  DB_NAME(dm.database_id) <span class="kwrd">AS</span> [DB_Name],
        FILE_NAME(dm.file_id) <span class="kwrd">AS</span> [File_Name],
        dm.*
<span class="kwrd">FROM</span>    sys.dm_io_virtual_file_stats (<span class="kwrd">NULL</span>, <span class="kwrd">NULL</span>) dm;

All we did here is add two new columns to figure out which database and file we are interested in.  Here’s a snippet of the output:

tempdb database and file IDs

OK, now we know tempdb is database #2.  We also know the data file is 1 (tempdev) and the tempdb log file is 2.  Hopefully that is clear from the screen capture above.

(Note: With SQL Server there are always multiple ways to do the same thing.  Another way we could have figured out the database and file IDs is with the system stored procedure sp_helpfile. We’ll leave that as an exercise for the reader or perhaps do a small posting on that one later on.)

OK, now we can limit the scope of our query to just return what we want to quantify how much tempdb is being used.

<span class="kwrd">SELECT</span>  DB_NAME(dm.database_id) <span class="kwrd">AS</span> [DB_Name],
        FILE_NAME(dm.file_id) <span class="kwrd">AS</span> [File_Name],
        num_of_reads,
        num_of_bytes_read,
        num_of_writes,
        num_of_bytes_written
<span class="kwrd">FROM</span>    sys.dm_io_virtual_file_stats (<span class="kwrd">NULL</span>, <span class="kwrd">NULL</span>) dm
<span class="kwrd">WHERE</span>    dm.database_id = 2
<span class="kwrd">AND</span>        dm.file_id = 1;
Note:  This query will work fine but a simpler version follows, that introduces the use of the DB_ID function for the first argument to our DM.

<span class="kwrd">SELECT</span>  DB_NAME(dm.database_id) <span class="kwrd">AS</span> [DB_Name],
        FILE_NAME(dm.file_id) <span class="kwrd">AS</span> [File_Name],
        num_of_reads,
        num_of_bytes_read,
        num_of_writes,
        num_of_bytes_written
<span class="kwrd">FROM</span>    sys.dm_io_virtual_file_stats (DB_ID(<span class="str">'tempdb'</span>), 1) dm;

So how do we actually use this to validate that tempdb is being used?  Simply run the query to capture the file stats data, run a query writes to tempdb, then re-run the DM query.

<span class="kwrd">drop</span> <span class="kwrd">table</span> #demoiostats
<span class="kwrd">drop</span> <span class="kwrd">table</span> #tempdcontact

<span class="kwrd">DBCC</span> dropcleanbuffers;
<span class="rem">-- Query 1: Capture a snapshot of the file stats on tempdb</span>
<span class="rem">-- before any data is written to it.</span>
<span class="kwrd">SELECT</span>    <span class="kwrd">CURRENT_TIMESTAMP</span> <span class="kwrd">as</span> capture_time,
        DB_NAME(dm.database_id) <span class="kwrd">AS</span> [DB_Name],
        FILE_NAME(dm.file_id) <span class="kwrd">AS</span> [File_Name],
        num_of_reads,
        num_of_bytes_read,
        num_of_writes,
        num_of_bytes_written
<span class="kwrd">INTO</span>    #demoiostats
<span class="kwrd">FROM</span>    sys.dm_io_virtual_file_stats (DB_ID(<span class="str">'tempdb'</span>), 1) dm;

<span class="rem">-- Query 2: Force a write to tempdb.  In practice we would be more interested</span>
<span class="rem">-- in queries that are writing to tempdb as a result of a SORT</span>
<span class="rem">-- or HASH operation.</span>
<span class="kwrd">SELECT</span>    FirstName,
        LastName,
        EmailAddress
<span class="kwrd">into</span>    #tempdcontact
<span class="kwrd">FROM</span>    AdventureWorks.Person.Contact;

<span class="kwrd">SELECT</span>    * <span class="kwrd">from</span> #tempdcontact;

<span class="rem">-- Query 4: Capture the snapshot AFTER the write to tempdb.</span>
INSERT <span class="kwrd">INTO</span> #demoiostats
    <span class="kwrd">SELECT</span>    <span class="kwrd">CURRENT_TIMESTAMP</span> <span class="kwrd">as</span> capture_time,
            DB_NAME(dm.database_id) <span class="kwrd">AS</span> [DB_Name],
            FILE_NAME(dm.file_id) <span class="kwrd">AS</span> [File_Name],
            num_of_reads,
            num_of_bytes_read,
            num_of_writes,
            num_of_bytes_written
    <span class="kwrd">FROM</span>    sys.dm_io_virtual_file_stats (DB_ID(<span class="str">'tempdb'</span>), 1) dm;

<span class="rem">-- Query 5: Compute the total number of reads and writes.</span>
<span class="kwrd">SELECT</span>    t2.num_of_reads - t1.num_of_reads <span class="kwrd">AS</span> [Total_Num_of_Reads],
        t2.num_of_bytes_read - t1.num_of_bytes_read <span class="kwrd">AS</span> [Total_Num_of_Bytes_Read],
        t2.num_of_writes - t1.num_of_writes <span class="kwrd">AS</span> [Total_Num_of_Writes],
        t2.num_of_bytes_written - t1.num_of_bytes_written <span class="kwrd">AS</span> [Total_Num_of_Bytes_Written]
<span class="kwrd">FROM</span>        #demoiostats t1
        <span class="kwrd">CROSS</span> <span class="kwrd">JOIN</span> #demoiostats t2
<span class="kwrd">WHERE</span>    t1.capture_time &lt; t2.capture_time;

To recap the above code:

  1. Query 1 captures the file stats counters on tempdb to a temp file #demoiostats.
  2. Query 2 writes to a temp table #tempdcontact.  In practice we would be more interested in a spill to tempdb from either a hash or sort physical operator.
  3. Query 3 does a simple read from the temp table we just created.
  4. Query 4 captures the file stats AFTER the write and read to and from  tempdb.
  5. Query 5: Finally we take the differences between the two sets of counters we just captured.

Here’s the output of our little test:

image

What’s interesting is that we have 4 reads and and 171 writes.  You might be wondering “Reads and writes of what?”

I ran these tests several times and the results are consistent.  We’re doing about 64k per read and 12k per write.

The counts of reads and writes are PHYSICAL reads, or the number of trips to the physical disk.  The definition of LOGICAL reads, which is not what this routine returns, is the number of trips data is sent to/from the data cache.  This is why I added the DBCC dropcleanbuffers before running the routine.  Without clearing the data cache, no increase of read counters would occur because the data would conveniently be sitting in cache.

I found a nice blog post on physical and logical reads by Kasim Wirama.  Check it out for additional details.

Conclusion: The dm_io_virtual_file_stats DMV can be very useful to monitor PHYSICAL read and write operations to the tempdb (or any other db).  It’s also a useful tool to point out the difference between LOGICAL and PHYSICAL reads.  Clearly this tool can be easily used to build optimized queries to avoid spilling to tempdb.

Thanks to Ramesh for providing the lead example to get me thinking about this tool… and the many other posters out there who demonstrate how to really make this tool dance.

Anytime I attempt to post a blog I run the risk of learning something unexpected.  In this case it was the distinction between logical and physical reads.  We all know it’s there… but probably don’t think about it much.

Forever curious…

Dave

Leave a Reply

You must be logged in to post a comment.

Using Gravatars in the comments - get your own and be recognized!

XHTML: These are some of the tags you can use: <a href=""> <b> <blockquote> <code> <em> <i> <strike> <strong>