SQL сервер: Сбор и анализ статистики по выполняемым процедурам на продуктивном сервере

По мотивам Finding the Causes of Poor Performance in SQL Server, Part 1 https://www.simple-talk.com/sql/performance/finding-the-causes-of-poor-performance-in-sql-server,-part-1/

Получение данных трассировки

С этой целью мы могли бы воспользоваться SQL Server Profiler, однако в условиях продуктивной среды его использование не рекомендуется 

Мы будем использовать трассировку на стороне сервера (server-side trace)

Создание скрипта трассировки

Для создания скрипта трассировки мы можем воспользоваться SQL server Profiler на тестовом сервере

Можно установить фильтр по базе данных.

После того как мы запустили и остановили трассировку, можно сгенерировать скрипт трассировки

После его открытия в SQL query мы получим сгенерированный скрипт:

/****************************************************/

/****************************************************/
/* Created by: SQL Server 2012  Profiler          */
/* Date: 22/09/2014  09:40:38         */
/****************************************************/


-- Create a Queue
declare @rc int
declare @TraceID int
declare @maxfilesize bigint
set @maxfilesize = 5 

-- 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, 146, 1, @on
exec sp_trace_setevent @TraceID, 146, 3, @on
exec sp_trace_setevent @TraceID, 146, 12, @on
exec sp_trace_setevent @TraceID, 146, 14, @on
exec sp_trace_setevent @TraceID, 146, 51, @on
exec sp_trace_setevent @TraceID, 10, 1, @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, 10, 16, @on
exec sp_trace_setevent @TraceID, 10, 17, @on
exec sp_trace_setevent @TraceID, 10, 18, @on
exec sp_trace_setevent @TraceID, 10, 48, @on
exec sp_trace_setevent @TraceID, 10, 51, @on
exec sp_trace_setevent @TraceID, 12, 1, @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
exec sp_trace_setevent @TraceID, 12, 14, @on
exec sp_trace_setevent @TraceID, 12, 16, @on
exec sp_trace_setevent @TraceID, 12, 17, @on
exec sp_trace_setevent @TraceID, 12, 18, @on
exec sp_trace_setevent @TraceID, 12, 48, @on
exec sp_trace_setevent @TraceID, 12, 51, @on


-- Set the Filters
declare @intfilter int
declare @bigintfilter bigint

set @intfilter = 6
exec sp_trace_setfilter @TraceID, 3, 0, 0, @intfilter

set @bigintfilter = 1000
exec sp_trace_setfilter @TraceID, 13, 0, 4, @bigintfilter

-- 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

Перед запуском его необходимо доработать. Добавим:

--указываем путь и имя файла
SET @OutputFileName = 'E:\MSSQL_Trace\' +
    CONVERT(VARCHAR(20), GETDATE(),112) +
    REPLACE(CONVERT(VARCHAR(20), GETDATE(),108),':','')

--время окончания через 30 мин
SET @EndTime = DATEADD(mi,30,getdate())

SELECT *
FROM   sys.traces;

Окончательная версия скрипта:

-- Create a Queue
declare @rc int
declare @TraceID int
declare @maxfilesize bigint

DECLARE @OutputFileName NVARCHAR(256) 
DECLARE @EndTime DATETIME

set @maxfilesize = 100

--указываем путь и имя файла
SET @OutputFileName = 'E:\MSSQL_Trace\' +
    CONVERT(VARCHAR(20), GETDATE(),112) +
    REPLACE(CONVERT(VARCHAR(20), GETDATE(),108),':','')

--время окончания через 30 мин
SET @EndTime = DATEADD(mi,30,getdate())

--трассировка прекратится при наступлении времени окончания
exec @rc = sp_trace_create @TraceID output, 0, @OutputFileName, @MaxFileSize, @EndTime

-- Set the events
declare @on bit
set @on = 1
exec sp_trace_setevent @TraceID, 146, 1, @on
exec sp_trace_setevent @TraceID, 146, 3, @on
exec sp_trace_setevent @TraceID, 146, 12, @on
exec sp_trace_setevent @TraceID, 146, 14, @on
exec sp_trace_setevent @TraceID, 146, 51, @on
exec sp_trace_setevent @TraceID, 10, 1, @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, 10, 16, @on
exec sp_trace_setevent @TraceID, 10, 17, @on
exec sp_trace_setevent @TraceID, 10, 18, @on
exec sp_trace_setevent @TraceID, 10, 48, @on
exec sp_trace_setevent @TraceID, 10, 51, @on
exec sp_trace_setevent @TraceID, 12, 1, @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
exec sp_trace_setevent @TraceID, 12, 14, @on
exec sp_trace_setevent @TraceID, 12, 16, @on
exec sp_trace_setevent @TraceID, 12, 17, @on
exec sp_trace_setevent @TraceID, 12, 18, @on
exec sp_trace_setevent @TraceID, 12, 48, @on
exec sp_trace_setevent @TraceID, 12, 51, @on


-- Set the Filters
declare @intfilter int
declare @bigintfilter bigint

set @intfilter = 6
exec sp_trace_setfilter @TraceID, 3, 0, 0, @intfilter

set @bigintfilter = 1
exec sp_trace_setfilter @TraceID, 13, 0, 4, @bigintfilter

-- Set the trace status to start
exec sp_trace_setstatus @TraceID, 1


SELECT *
FROM   sys.traces;

Осталось запустить трассировку в пик нагрузки и подождать полчаса.

Расшифровка трассировки

Поместим данные расшифровки в таблицу SQL. Я использую отдельную вспомогательную базу.

USE [ExchangeDB]

CREATE TABLE TraceResults (
 EventClass VARCHAR(100),
 TextData VARCHAR(4000),
 PlanXML XML,
 Duration INT,
 RowCounts INT,
 Reads INT,
 Writes INT,
 CPU INT,
 StartTime DATETIME,
 ProcedureName VARCHAR(100),
 EventSequence INT
)
GO

DECLARE @FileName NVARCHAR(256) 
SET @FileName = 'E:\MSSQL_Trace\20140922101559.trc'
 
INSERT INTO TraceResults
	(EventClass, TextData, Duration, Reads, RowCounts, Writes, CPU, StartTime, EventSequence)
SELECT EventClass, Convert(VARCHAR(4000),TextData) as TextData, 
	Duration, RowCounts, Reads, Writes, CPU, StartTime, EventSequence
FROM fn_trace_gettable(@FileName,1)
WHERE EventClass 146

UPDATE TraceResults
	SET ProcedureName =
	Convert(VARCHAR(100),TextData)
WHERE ProcedureName is NULL

INSERT INTO TraceResults
	(EventClass, PlanXML, EventSequence)
SELECT EventClass, 
	Convert(XML,TextData) as PlanXML,
	EventSequence
FROM fn_trace_gettable(@FileName,1)
WHERE EventClass = 146

Теперь осталось сформировать несколько запросов к нашей таблице для анализа результатов трассировки. Простые запросы приводить не буду, покажу лишь два примера. Первый отбирает запросы по длительности в порядке убывания:

SELECT        
	 TR1.EventSequence
	,TR2.EventSequence
	,TR1.TextData
	,TR2.PlanXML
	,TR1.Duration AS Duration
	,TR1.Reads
	,TR1.Writes
	,TR1.CPU
	,TR1.StartTime
FROM  dbo.TraceResults AS TR1 
     LEFT OUTER JOIN
        dbo.TraceResults AS TR2 
		ON TR1.EventSequence-1 = TR2.EventSequence

WHERE (TR1.TextData IS NOT NULL 
      AND TR2.PlanXML IS NOT NULL)

ORDER BY Duration Desc

Второй группирует по полю ProcedureName и суммирует данные по показателям

USE [ExchangeDB]


SELECT
	 TR1.EventSequence
	,TR2.EventSequence 
	,TR1.ProcedureName
	,TR2.PlanXML 
	,TR1.DurationTot
	,TR1.RowCountsTot
	,TR1.ReadsTot
	,TR1.WritesTot
	,TR1.CPUTot
FROM
(   SELECT 
	   ProcedureName 
	  ,MAX(EventSequence) AS EventSequence
         ,SUM(Duration) as DurationTot
         ,SUM(Reads) as ReadsTot
	  ,SUM(RowCounts) as RowCountsTot
         ,SUM(Writes) as WritesTot
         ,SUM(CPU) as CPUTot
   FROM TraceResults 
   GROUP BY ProcedureName) TR1
LEFT OUTER JOIN
			dbo.TraceResults AS TR2 
			ON TR1.EventSequence-1 = TR2.EventSequence
WHERE (TR1.ProcedureName IS NOT NULL 
      AND TR2.PlanXML IS NOT NULL)

ORDER BY DurationTot DESC

В нашем случае, по итогам двух запросов, лидирует вставка во временную таблицу #tt14 PlanXML из первой строчки:

В итоге мы имеем данные, с которыми можно дальше работать. В частности, на рисунке выше предлагается добавить индексы.