Vigilate Reservate – Live Query Statistics in SQL Server 2014

One of many new features with SQL Server 2014 that’s not to be overlooked is ability to see live query stats real time as query is being executed using new DMVs. The fact is that in SQL Server 2014 we have a new Dynamic Management View to track what a query is actually doing at a physical operator level.  I am referring to the sys.dm_exec_query_profiles Dynamic Management View (DMV).

This feature will help the database administrators and experienced developers to troubleshoot long running queries in real-time. I’m pretty sure you had to deal with the following questions: When will this query finish? What percentage of total workload is performed by this request? Which steps are the longest? Before SQL Server 2014 it was impossible to answer the questions above.

Important note – in order to use this feature with this DMV we must use some session options like STATISTICS PROFILE, STATISTICS XML or SET STATISTICS XML ON to  force SQL Server to display the execution plan after execution query with SQL Server Management Studio. So in other words Sit doesn’t work for plans stored in the Plan Cache.

SQL Server BOL has a good detail on new sys.dm_exec_query_profiles DMV here – https://msdn.microsoft.com/en-us/library/dn223301(v=sql.120).aspx. What BOL states there is – “Monitors real time query progress while the query is in execution. The counters are per operator per thread. The data collected is serialized into the SHOWPLAN XML when the query finishes.”  What Microsoft really wanted to say by it was that SHOWPLAN XML or any other sort of actual execution plan is a prerequisite. If actual execution plan isn’t required for your query, SQL Server won’t gather all this data at the first hand. And won’t show it in sys.dm_exec_query_profiles during runtime.

So that means I can use SSMS to run a particulary long running query and get stats on it. However you probably will not be running this all of the time, the overhead is pretty big here.  This DMV provides a lot of useful information.  These information are more granular than SET STATISTICS IO because the counters returned are per operator per thread (node_id / physical_operator_name and thread_id columns). Moreover two others columns are interesting like estimate_row_count and row_count. The former is the number of estimated rows an operator should address and the latter is the current number of rows addressed by the same operator (remember these counters are per operator per thread …). We can compare these two columns to estimate a completion percentage per operator (or per operator per thread). Finally we can categorize some information provided by this DMV in two parts: information related either to the query execution engine (row_count, estimated_row_count) or the storage execution engine (logical_read_count, write_page_count, lob_logical_read_count etc.)

so imagine I am running a following query against AdvetureWorks2012 sample DB:

 

USE AdventureWorks2012 GO SET STATISTICS XML ON SELECT * FROM Sales.SalesOrderHeader OH INNER JOIN Sales.SalesOrderDetail OD ON OD.SalesOrderID = OH.SalesOrderID INNER JOIN Sales.Customer C ON C.CustomerID = OH.CustomerID INNER JOIN Production.Product P ON P.ProductID = OD.ProductID INNER JOIN Production.ProductSubcategory PS ON pS.ProductSubcategoryID = P.ProductSubcategoryID GO

 

Query result will be when finished:

image

While that is running in another SSMS query window I execute:

SELECT  session_id ,
        node_id ,
        physical_operator_name ,
        SUM(row_count) row_count ,
        SUM(estimate_row_count) AS estimate_row_count ,
        IIF(COUNT(thread_id) = 0, 1, COUNT(thread_id)) [Threads] ,
        CAST(SUM(row_count) * 100. / SUM(estimate_row_count) AS DECIMAL(30, 2)) [% Complete] ,
        CONVERT(TIME, DATEADD(ms, MAX(elapsed_time_ms), 0)) [Operator time] ,
        DB_NAME(database_id) + '.' + OBJECT_SCHEMA_NAME(QP.object_id,
                                                        qp.database_id) + '.'
        + OBJECT_NAME(QP.object_id, qp.database_id) [Object Name]
FROM    sys.dm_exec_query_profiles QP
GROUP BY session_id ,
        node_id ,
        physical_operator_name ,
        qp.database_id ,
        QP.OBJECT_ID ,
        QP.index_id
ORDER BY session_id ,
        node_id
GO


I get following as a result:

image

 

Just as with execution plan information can be useful looking at operator time and differences in estimated row counts to actual. Looking on the web appears that folks went further and correlated sys.dm_exec_query_profiles, sys.objects, sys.indexes, sys.dm_exec_requets, sys.dm_exec_sessions, and sys.dm_os_waiting_tasks to cover both the real-time execution information and the related waits occurring in the same time. One such interesting script by David Barbarin is here – http://blog.dbi-services.com/sql-server-2014-sysdmexecqueryprofiles-a-new-promising-feature/ 

 

This feature and new DMV generated lots of buzz so more details are available here – http://sqlserver-help.com/2014/06/10/sql-2014-learning-series-11-new-dmv-sys-dm_exec_query_profiles-part-1/, http://sqlserver-help.com/tag/sys-dm_exec_query_profiles/, and http://blog.sqltechie.com/2013/11/sysdmexecqueryprofiles-sql-2014-new-way.html, http://sqlblog.com/blogs/michael_zilberstein/archive/2013/10/21/51415.aspx

Advertisements

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s