11.09.2015
Наблюдаем высокую загрузку CPU по счетчикам Processor Time на сервере СУБД c MS SQL Server.
Что делать?
Видим высокую загрузку CPU на сервере MS SQL Server.
Загрузку видим "сейчас", при этом по данным Performance Monitor, Диспетчера задач или Монитора ресурсов мы уверены, что основную нагрузку создает именно MS SQL Server.
Существует два подхода к получению ответа на вопрос: "Почему и что именно создает такую нагрузку".
Каждый из подходов может оказаться полезным.
Рекомендуется проделать действия, указанные в двух подходах, и применять на практике тот (либо их комбинацию ), который более других подойдет к вашей ситуации.
Как найти самый тяжелый (или несколько тяжелых) запрос в коде конфигурации.
Например, можно настроить технологический журнал с фильтрами только на один запрос. Может выглядеть так:
Копировать в буфер обмена<?xml version="1.0" encoding="UTF-8"?> <config xmlns="http://v8.1c.ru/v8/tech-log"> <log location="С:\Sql_Reads" history="2"> <event> <eq property="Name" value="DBMSSQL"/> <like property="Sql" value="%Reference5774%"/> <like property="Sql" value="%SELECT TOP%"/> </event> <property name="all"/> </log> <plansql/> </config>
Смысл в том, чтобы указать такие фильтры
Копировать в буфер обмена<like property="Sql" value="%Reference5774%"/>
которые будут включать имена таблиц в найденном вами на предыдущем шаге запросе.
Если всё аккуратно сделаете, то в полученном технологическом журнале запрос у вас будет только тот, который нужен.
Журнал получится небольшим.
Собственно стек из кода на встроенном языке будет сразу в конце события с запросом.
Top запросов, создающих нагрузку на CPU на сервере СУБД за последний час
Копировать в буфер обменаSELECT
SUM(qs.max_elapsed_time) as elapsed_time,
SUM(qs.total_worker_time) as worker_time
into T1 FROM (
select top 100000
*
from
sys.dm_exec_query_stats qs
where qs.last_execution_time > (CURRENT_TIMESTAMP - '01:00:00.000')
order by qs.last_execution_time desc
) as qs
;
Копировать в буфер обмена
select top 10000
(qs.max_elapsed_time) as elapsed_time,
(qs.total_worker_time) as worker_time,
qp.query_plan,
st.text,
dtb.name,
qs.*,
st.dbid
INTO T2
FROM
sys.dm_exec_query_stats qs
CROSS APPLY sys.dm_exec_query_plan(qs.plan_handle) qp
CROSS APPLY sys.dm_exec_sql_text(qs.sql_handle) st
left outer join sys.databases as dtb on st.dbid = dtb.database_id
where qs.last_execution_time > (CURRENT_TIMESTAMP - '01:00:00.000')
order by qs.last_execution_time desc
;
select top 100
(T2.elapsed_time*100/T1.elapsed_time) as percent_elapsed_time,
(T2.worker_time*100/T1.worker_time) as percent_worker_time,
T2.*
from
T2 as T2
INNER JOIN T1 as T1
ON 1=1
order by T2.worker_time desc
;
drop table T2
;
drop table T1
;
Копировать в буфер обмена
WITH DB_CPU_StatsКопировать в буфер обмена
AS
(SELECT DatabaseID, DB_Name(DatabaseID) AS [DatabaseName], SUM(total_worker_time) AS [CPU_Time_Ms]
FROM sys.dm_exec_query_stats AS qs
CROSS APPLY (SELECT CONVERT(int, value) AS [DatabaseID]
FROM sys.dm_exec_plan_attributes(qs.plan_handle)
WHERE attribute = N'dbid') AS F_DB
GROUP BY DatabaseID)
SELECT ROW_NUMBER() OVER(ORDER BY [CPU_Time_Ms] DESC) AS [row_num],
DatabaseName, [CPU_Time_Ms],
CAST([CPU_Time_Ms] * 1.0 / SUM([CPU_Time_Ms]) OVER() * 100.0 AS DECIMAL(5, 2)) AS [CPUPercent]
FROM DB_CPU_Stats
WHERE DatabaseID > 4 -- system databases
AND DatabaseID <> 32767 -- ResourceDB
ORDER BY row_num OPTION (RECOMPILE);
SELECT TOP 10
[Average CPU used] = total_worker_time / qs.execution_count
,[Total CPU used] = total_worker_time
,[Execution count] = qs.execution_count
,[Individual Query] = SUBSTRING (qt.text,qs.statement_start_offset/2,
(CASE WHEN qs.statement_end_offset = -1
THEN LEN(CONVERT(NVARCHAR(MAX), qt.text)) * 2
ELSE qs.statement_end_offset END -
qs.statement_start_offset)/2)
,[Parent Query] = qt.text
,DatabaseName = DB_NAME(qt.dbid)
FROM sys.dm_exec_query_stats qs
CROSS APPLY sys.dm_exec_sql_text(qs.sql_handle) as qt
ORDER BY [Average CPU used] DESC;
Наиболее часто выполняемые запросы
Копировать в буфер обменаSELECT TOP 10
[Execution count] = execution_count
,[Inpidual Query] = SUBSTRING (qt.text,qs.statement_start_offset/2,
(CASE WHEN qs.statement_end_offset = -1
THEN LEN(CONVERT(NVARCHAR(MAX), qt.text)) * 2
ELSE qs.statement_end_offset END - qs.statement_start_offset)/2)
,[Parent Query] = qt.text
,DatabaseName = DB_NAME(qt.dbid)
FROM sys.dm_exec_query_stats qs
CROSS APPLY sys.dm_exec_sql_text(qs.sql_handle) as qt
ORDER BY [Execution count] DESC;
Текущая статистика по задержкам (расшифровка задержек в библиотеке MSDN)
Копировать в буфер обменаSELECT TOP 10
[Wait type] = wait_type,
[Wait time (s)] = wait_time_ms / 1000,
[% waiting] = CONVERT(DECIMAL(12,2), wait_time_ms * 100.0
/ SUM(wait_time_ms) OVER())
FROM sys.dm_os_wait_stats
WHERE wait_type NOT LIKE '%SLEEP%'
ORDER BY wait_time_ms DESC;
Индексы с высокими издержками при использовании
Копировать в буфер обмена-- Create required table structure only.
-- Note: this SQL must be the same as in the Database loop given in the following step.
SELECT TOP 1
[Maintenance cost] = (user_updates + system_updates)
,[Retrieval usage] = (user_seeks + user_scans + user_lookups)
,DatabaseName = DB_NAME()
,TableName = OBJECT_NAME(s.[object_id])
,IndexName = i.name
INTO #TempMaintenanceCost
FROM sys.dm_db_index_usage_stats s
INNER JOIN sys.indexes i ON s.[object_id] = i.[object_id]
AND s.index_id = i.index_id
WHERE s.database_id = DB_ID()
AND OBJECTPROPERTY(s.[object_id], 'IsMsShipped') = 0
AND (user_updates + system_updates) > 0 -- Only report on active rows.
AND s.[object_id] = -999 -- Dummy value to get table structure.
;
-- Loop around all the databases on the server.
EXEC sp_MSForEachDB 'USE [?];
-- Table already exists.
INSERT INTO #TempMaintenanceCost
SELECT TOP 10
[Maintenance cost] = (user_updates + system_updates)
,[Retrieval usage] = (user_seeks + user_scans + user_lookups)
,DatabaseName = DB_NAME()
,TableName = OBJECT_NAME(s.[object_id])
,IndexName = i.name
FROM sys.dm_db_index_usage_stats s
INNER JOIN sys.indexes i ON s.[object_id] = i.[object_id]
AND s.index_id = i.index_id
WHERE s.database_id = DB_ID()
AND i.name IS NOT NULL -- Ignore HEAP indexes.
AND OBJECTPROPERTY(s.[object_id], ''IsMsShipped'') = 0
AND (user_updates + system_updates) > 0 -- Only report on active rows.
ORDER BY [Maintenance cost] DESC
;
'
-- Select records.
SELECT TOP 10 * FROM #TempMaintenanceCost
ORDER BY [Maintenance cost] DESC
-- Tidy up.
DROP TABLE #TempMaintenanceCost
WITH DB_CPU_Stats
AS
(
SELECT DatabaseID, DB_Name(DatabaseID) AS [DatabaseName], SUM(total_worker_time) AS [CPU_Time_Ms]
FROM sys.dm_exec_query_stats AS qs
CROSS APPLY (SELECT CONVERT(int, value) AS [DatabaseID]
FROM sys.dm_exec_plan_attributes(qs.plan_handle)
WHERE attribute = N'dbid') AS F_DB
WHERE qs.last_execution_time > (CURRENT_TIMESTAMP - '01:00:00.000')
GROUP BY DatabaseID)
SELECT ROW_NUMBER() OVER(ORDER BY [CPU_Time_Ms] DESC) AS [row_num],
DatabaseName, [CPU_Time_Ms],
CAST([CPU_Time_Ms] * 1.0 / SUM([CPU_Time_Ms]) OVER() * 100.0 AS DECIMAL(5, 2)) AS [CPUPercent]
FROM DB_CPU_Stats
WHERE DatabaseID > 4 -- system databases
AND DatabaseID <> 32767 -- ResourceDB
ORDER BY row_num OPTION (RECOMPILE);
SELECT
SUM(qs.max_elapsed_time) as elapsed_time,
SUM(qs.total_worker_time) as worker_time
into T1 FROM (
select top 100000
*
from
sys.dm_exec_query_stats qs
where qs.last_execution_time > (CURRENT_TIMESTAMP - '01:00:00.000')
order by qs.last_execution_time desc
) as qs
;
select top 10000
(qs.max_elapsed_time) as elapsed_time,
(qs.total_worker_time) as worker_time,
qp.query_plan,
st.text,
dtb.name,
qs.*,
st.dbid
INTO T2
FROM
sys.dm_exec_query_stats qs
CROSS APPLY sys.dm_exec_query_plan(qs.plan_handle) qp
CROSS APPLY sys.dm_exec_sql_text(qs.sql_handle) st
left outer join sys.databases as dtb on st.dbid = dtb.database_id
where qs.last_execution_time > (CURRENT_TIMESTAMP - '01:00:00.000')
order by qs.last_execution_time desc
;
select
(T2.elapsed_time*100/T1.elapsed_time) as percent_elapsed_time,
(T2.worker_time*100/T1.worker_time) as percent_worker_time,
T2.*
from
T2 as T2
INNER JOIN T1 as T1
ON 1=1
order by T2.worker_time desc
;
drop table T2
;
drop table T1
;
В первую очередь смотрим на percent_worker_time и percent_elapsed_time. Нагрузка не должна быть «размазана» между всеми запросами.
4.1.1. Для этого на сервере должна быть директория для трассировки.
Нужно директорию указать вместо 'InsertFileNameHere' в скрипте ниже.
Размер файла трассировки ограничен 1 Гб.
Копировать в буфер обмена-- Create a Queue
declare @rc int
declare @TraceID int
declare @maxfilesize bigint
set @maxfilesize = 1024
-- Please replace the text InsertFileNameHere, with an appropriate
-- filename prefixed by a path, e.g., c:\MyFolder\MyTrace. The .trc extension
-- will be appended to the filename automatically. If you are writing from
-- remote server to local drive, please use UNC path and make sure server has
-- write access to your network share
exec @rc = sp_trace_create @TraceID output, 0, N'InsertFileNameHere', @maxfilesize, NULL
if (@rc != 0) goto error
-- Client side File and Table cannot be scripted
-- Set the events
declare @on bit
set @on = 1
exec sp_trace_setevent @TraceID, 10, 15, @on
exec sp_trace_setevent @TraceID, 10, 8, @on
exec sp_trace_setevent @TraceID, 10, 16, @on
exec sp_trace_setevent @TraceID, 10, 48, @on
exec sp_trace_setevent @TraceID, 10, 1, @on
exec sp_trace_setevent @TraceID, 10, 9, @on
exec sp_trace_setevent @TraceID, 10, 17, @on
exec sp_trace_setevent @TraceID, 10, 18, @on
exec sp_trace_setevent @TraceID, 10, 66, @on
exec sp_trace_setevent @TraceID, 10, 3, @on
exec sp_trace_setevent @TraceID, 10, 12, @on
exec sp_trace_setevent @TraceID, 10, 13, @on
exec sp_trace_setevent @TraceID, 10, 14, @on
exec sp_trace_setevent @TraceID, 12, 15, @on
exec sp_trace_setevent @TraceID, 12, 8, @on
exec sp_trace_setevent @TraceID, 12, 16, @on
exec sp_trace_setevent @TraceID, 12, 48, @on
exec sp_trace_setevent @TraceID, 12, 1, @on
exec sp_trace_setevent @TraceID, 12, 9, @on
exec sp_trace_setevent @TraceID, 12, 17, @on
exec sp_trace_setevent @TraceID, 12, 14, @on
exec sp_trace_setevent @TraceID, 12, 18, @on
exec sp_trace_setevent @TraceID, 12, 66, @on
exec sp_trace_setevent @TraceID, 12, 3, @on
exec sp_trace_setevent @TraceID, 12, 12, @on
exec sp_trace_setevent @TraceID, 12, 13, @on
-- Set the Filters
declare @intfilter int
declare @bigintfilter bigint
-- Set the trace status to start
exec sp_trace_setstatus @TraceID, 1
-- display trace id for future references
select TraceID=@TraceID
goto finish
error:
select ErrorCode=@rc
finish:
go
4.1.2. Останавливаем трассировку, когда уверены, что трассировку собрали в интересующий период нагрузки.
Копировать в буфер обменаexec sp_trace_setstatus @TraceID, 0
4.1.3. Сохраняем трассировку в тестовую БД test в таблицу trace, в которой будем анализировать загрузку.
4.1.4. Добавляем в таблицу trace две колонки HashSQL varchar(4000) и HashSQLMD5 varbinary(32).
Копировать в буфер обменаALTER TABLE [test].[dbo].[trace] ADD HashSQL VARCHAR(4000) NULL, HashSQLMD5 varbinary(32) NULL ;
Затем выполняем:
Копировать в буфер обменаUPDATE [test].[dbo].[trace] SET [HashSQL] = dbo.fn_GetSQLHash(SUBSTRING([TextData], 1, 4000));
UPDATE [test].[dbo].[trace] SET [HashSQLMD5] = HashBytes('MD5', HashSQL);
В качестве альтернативы для этих целей можно использовать курсор:
Копировать в буфер обмена
DECLARE @RowNumber intКопировать в буфер обмена
DECLARE @TextData nvarchar(4000)
DECLARE @HashSQL nvarchar(4000)
DECLARE hash_cursor CURSOR
FOR SELECT TextData,RowNumber FROM [test].[dbo].[trace]
OPEN hash_cursor
FETCH NEXT FROM hash_cursor
INTO @TextData, @RowNumber
WHILE @@FETCH_STATUS = 0
BEGIN
SET @HashSQL = [test].[dbo].fn_GetSQLHash(@TextData)
UPDATE [test].[dbo].[trace]
SET [HashSQL] = @HashSQL
,[HashSQLMD5] = HashBytes('MD5', @HashSQL)
WHERE RowNumber = @RowNumber
FETCH NEXT FROM hash_cursor
INTO @TextData, @RowNumber
END
CLOSE hash_cursor
DEALLOCATE hash_curso
CREATE FUNCTION fn_GetSQLHash(@TSQL nvarchar(4000))
RETURNS varchar(4000)
AS
BEGIN
DECLARE @TmpTableName nvarchar(4000)
DECLARE @i int
SET @TmpTableName = ''
IF (CHARINDEX('#', @TSQL) > 0)
BEGIN
SET @TmpTableName = SUBSTRING(@TSQL, CHARINDEX('#', @TSQL), 4000)
IF (CHARINDEX(' ', @TmpTableName) > 0)
BEGIN
SET @TmpTableName = SUBSTRING(@TmpTableName, 1, CHARINDEX(' ', @TmpTableName) - 1)
END
END
SET @TSQL = REPLACE ( @TSQL , @TmpTableName , 'TEMPTABLE')
SET @TSQL = REPLACE ( @TSQL , ' ' , '')
SET @TSQL = REPLACE ( @TSQL , ' ' , '')
SET @TSQL = REPLACE ( @TSQL , ' ' , '')
SET @TSQL = REPLACE ( @TSQL , 'execsp_executesqlN''' , '')
SET @TSQL = REPLACE ( @TSQL , CHAR(10) , '')
IF (CHARINDEX(''',N''', @TSQL) > 0)
SET @TSQL = SUBSTRING(@TSQL, 1, CHARINDEX(''',N''', @TSQL) - 1)
SET @i = 1
WHILE @i < 30
BEGIN
SET @TSQL = REPLACE ( @TSQL , '@P' + CAST(@i AS varchar), '')
SET @i = @i + 1
END
SET @TSQL = REPLACE ( @TSQL , '{', '')
SET @TSQL = REPLACE ( @TSQL , '}', '')
SET @TSQL = REPLACE ( @TSQL , '''', '')
SET @TSQL = REPLACE ( @TSQL , '"', '')
SET @TSQL = REPLACE ( @TSQL , '.', '')
SET @TSQL = REPLACE ( @TSQL , ',', '')
SET @TSQL = REPLACE ( @TSQL , ';', '')
SET @TSQL = REPLACE ( @TSQL , ':', '')
SET @TSQL = REPLACE ( @TSQL , '@', '')
SET @TSQL = REPLACE ( @TSQL , '?', '')
SET @TSQL = REPLACE ( @TSQL , '=', '')
SET @TSQL = UPPER(@TSQL)
SET @TSQL = LEFT(@TSQL, 4000)
RETURN(@TSQL);
END
4.1.5. Анализируем трассировку. Например, смотрим:
Копировать в буфер обменаSELECT TOP 100
[HashSQL] as HashSQL
,SUM([CPU]) as SumCPU
,SUM([Reads]) as SumReads
,SUM([Writes]) as SumWrites
,SUM([Duration]) as SumDuration
,[DatabaseID] as DatabaseID
,SUM([RowCounts]) as SumRowCounts
FROM [test].[dbo].[trace]
WHERE [DatabaseID] = 12345
GROUP BY
[HashSQL]
,[DatabaseID]
ORDER BY SumCPU desc
Находим наиболее интересные запросы по SUM([CPU]).
В целом эту же методику можно использовать для поиска по Reads, Writes, Duration, и т.д.
4.1.6. Для того, чтобы найти запрос в коде конфигурации настраиваем тех журнал вида
Копировать в буфер обмена<?xml version="1.0" encoding="UTF-8"?> <config xmlns="http://v8.1c.ru/v8/tech-log">
<log location="С:\Sql_Reads" history="2">
<event>
<eq property="Name" value="DBMSSQL"/>
<like property="Sql" value="%SELECT TOP%Reference5774%"/>
</event>
<property name="all"/>
</log>
<plansql/>
</config>
Где в строке
Копировать в буфер обмена<like property="Sql" value="%SELECT TOP%Reference5774%"/>
указываем ключевые слова из запроса.
4.1.7. По технологическому журналу определяем лидера, исправляем.
4.2.1. Для того, чтобы найти запрос в коде конфигурации настраиваем тех журнал вида
Копировать в буфер обмена<?xml version="1.0" encoding="UTF-8"?>
<config xmlns="http://v8.1c.ru/v8/tech-log">
<log location="С:\Sql_Reads" history="2">
<event>
<eq property="Name" value="DBMSSQL"/>
<like property="Sql" value="%SELECT TOP%Reference5774%"/>
</event>
<property name="all"/>
</log>
<plansql/>
</config>
Где в строке
Копировать в буфер обмена<like property="Sql" value="%SELECT TOP%Reference5774%"/>
указываем ключевые слова из запроса.
4.2.2. По технологическому журналу определяем лидера, исправляем в коде конфигурации.
В собранном технологическом журнале будет искомый запрос с указанием стека на встроенном языке, "откуда" этот запрос выполнялся.