April 30, 2008 at 11:14 am
One of the servers I am responsible for at work experiences CPU spikes (like yesterday it was at 100% for a hour) and my boss comes to me and wants to know what was going on at that time on the server. I am relatively experienced DBA but have a hard timer answering that question. Does anyone have any way to help out or suggestions. I have looked through DMV's but found nothing that really helps.
Thanks
April 30, 2008 at 12:24 pm
Try using the sys.dm_exec_requests data management view for the basis information. The system function sys.dm_exec_sql_text can be used to get the currently executing SQL statement.
select sys.dm_exec_requests.*
,db_name(SQLText.dbid)
,SQLText.text
fromsys.dm_exec_requests
OUTER APPLY sys.dm_exec_sql_text(sys.dm_exec_requests.sql_handle) AS SQLText
wheresys.dm_exec_requests.sql_handle is not null
SQL = Scarcely Qualifies as a Language
April 30, 2008 at 2:44 pm
How long does the spike last and are you sure that it is coming from the SQL Server process and not something else running on the same machine?
[font="Times New Roman"]-- RBarryYoung[/font], [font="Times New Roman"] (302)375-0451[/font] blog: MovingSQL.com, Twitter: @RBarryYoung[font="Arial Black"]
Proactive Performance Solutions, Inc. [/font][font="Verdana"] "Performance is our middle name."[/font]
May 1, 2008 at 9:59 am
we used the above procedure last year when we first upgraded. worked for us. we found a few queries using an in statement that caused it.
MS changed the optimizer from sql 2000 and this is what caused it. devs had to do an emergency patch in the code
May 1, 2008 at 3:10 pm
If it is definitely SQL Server causing the issue, you can track the issue to a specific SPID and from there see what code/connection is causing the issue.
Fire up Perfmon, select the Thread object, % Processor Time counter and all instances of sqlservr. Switch to Chart/Histogram view.
If it is one thread causing the issue, it will be very obvious - one of the bars will be at a high level and remain there. Make a note of which thread number it is.
Open another copy of Perfmon, select the Thread object again, ID Thread counter and select the sqlservr instance number that matches what you found above. Or you can just select all the sqlservr instances. Switch to Report view.
This will give you an ID Thread number for each thread. We use this number to match a SPID in SQL Server.
Open a query window to your SQL Server. Run the following command:
[font="Courier New"]SELECT spid, kpid, hostname, dbid, cmd
FROM master..sysprocesses -- for SQL 2005, use master.sys.sysprocesses
WHERE kpid = [/font]
This will return the SPID that is hogging the CPU, the command it is running (you can also run DBCC INPUTBUFFER on the SPID as well), the hostname that created the connection and the ID of the database being queried. You could also fire up the Activity Monitor in SQL Server or SQL Server Profiler to get more information.
Then you can start troubleshooting the query - badly written, missing indexes?
MARCUS. Why dost thou laugh? It fits not with this hour.
TITUS. Why, I have not another tear to shed;
--Titus Andronicus, William Shakespeare
May 2, 2008 at 7:19 am
Here is a stored procedure to list the resource usages for a given interval of time:
create PROCEDUREsp_resources
(@WaitSeconds TINYINT = 3
)
AS
SET NOCOUNT ON
SETXACT_ABORT ON
declare@WaitTimechar(8)
SET@WaitSeconds = 3
SET@WaitTime = '00:00:' + CAST(@WaitSeconds AS VARCHAR(2) )
Selectsys.dm_exec_requests.session_id
,sys.dm_exec_requests.request_id
,sys.dm_exec_requests.cpu_time
,sys.dm_exec_requests.reads
,sys.dm_exec_requests.writes
,sys.dm_exec_requests.logical_reads
INTO#Requests
FROMsys.dm_exec_requests
WAITFOR DELAY @WaitTime
SELECT sys.dm_exec_requests.cpu_time - #Requests.cpu_time AS cpu_time_Delta
, sys.dm_exec_requests.reads - #Requests.reads AS ReadsDelta
, sys.dm_exec_requests.writes - #Requests.writes AS writesDelta
, sys.dm_exec_requests.logical_reads - #Requests.logical_reads AS logical_reads_Delta
, sys.dm_exec_requests.session_id
, sys.dm_exec_requests.request_id
, sys.dm_exec_requests.start_time
, sys.dm_exec_requests.status
, sys.dm_exec_requests.command
, DB_NAME(sys.dm_exec_requests.database_id) AS Database_Name
, sys.dm_exec_requests.database_id
, sys.dm_exec_requests.user_id
, sys.dm_exec_requests.connection_id
, sys.dm_exec_requests.blocking_session_id
, sys.dm_exec_requests.wait_type
, sys.dm_exec_requests.wait_time
, sys.dm_exec_requests.last_wait_type
, sys.dm_exec_requests.wait_resource
, sys.dm_exec_requests.open_transaction_count
, sys.dm_exec_requests.open_resultset_count
, sys.dm_exec_requests.transaction_id
, sys.dm_exec_requests.percent_complete
, sys.dm_exec_requests.estimated_completion_time
, sys.dm_exec_requests.cpu_time
, sys.dm_exec_requests.total_elapsed_time
, sys.dm_exec_requests.reads
, sys.dm_exec_requests.writes
, sys.dm_exec_requests.logical_reads
, SQLText.text
FROM #Requests
JOIN sys.dm_exec_requests
ON sys.dm_exec_requests.session_id = #Requests.session_id
OUTER APPLY sys.dm_exec_sql_text(sys.dm_exec_requests.sql_handle) AS SQLText
WHERE sys.dm_exec_requests.sql_handle IS NOT NULL
AND ( sys.dm_exec_requests.cpu_time - #Requests.cpu_time > 0
OR sys.dm_exec_requests.reads - #Requests.reads > 0
OR sys.dm_exec_requests.writes - #Requests.writes > 0
OR sys.dm_exec_requests.logical_reads - #Requests.logical_reads > 0
)
ORDER BY ( sys.dm_exec_requests.cpu_time - #Requests.cpu_time ) DESC
SQL = Scarcely Qualifies as a Language
May 2, 2008 at 7:58 am
There was a VERY nasty bug (related to spin locks?) that was fixed in CU 3? or 4? (last Oct??) that exhibited this exact behavior. I am unfortunately unable to find the details of the situation due to some email issues a while back. If you aren't at least on CU 5 I would recommend investigating a patch. CU 7 was just released a few weeks ago.
I witnessed 16 CPUs peg for 17 mins at one of my clients early the morning of my FIRST day onsite for a performance review. This had been happening about once per week on average for a while and they hadn't been able to isolate it. It took me about an hour to isolate the cause and find that there had been a bug fix released just a few days prior. One of my finer moments, and both the CIO and CEO of the company stopped by to thank me!! 😎
Best,
Kevin G. Boles
SQL Server Consultant
SQL MVP 2007-2012
TheSQLGuru on googles mail service
May 3, 2008 at 7:51 am
To see the code running you can do right click on servername, reports, standard reports, activity all sessions and then click throught these to get to the SQL Code being executed...(this is similar to using profiler but profiler can be a bit overwhelming first time in here).
May 3, 2008 at 7:55 am
How do you get the kpid from here? Do you mean sql profiler?
Fire up Perfmon, select the Thread object, % Processor Time counter and all instances of sqlservr. Switch to Chart/Histogram view.
May 4, 2008 at 9:21 pm
No, the first perfmon instance (in Histogram view) shows you which SQL Server thread is hogging CPU use. Each thread is assigned a number, so you have sqlservr/1, sqlservr/2 etc.
The second perfmon instance (in Report view) associates the Windows thread number with a kpid (called ID Thread in perfmon). You take the kpid from there and put it into the query to get a SPID from SQL Server. Once you have a SPID, you can see what the query is that's causing the problems, where it is running from and who is running it (although the last two may be of limited use if everything is coming from a single source like a web application on IIS).
MARCUS. Why dost thou laugh? It fits not with this hour.
TITUS. Why, I have not another tear to shed;
--Titus Andronicus, William Shakespeare
May 4, 2008 at 9:27 pm
Here's some revised code that returns the SPID and does a DBCC INPUTBUFFER all in one step:
[font="Courier New"]USE master
GO
-- returns SPID & DBCC INPUTBUFFER for a given kpid
DECLARE @sql nvarchar(1000), @SPID int, @ParamDef nvarchar(1000)
SET @ParamDef = N'@spidOUT int OUTPUT'
SET @sql = N'SELECT @spidOUT = spid '
+ 'FROM master..sysprocesses '
+ 'WHERE kpid = ' -- insert kpid here. Use master.sys.processes for 2005
EXEC sp_executesql @sql, @ParamDef, @spidOUT = @spid OUTPUT
SET @sql = N'SELECT @spidOUT AS [SPID];dbcc inputbuffer('
+ CAST(@spid AS nvarchar(3)) + N')'
EXEC sp_executesql @sql, @ParamDef, @spid
[/font]
MARCUS. Why dost thou laugh? It fits not with this hour.
TITUS. Why, I have not another tear to shed;
--Titus Andronicus, William Shakespeare
May 5, 2008 at 7:48 am
Did not know this...so im trying this out.
Fire up Perfmon, select the Thread object, % Processor Time counter and all instances of sqlservr. Switch to Chart/Histogram view.
If it is one thread causing the issue, it will be very obvious - one of the bars will be at a high level and remain there.
---Make a note of which thread number it is. I cannot see the thread number do you have screen shot for example? (I must be missing something in properties)?
(Also how did you figure it was spinlocks)...
May 5, 2008 at 3:05 pm
First thing we do is open two copies of perfmon. The first one, we add the % Processor time per thread counters (see PerfMon01.jpg) and switch to Chart/Histogram view. The second one, we add ID Thread per thread counters (see PerfMon02.jpg) and switch to Report view.
Then we check the first perfmon instance for any single SQL thread that may be generating excess CPU usage. Check PerfMon03.jpg - if a single process is hogging CPU, you may see something like this (of course, it may be more than one thread causing issues, but let's keep it simple). In this case, the instance (or thread) number is 33.
Switch to the other perfmon instance (in Report view). Scroll across until you find instance 33. You will see the ID Thread number in this case is 4428 (see PerfMon04.jpg).
In the SQL statement in my previous post, add the number to the WHERE clause and run it:
[font="Courier New"]...WHERE kpid = 4428...[/font]
It will return the SQL Server SPID and the contents of the INPUTBUFFER (using DBCC INPUTBUFFER) for that SPID.
MARCUS. Why dost thou laugh? It fits not with this hour.
TITUS. Why, I have not another tear to shed;
--Titus Andronicus, William Shakespeare
July 21, 2009 at 1:33 pm
Hi there:
Good article. I could have used this on a few occasions. Tryed your code but had some syntax issues:
USE master
GO
-- returns SPID & DBCC INPUTBUFFER for a given kpid
DECLARE @sql nvarchar(1000), @spid int, @ParamDef nvarchar(1000)
SET @ParamDef = N'@spidOUT int OUTPUT'
SET @sql = N'SELECT @spidOUT = spid '
+ 'FROM master..sysprocesses '
+ 'WHERE kpid = ' -- insert kpid here. Use master.sys.processes for 2005
EXEC sp_executesql @sql, @ParamDef, @spidOUT = @spid OUTPUT
SET @sql = N'SELECT @spidOUT AS [SPID];dbcc inputbuffer('
+ CAST(@spid AS nvarchar(3)) + N')'
EXEC sp_executesql @sql, @ParamDef, @spid
Server: Msg 170, Level 15, State 1, Line 8
Line 8: Inccorect syntax near '7076'.
->I also lower cased SPID to spid
Do you see something odvious?
thnxs
July 22, 2009 at 5:53 am
An excellent trick to have up the sleeve that one Scott, thanks. Never seen it documented/mentioned before but its definately a neat approach to CPU spikes.
John
Viewing 15 posts - 1 through 15 (of 20 total)
You must be logged in to reply to this topic. Login to reply