Archive

Posts Tagged ‘DMF – sys.dm_exec_query_plan’

“SQL Server is running slow!?!” Help!

April 15, 2013 Leave a comment

How many times have we heard that SQL Server is running slow from end-user, but can’t track down why? Or what happened?  In this post I hope to point out some of the things you can consider.  I’ll approach this scenario two ways, 1) SQL Server is running slow due to processor is pinned 2) SQL Server is running slow but processor is not pinned.

SQL Server is running slow due to processor is pinned

What are some of the things that require CPU in SQL Server?  When dealing with processor related issue, we need to know what might cause CPU utilization and what kind of utilization we have (privileged or user)? Before we start troubleshooting any kind of issue on the server, please ask the first obvious question?  Is it really sqlservr.exe (SQL Engine) causing the issue?  In CPUs case it is pretty easy, we can look at task manager. However if we wanted to look at the Windows Performance Monitor (perfmon), then we might want to look at least three counters; Processor\% Processor Time (_Total), Process\% User Time (sqlservr), and Process\% Privileged Time (sqlservr).

An interesting difference between Processor and Process counter is, Processor counter is an average of all processors visible to the operating system.  Where as Process counter is a summation of all processor visible to the operating system.

CPU Usage

Image 1: Processor Utilization

If we look at the utilization the Process\% User Time is much higher then Processor\% Processor Time, therefore to really see the utilization for SQL when looking at Process counters, we need to average the value to get true utilization.  When looking at Processor\% Processor Time, I would like the values to ideally run around maximum of 70-80%, if these values are going above that for extended period of time, then we need to figure out what is causing CPU utilization.  Maybe it is time to migrate some workloads off this server, maybe its time to purchase new hardware, or maybe we have runaway queries and need to do some performance tuning.  All of this normally depends on having proper baseline of these values.  However lets say we do have an issue so now what?

First thing to note, everything in SQL Server uses CPU.  Like life, nothing comes free.  Memory Reads (Logical Reads), Disk Read/Writes (Physical Reads/Writes), Hash Operations, Execution Plans, etc. all require CPU.  Question is what is using up the CPU?

Maybe its physical operations?

If its physical operations I should see my Process\% Privileged Time higher then normal.  Generally for SQL server we recommend this value should not exceed 25-30%.  In addition to this we should see high disk usage or some kind of memory pressure.  That is causing SQL Server to write dirty pages out or high amount of scans causing light number of physical reads.  So we potentially need to look at the Logical Disk or Physical Disk counters, SQL Server: Access Methods, and SQL Server: Buffer Manager counters.  In SQL Server we might see PAGEIOLATCH_* wait types in sys.dm_os_waiting_tasks DMV.

Maybe its logical operations?

If its logical operations, I should not see high number in Processor\% Privileged Time but should see high number in Process\% User Time.  In SQL Server maybe I want to run a query to get the most expensive queries by Logical Reads from sys.dm_exec_query_stats to see who is causing excessive logical reads.  You can look at Get Top 50 SQL Statements/Query Plans post on how to get this information.

Maybe its hash operations?

Again this should be user time utilization on CPU and if I have lots of Hash Operations, that means I have potential for high TempDB usage.  So I might look for counters SQLServer:Access Methods\Workfiles Created/sec in relation to SQLServer:SQL Statistics\Batch Requests/sec.  These values we like to see this ratio to be around 1:5 ratio.  In SQL Server we might want to look for queries with high amount of worker time.  In addition we might have SOS_SCHEDULER_YEILD wait_type in sys.dm_os_waiting_tasks if the box is being very busy.

Maybe its execution plans?

If its execution plans, then we might have high number of SQLServer:SQL Statistics\SQL Compilations/sec or SQLServer:SQL Statistics\SQL Re-Compilations/sec.  If its re-compilations n the sys.dm_exec_query_stats we might find execution plans with high plan_generation_num.  Alternatively we might have high compilations/sec because lots of Ad-Hoc T-SQL (any code that is not object with in SQL Server, such as stored procedures, triggers, etc.) code is being executed (greater then your baselines).

SQL Server is running slow but processor is not pinned

Well we looked at some of the scenarios where the CPU might be pinned, how about where CPU is not pinned?  What might be issue then?  In these cases, if your CPU is not pinned but things are running slow, the problem might be resource contention issue.  Therefore you might have blocking in SQL Server.  If you look at activity monitor you might see wait types such as LCK_M_*, or ASYNC_NETWORK_IO, etc.

We can look at DMV sys.dm_exec_waiting_tasks, sys.dm_exec_requests, and sys.dm_tran_locks to se where is the contention issue.  From there we can further dig into the SQL statement using sys.dm_exec_sql_text and then further the execution plan using sys.dm_exec_query_plan.

In addition you might need to track blocking in SQL Server, please look at Blocked Process Report in SQL Profiler post.

Conclusion

I am sure everyone has run into their fair share of issues, unfortunately the answer is rarely simple, especially when it comes to performance issues.  However I hope this post gave you some idea for your further troubleshooting.  Another thing to consider is, what if the issue has happened few hours ago or last day and you are just finding about it?  It is really outside scope of this post, but something’s that might help in this case is Management Data Warehouse, looking at the previous execution in the DMVs, or using other external monitoring tools such as Microsoft System Center Options Manager.

