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

linked-serversql serversql-server-2012

As part of another question (SQL Server 2012 performance issues (maybe due to linked server)) I've identified a CPU spike to be directly related to a spike in Bytes Received, which leads me to believe it is likely due to the link server.

THE ENVIRONMENT

2 servers, one server accesses a database on the first via a linked server, for nice diagram, please see SQL Server 2012 performance issues (maybe due to linked server)

enter image description here

CPU spike directly related to Bytes Received Spike

QUESTION
How to find which queries could be causing it??

TYPES OF QUERIES WE RUN

I've went through all our stored procedures, and they are optimized. Here are the types of linked server access that we do:

select one value from remote table

select @userid = userid from FBGC.FBGCommon.dbo.players where playerid = @playerid

execute stored procedure that returns result set of max few hundred rows

exec FBGC.Fbgcommon.dbo.qPlayersFriends @PlayerID

execute stored procedure that returns one value

exec @HasEnoughCredits = FBGC.FBGCommon.dbo.qDoesPlayerHaveEnoughCredits @PlayerID, @Cost

delete a few rows from remove table

delete from FBGC.FBGCommon.dbo.InactivePlayersToBeWarned where PlayerID = @AccountOwnerPlayerID

Update one row in remote table, or add one row to remote table

update FBGC.FBGCommon.dbo.users set XP = XP + @XPForTitle where userid = @userid
insert into FBGC.FBGCommon.dbo.UserXPHistory (userid, time, XPReceived, XPFromTypeID, XPFromRealmID) values (@UserID, GETDATE(), @XPForTitle, 1, @ThisRealmID)

I believe all of these are optimized, yet, it appears we are joining tables over the linked server!

Some interesting wait stats that I do not know how to interpret.
Ran a query from http://www.sqlskills.com/blogs/paul/wait-statistics-or-please-tell-me-where-it-hurts/

I get this DURING the CPU spike:
enter image description here

I get this when there is no CPU spike:
enter image description here

These wait times are on the server with DB2, the SQL 2012 server which accesses a remote database on another server running sql server 2008 (for diagram, see SQL Server 2012 performance issues (maybe due to linked server)

Restarting sql server help – no CPU spike for significant amount of time.

We've also found that, restarting SQL Server helps – we could be getting intermittent spikes for hours, many times an hour, then after restart, no spikes for an hour or more..

Process explorer

As suggested by @EdwardDortland, I used Process explorer to see what thread is consuming most CPU during the slow down

unfortunately, no single thread shows up as the main culprit – during CPU spike, simply all threads consume more CPU. although I am seeing a lot more threads highlighted in red (meaning deleted) during the CPU spike – not sure how to interpret this.

Threads before the CPU spike
enter image description here

Threads during the CPU spike
enter image description here

Best Answer

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>

Related Solutions

Sql-server – I cannot get SQL Server 2012 to install the database engine

SQL server 2012 installation is not supported through terminal services. It causes a lot of strange problems, and I experienced this same issue.

Microsoft states this in their prerequisites:

Link is http://msdn.microsoft.com/en-us/library/ms143506.aspx

This document states:

The installation of SQL Server 2012 fails if you launch the setup through Terminal Services Client. Launching SQL Server Setup through Terminal Services Client is not supported.

SQL Server Performance – PREEMPTIVE_OS_DELETESECURITYCONTEXT Dominant Wait Type

I know this question, based on the Title, is mainly concerned with the PREEMPTIVE_OS_DELETESECURITYCONTEXT wait type, but I believe that is a misdirection of the true issue which is " a customer who was complaining about high CPU usage on their SQL Server ".

The reason I believe that focusing on this specific wait type is a wild goose chase is because it goes up for every connection made. I am running the following query on my laptop (meaning I am the only user):

SELECT * 
FROM sys.dm_os_wait_stats
WHERE wait_type = N'PREEMPTIVE_OS_DELETESECURITYCONTEXT'

And then I do any of the following and re-run this query:

open a new query tab
close the new query tab
run the following from a DOS prompt: SQLCMD -E -Q "select 1"

Now, we know that CPU is high so we should look at what is running to see what sessions have high CPU:

SELECT req.session_id AS [SPID],
       req.blocking_session_id AS [BlockedBy],
       req.logical_reads AS [LogReads],
       DB_NAME(req.database_id) AS [DatabaseName],
       SUBSTRING(txt.[text],
                 (req.statement_start_offset / 2) + 1,
                 CASE
                     WHEN req.statement_end_offset > 0
                        THEN (req.statement_end_offset - req.statement_start_offset) / 2
                     ELSE LEN(txt.[text])
                 END
                ) AS [CurrentStatement],
       txt.[text] AS [CurrentBatch],
       CONVERT(XML, qplan.query_plan) AS [StatementQueryPlan],
       OBJECT_NAME(qplan.objectid, qplan.[dbid]) AS [ObjectName],
       sess.[program_name],
       sess.[host_name],
       sess.nt_user_name,
       sess.total_scheduled_time,
       sess.memory_usage,
       req.*
FROM sys.dm_exec_requests req
INNER JOIN sys.dm_exec_sessions sess
        ON sess.session_id = req.session_id
CROSS APPLY sys.dm_exec_sql_text(req.[sql_handle]) txt
OUTER APPLY sys.dm_exec_text_query_plan(req.plan_handle,
                                        req.statement_start_offset,
                                        req.statement_end_offset) qplan
WHERE req.session_id <> @@SPID
ORDER BY req.logical_reads DESC, req.cpu_time DESC
--ORDER BY req.cpu_time DESC, req.logical_reads DESC

I usually run the above query as it is, but you could also switch which ORDER BY clause is commented out to see if that gives more interesting / helpful results.

Alternatively you can run the following, based on dm_exec_query_stats, to find highest-cost queries. The first query below will show you individual queries (even if they have multiple plans) and is ordered by Average CPU Time, but you can easily change that to be Average Logical Reads. Once you find a query that looks like it is taking a lot of resources, copy the "sql_handle" and "statement_start_offset" into the WHERE condition of the second query below to see the individual plans (can be more than 1). Scroll to the far right and assuming there was an XML Plan, it will display as a link (in Grid Mode) which will take you to the plan viewer if you click on it.

Query #1: Get Query Info

;WITH cte AS
(
   SELECT qstat.[sql_handle],
          qstat.statement_start_offset,
          qstat.statement_end_offset,
          COUNT(*) AS [NumberOfPlans],
          SUM(qstat.execution_count) AS [TotalExecutions],

          SUM(qstat.total_worker_time) AS [TotalCPU],
          (SUM(qstat.total_worker_time * 1.0) / SUM(qstat.execution_count)) AS [AvgCPUtime],
          MAX(qstat.max_worker_time) AS [MaxCPU],

          SUM(qstat.total_logical_reads) AS [TotalLogicalReads],
   (SUM(qstat.total_logical_reads * 1.0) / SUM(qstat.execution_count)) AS [AvgLogicalReads],
          MAX(qstat.max_logical_reads) AS [MaxLogicalReads],

          SUM(qstat.total_rows) AS [TotalRows],
          (SUM(qstat.total_rows * 1.0) / SUM(qstat.execution_count)) AS [AvgRows],
          MAX(qstat.max_rows) AS [MaxRows]
   FROM sys.dm_exec_query_stats  qstat
   GROUP BY qstat.[sql_handle], qstat.statement_start_offset, qstat.statement_end_offset
)
SELECT  cte.*,
        DB_NAME(txt.[dbid]) AS [DatabaseName],
        SUBSTRING(txt.[text],
                  (cte.statement_start_offset / 2) + 1,
                  CASE
                      WHEN cte.statement_end_offset > 0
                          THEN (cte.statement_end_offset - cte.statement_start_offset) / 2
                      ELSE LEN(txt.[text])
                  END
                 ) AS [CurrentStatement],
        txt.[text] AS [CurrentBatch]
FROM cte
CROSS APPLY sys.dm_exec_sql_text(cte.[sql_handle]) txt
ORDER BY cte.AvgCPUtime DESC

Query #2: Get Plan Info

SELECT  *,
        DB_NAME(qplan.[dbid]) AS [DatabaseName],
        CONVERT(XML, qplan.query_plan) AS [StatementQueryPlan],
        SUBSTRING(txt.[text],
                  (qstat.statement_start_offset / 2) + 1,
                  CASE
                        WHEN qstat.statement_end_offset > 0
                        THEN (qstat.statement_end_offset - qstat.statement_start_offset) / 2
                        ELSE LEN(txt.[text])
                  END
                 ) AS [CurrentStatement],
        txt.[text] AS [CurrentBatch]
FROM sys.dm_exec_query_stats  qstat
CROSS APPLY sys.dm_exec_sql_text(qstat.[sql_handle]) txt
OUTER APPLY sys.dm_exec_text_query_plan(qstat.plan_handle,
                                        qstat.statement_start_offset,
                                        qstat.statement_end_offset) qplan
-- paste info from Query #1 below
WHERE qstat.[sql_handle] = 0x020000001C70C614D261C85875D4EF3C90BD18D02D62453800....
AND qstat.statement_start_offset = 164
-- paste info from Query #1 above
ORDER BY qstat.total_worker_time DESC

Best Answer

Related Solutions

Sql-server – I cannot get SQL Server 2012 to install the database engine

SQL Server Performance – PREEMPTIVE_OS_DELETESECURITYCONTEXT Dominant Wait Type

Related Question