Sql-server – Production SQL Server High CPU for a Single Query

performancesql serversql-server-2008

I have a single query which is consuming a larger amount of CPU than I would expect in SQL 2008. I am not able to determine why the CPU is spiking for this single query.

I can trigger an application to make a query and watch the CPU spike, typically between 40-80%, which is much higher than any other similar queries executing at the same time or when I execute this same query by hand. In the Activity Monitor I see the spike occur and I see this single query pop up to the top of the Recent Expensive Queries list. It will show only a handful of executions/min but will show several hundred for its CPU ms/sec (250-500 on average). The logical reads is somewhere around several thousand. The duration is typically 600 or so. I have ran SQL Profiler and examined the logs to find the query being executed. However, I'm not able to replicate the issue calling this query myself. I can execute the query just as SQL Profile shows it, or execute it manually, and the CPU will not spike and the query never shows as a Recent Expensive Query. It only spikes when the consuming applications makes the call.

The query is a stored procedure that joins a few large select statements together. When I run this stored procedure manually I see very little cost in terms of CPU and I get results in less than a second. Examining the Profiler logs this stored procedure appears to be taking roughly 4 seconds to execute.

I have gone as far as to fire up duplicate images of the database and the application server. However, making these requests from this duplicate environment doesn't replicate the issue, nor does testing in our staging, dev or local environments.

Has SQL improperly cached the query execution or something to this effect? I recently added a couple indexes to the tables involved in this query and the execution plan I see from the Activity Monitor shows that the execution plan was updated for this change (no longer recommends these indexes). This sounds dumb, but do I need to restart the SQL Server or something? Or is there a way to better replicate the query that is coming into the server than pulling the query from the Profile trace?

Best Answer

Perhaps we can pull out the execution plan when it seems that particular query is running slow and compare it to the execution plan for when you run it. If you recently updated indexes it might still have the old exec plan cached, however, it does not answer the question as to why it runs fast when you execute the stored procedure from SQL Server, unless you're using different parameters.

Did you check if AUTO_UPDATE stats is on?

Is your tempdb optimized? Sometimes PAGELATCH_SH issues will be intermittent.

Can you view the wait stats, clear them, run the query, and then see the wait stats for when it was slow?

Viewing the plan cache: http://www.sqlteam.com/article/what-query-plans-are-in-sql-server-memory

Related Solutions

Sql-server – SQL Server 2008: High CPU historical queries

No, SQL Server does not track individual occurrences of queries, for the same reason you don't want to run profiler: tracing constantly can have a substantial performance impact on the server, and the last thing Microsoft wants to do is to turn on high-cost diagnostics most people will rarely or never use. Profiler is the absolute last tool you want to use for this anyway, as it is the worst offender. A server-side trace is much lighter weight, but you should also look into extended events and perhaps even 3rd party monitoring tools - I work for a vendor of one such tool and would be happy to give you guidance there.

In the meantime, you can track expensive queries in aggregate using DMVs like sys.dm_exec_procedure_stats and sys.dm_exec_query_stats. Here's a procedure from Glenn Berry's Diagnostic Queries that gets the top 25 CPU-consuming stored procedures for a specific database:

SELECT TOP(25) p.name AS [SP Name], qs.total_worker_time AS [TotalWorkerTime], 
qs.total_worker_time/qs.execution_count AS [AvgWorkerTime], qs.execution_count, 
ISNULL(qs.execution_count/DATEDIFF(Second, qs.cached_time, GETDATE()), 0) AS [Calls/Second],
qs.total_elapsed_time, qs.total_elapsed_time/qs.execution_count 
AS [avg_elapsed_time], qs.cached_time
FROM sys.procedures AS p WITH (NOLOCK)
INNER JOIN sys.dm_exec_procedure_stats AS qs WITH (NOLOCK)
ON p.[object_id] = qs.[object_id]
WHERE qs.database_id = DB_ID()
ORDER BY qs.total_worker_time DESC OPTION (RECOMPILE);

You can do a similar thing with sys.dm_exec_query_stats if you have a lot of ad hoc queries. For example:

SELECT TOP(25) SUBSTRING(t.text, (qs.statement_start_offset/2)+1, 
    ((CASE qs.statement_end_offset
      WHEN -1 THEN DATALENGTH(t.text)
     ELSE qs.statement_end_offset
     END - qs.statement_start_offset)/2) + 1) AS statement_text,
qs.total_worker_time/qs.execution_count AS [AvgWorkerTime], qs.execution_count, 
ISNULL(qs.execution_count/DATEDIFF(Second,qs.creation_time,GETDATE()),0) AS [Calls/Second],
qs.total_elapsed_time, qs.total_elapsed_time/qs.execution_count AS [avg_elapsed_time]
FROM sys.dm_exec_query_stats AS qs WITH (NOLOCK)
CROSS APPLY sys.dm_exec_sql_text(qs.sql_handle) AS t
ORDER BY AvgWorkerTime DESC OPTION (RECOMPILE);

Note that these DMVs do not persist data beyond a service restart and some other events, so you might not have the history you expect.

Sql-server – SQL Server 2012 CPU spike due to LinkedServer – how to find the offending query

To answer the question: How to find the offending query:

Since the spikes in the graph you posted last for several minutes you have plenty of time to use the following method:

Download sysinternals process explorer

start process explorer and find the SQL Server process.
right click and select properties
look at the thread tab.
Sort on the CPU column and note the thread id (TID) that is consuming the most CPU.

Use this query and lookup the query that is currently being executed by that thread:

SELECT r.session_id, st.text, qp.query_plan
FROM sys.dm_os_threads AS ot
JOIN sys.dm_os_tasks AS t
ON t.worker_address = ot.worker_address
JOIN sys.dm_exec_requests AS r
ON t.session_id = r.session_id
CROSS APPLY sys.dm_exec_sql_text(r.sql_handle) AS st
CROSS APPLY sys.dm_exec_query_plan(r.plan_handle) AS qp
WHERE os_thread_id = <thread id>

Best Answer

Related Solutions

Sql-server – SQL Server 2008: High CPU historical queries

Sql-server – SQL Server 2012 CPU spike due to LinkedServer – how to find the offending query

Related Question