Finding All Plans/SQL Statements that executed in Parallel

October 21, 2011 Leave a comment
       WITH XMLNAMESPACES (DEFAULT 'http://schemas.microsoft.com/sqlserver/2004/07/showplan')
     SELECT   query_plan                                            AS CompleteQueryPlan
            , n.value('(@StatementText)[1]', 'VARCHAR(4000)')       AS StatementText
            , n.value('(@StatementOptmLevel)[1]', 'VARCHAR(25)')    AS StatementOptimizationLevel
            , n.value('(@StatementSubTreeCost)[1]', 'VARCHAR(128)') AS StatementSubTreeCost
            , n.query('.')                                          AS ParallelSubTreeXML
       FROM sys.dm_exec_cached_plans AS ecp
CROSS APPLY sys.dm_exec_query_plan(plan_handle) AS eqp
CROSS APPLY query_plan.nodes('/ShowPlanXML/BatchSequence/Batch/Statements/StmtSimple')     AS qn(n)
      WHERE n.query('.').exist('//RelOp[@PhysicalOp="Parallelism"]') = 1

References: #21

Statement copied from The Rambling DBA: Jonathan Kehayias Blog

Get Top 50 SQL Statements/Query Plans

October 21, 2011 1 comment

Finding out what statements causing grief on SQL Server has become significantly easier with SQL Server 2005+.  I am using some of the DMV/DMF to pull this information together.  Please note on a 64-bit system with lots of memory this can take a bit of time to run because of Sort & pulling execution plan information.  If that is an issue, I recommend getting the full information without sort by and dumping it to a temp table.  From there do your analysis, here are few options for running this statement:

Following query returns everything it is very expensive and takes a while to complete, even if you dump it to tempdb it can take 10+ mintutes on systems with lots of memory.

-- Get Top 50 Statements that have been recorded in SQL Server since last restart.
--

DECLARE @Top50By INT

-- 1 = Duration, 2 = CPU, 3 = Reads
SET @Top50By = 1

     SELECT   TOP 50
              SUBSTRING(st.text,
                        (qs.statement_start_offset/2)+1,
                        ((CASE qs.statement_end_offset WHEN -1 THEN
                             DATALENGTH(st.text)
                          ELSE
                             qs.statement_end_offset
                          END - qs.statement_start_offset)/2) + 1)  AS SQLStatement
            , qp.query_plan                                         AS QueryPlan
            , execution_count                                       AS NumOfExecutions
            , (total_elapsed_time/execution_count)/1000             AS AVGDuration_ms
            , (total_worker_time/execution_count)/1000              AS AVGCPU_ms
            , (total_logical_reads/execution_count)                 AS AVGReads
            , (total_logical_writes/execution_count)                AS AVGWrites
       FROM sys.dm_exec_query_stats qs
CROSS APPLY sys.dm_exec_sql_text (qs.sql_handle) st
CROSS APPLY sys.dm_exec_query_plan (qs.plan_handle) qp
   ORDER BY CASE
            WHEN @Top50By = 1 THEN
               (total_elapsed_time/execution_count)/1000
            WHEN @Top50By = 2 THEN
               (total_worker_time/execution_count)/1000
            WHEN @Top50By = 3 THEN
               (total_logical_reads/execution_count)
            END DESC

Same code, but I have taken out the execution plan, so it should execute faster. The idea is once you know which queries you want to address those are the only plans you will bring up; making it faster. However this method if you save the data, there is no grantee the plan will be there in the future.

-- Get Top 50 Statements that have been recorded in SQL Server since last restart.
--

DECLARE @Top50By INT

-- 1 = Duration, 2 = CPU, 3 = Reads
SET @Top50By = 1

     SELECT   TOP 50
              SUBSTRING(st.text,
                        (qs.statement_start_offset/2)+1,
                        ((CASE qs.statement_end_offset WHEN -1 THEN
                             DATALENGTH(st.text)
                          ELSE
                             qs.statement_end_offset
                          END - qs.statement_start_offset)/2) + 1)  AS SQLStatement
            , qs.plan_handle										AS PlanHandle
            , execution_count                                       AS NumOfExecutions
            , (total_elapsed_time/execution_count)/1000             AS AVGDuration_ms
            , (total_worker_time/execution_count)/1000              AS AVGCPU_ms
            , (total_logical_reads/execution_count)                 AS AVGReads
            , (total_logical_writes/execution_count)                AS AVGWrites
       FROM sys.dm_exec_query_stats qs
CROSS APPLY sys.dm_exec_sql_text (qs.sql_handle) st
   ORDER BY CASE
            WHEN @Top50By = 1 THEN
               (total_elapsed_time/execution_count)/1000
            WHEN @Top50By = 2 THEN
               (total_worker_time/execution_count)/1000
            WHEN @Top50By = 3 THEN
               (total_logical_reads/execution_count)
            END DESC
%d bloggers like this: