Заметки Дмитрия Пилюгина о Microsoft SQL Server 

Twitter RSS
Home SQL Server (все заметки) Вариант использования процедур sp_trace_XXX для долгосрочной трассировки
formats

Вариант использования процедур sp_trace_XXX для долгосрочной трассировки

monitoring with sp_traceНеобходимость трассировки возникла после жалоб пользователей одного из офисов нашей компании на «внезапно появляющиеся» и столь же «внезапно исчезающие тормоза». Были исследованы планы предположительно «тормозящих» запросов, блокировки, счетчики сервера, канал связи, но явных проблем нигде не обнаружилось. По этому возникла резонная мысль посмотреть, а что происходит на сервере в этот момент, и главное когда именно (точное время) этот момент наступает и когда заканчивается. Для этих целей как раз и используется трассировка.

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

Почему для долгосрочной трассировки не подходит Profiler

Самая очевидная и первая мысль — использовать для трассировки  SQL Server Profiler, к тому же  Profiler умеет писать трассу сразу в таблицу, что может быть удобным для последующего анализа.  Profiler — отличная утилита и лично я, пользуюсь им постоянно для разных нужд, но в основном это оперативные нужды, ненадолго открыть, что-то посмотреть и закрыть. Но в данном случае такой подход не очень подходил, т.к. трассу нужно снимать постоянно, и держать у себя на машине постоянно открытый работающий  Profiler — не очень хорошо.

Вот что по этому поводу пишет Кен Хендерсон в своей книге «Профессиональное руководство по SQL Server хранимые процедуры, XML»:

Все это касается 2000 сервера и утилиты Sql Profiler 8.0. Мне стало интересно, как обстоят дела в SQL Server Profiler 10.0 и как он осуществляет запись в таблицу. Для исследование профайлера возьмем…профайлер =). Точнее два профайлера, первый будет регистрировать действия второго, второй — будет писать в таблицу.
В качестве сервера для теста, я использую sql server express на своей машине, версии
Microsoft SQL Server 2005 — 9.00.3042.00 (Intel X86) Feb 9 2007 22:47:07 Copyright (c) 1988-2005 Microsoft Corporation Express Edition on Windows NT 5.1 (Build 2600: Service Pack 3)
Обычно в боевых условиях профайлер запускается на локальной машине и по сети соединяется с сервером, по этому для чистоты эксперимента (чтобы взаимодействие осуществлялось посредством TCP а не посредством Shared memory), подключимся к своему локальному серверу по ip адресу. Если требуется, необходимо предварительно включить протокол TCP в Configuration Manager, который по умолчанию отключен для Express Edition.
Текущие соединения, впринципе, можно мониторить при помощи того же профайлера, но я решил, что буду смотреть соединения в Sql Server Management Studio (SSMS), при помощи exec sp_who2.
Пока все, что мы там видим, это:

SPID Status Login HostName BlkBy DBName Command CPUTime DiskIO LastBatch ProgramName
51 RUNNABLE dpi PILUGIN1 . master SELECT INTO 375 248 12/08 14:23:44 Microsoft SQL Server Management Studio — Query
52 sleeping dpi PILUGIN1 . master AWAITING COMMAND 63 193 12/08 14:23:32 Microsoft SQL Server Management Studio

Т.е. подключена только сама SSMS (есть еще внутренние подключения но я их опустил, чтобы не загромождать пост уж совсем окончательно =) ).

Итак, запускаем первый профайлер.
В открывшемся окне свойства трассировки, переходим на вкладку Events Selection. В событиях трассировки, выбираем события RPC:Completed и SQL: BatchComplited. Выберем колонки TextData, ApplicationName, SPID.
Далее кнопка Column FIlter, фильтр ApplicationName. Скопируем оттуда из атрибута Not Like значение, это название текущего инстанса профайлера.
У меня это SQL Server Profiler — c54ef85b-2631-4592-bd25-3eaf856cb1a9.
Посмотрим, что сейчас вернет exec sp_who2.

SPID Status Login HostName BlkBy DBName Command CPUTime DiskIO LastBatch ProgramName
51 RUNNABLE dpi PILUGIN1 . master SELECT INTO 391 250 12/08 14:30:05 Microsoft SQL Server Management Studio — Query
52 sleeping dpi PILUGIN1 . master AWAITING COMMAND 63 193 12/08 14:23:32 Microsoft SQL Server Management Studio
53 sleeping dpi PILUGIN1 . Test1 AWAITING COMMAND 0 0 12/08 14:06:27 SQL Server Profiler — c54ef85b-2631-4592-bd25-3eaf856cb1a9

Видим, что теперь у сервера есть еще одно подключение, от профайлера c54ef85b-2631-4592-bd25-3eaf856cb1a9, как и ожидалось.
Запускаем трассировку.

Теперь запустим второй профайлер. Выберем событие SQL:BatchComplited, с такими же колонками TextData, ApplicationName, SPID. Из фильтров копируем значение инстанса этого профайлера, у меня это SQL Server Profiler — f954baed-324c-4352-9b7f-7e6869f0518e.
В тот же фильтр добавим значение SQL Server Profiler — c54ef85b-2631-4592-bd25-3eaf856cb1a9 (чтобы этот профайлер не логировал первый).

Посмотрим текущие подключения:

SPID Status Login HostName BlkBy DBName Command CPUTime DiskIO LastBatch ProgramName
51 RUNNABLE dpi PILUGIN1 . master SELECT INTO 391 250 12/08 14:35:06 Microsoft SQL Server Management Studio — Query
52 sleeping dpi PILUGIN1 . master AWAITING COMMAND 63 193 12/08 14:23:32 Microsoft SQL Server Management Studio
53 SUSPENDED dpi PILUGIN1 . Test1 SELECT 0 0 12/08 14:38:43 SQL Server Profiler — c54ef85b-2631-4592-bd25-3eaf856cb1a9
54 sleeping dpi PILUGIN1 . Test1 AWAITING COMMAND 0 0 12/08 14:38:59 SQL Server Profiler — f954baed-324c-4352-9b7f-7e6869f0518e

Все ок, у нас появилось еще одно соединение, на этот раз с профайлером f954baed-324c-4352-9b7f-7e6869f0518e.
А теперь, вернемся на вкладку General и поставим галочку Save to table. Видим, что профайлер запросил параметры для еще одного подключения.
Подключимся и выберем базу и таблицу (если ее нет, она будет создана), в которую будет писаться трасса. У меня это [Test1].[dbo].[tracelog].
Запустим трассировку и посмотрим что с подключениями.

SPID Status Login HostName BlkBy DBName Command CPUTime DiskIO LastBatch ProgramName
51 RUNNABLE dpi PILUGIN1 . master SELECT INTO 517 250 12/08 15:06:01 Microsoft SQL Server Management Studio — Query
52 sleeping dpi PILUGIN1 . master AWAITING COMMAND 95 202 12/08 15:01:47 Microsoft SQL Server Management Studio
53 SUSPENDED dpi PILUGIN1 . Test1 SELECT 15 0 12/08 15:04:07 SQL Server Profiler — c54ef85b-2631-4592-bd25-3eaf856cb1a9
54 SUSPENDED dpi PILUGIN1 . Test1 SELECT 0 0 12/08 15:05:46 SQL Server Profiler — f954baed-324c-4352-9b7f-7e6869f0518e
55 sleeping dpi PILUGIN1 . Test1 AWAITING COMMAND 0 7 12/08 15:06:01 SQL Server Profiler — f954baed-324c-4352-9b7f-7e6869f0518e

Мы видим, что есть два подключения, от одного и того же инстанса профайлера SQL Server Profiler — f954baed-324c-4352-9b7f-7e6869f0518e.
Ту же картину, можно наблюдать внешней утилитой TCPView (можно бесплатно скачать с сайта sysinternals.com).

Видно что профайлер с ид процесса 1232 — имеет одно соединение, а с ид процесса 6220 — два.

Итак, дополнительное соединение все же открывается. Я не вижу в этом ничего криминального, просто такой факт наличествует, профайлер открывает соединение для записи в таблицу.
Посмотрим, что в нем происходит, для этого, обратимся к первому профайлеру (c54ef85b-2631-4592-bd25-3eaf856cb1a9), на котором у нас все это время работала трассировка, и посмотрим, что он зафиксировал.
Вот что мы видим.

declare @p1 int
set @p1=3
exec sp_trace_create @p1 output,1,NULL,NULL,NULL
select @p1
go
exec sp_trace_setevent 3,12,1,1
go
exec sp_trace_setevent 3,12,10,1
go
exec sp_trace_setevent 3,12,12,1
go
exec sp_trace_setfilter 3,10,0,7,N'SQL Server Profiler - f954baed-324c-4352-9b7f-7e6869f0518e'
go
exec sp_trace_setfilter 3,10,0,7,N'SQL Server Profiler - c54ef85b-2631-4592-bd25-3eaf856cb1a9'
go
exec sp_trace_setstatus 3,1
go
select * from [dbo].[tracelog]
go
DROP TABLE [dbo].[tracelog]
go
CREATE TABLE [dbo].[tracelog] ([RowNumber] int IDENTITY(0,1) PRIMARY KEY, [EventClass] int NULL,[TextData] ntext NULL,[ApplicationName] nvarchar(128) NULL,[SPID] int NULL,[BinaryData] image NULL)
go
declare @p1 int
set @p1=180150003
declare @p3 int
set @p3=2
declare @p4 int
set @p4=4
declare @p5 int
set @p5=-1
exec sp_cursoropen @p1 output,N'select * from [dbo].[tracelog]',@p3 output,@p4 output,@p5 output
select @p1, @p3, @p4, @p5
go
exec sp_cursor 180150003,4,0,N'[dbo].[tracelog]',@EventClass=65528,@TextData=NULL,@ApplicationName=NULL,@SPID=NULL,@BinaryData=0xFFFE...00
go
exec sp_cursor 180150003,4,0,N'[dbo].[tracelog]',@EventClass=65534,@TextData=NULL,@ApplicationName=NULL,@SPID=NULL,@BinaryData=NULL
go

То есть, мы видим, что профайлер, в одном соединении (spid 54) создает трассировку, устанавливает ее параметры, фильтры и т.д. В другом соединении (spid 55) создает таблицу, открывает курсор, и осуществляет запись, полученной трассировочной информации в таблицу посредством курсора.
Конечно, и в этом нет ничего криминального (хотя когда я слышу «курсор», применительно к sql server, мне становится как то неуютно =) ).

Подведем итог.
Скажу сразу я лично, не был свидетелем того как профайлер при длительной работе «подвесил» бы sql server и таких экспериментов не ставил.
Но факты:

  1. постоянно открытое дополнительное соединение
  2. Накладные расходы на передачу данных. схема при которой данные передаются по сети сначала на машину с профайлером, тут записываются в параметры для вызова sp_cursor, и собственно передаются обратно на сервер для записи.
  3. Постоянно открытый курсор, через который осуществляется запись.
  4. Постоянно висящий открытый профайлер, в котором, к тому же идет он-лайн отображение того, что происходит на сервере, и вывод всех строк на экран (что тоже требует ресурсов локальной машины).
  5. Предостережения умных людей =)

— заставляют отказаться от использования схемы Profiler Таблица для долгосрочного мониторинга и логирования действий.
К тому же есть замечательная альтернатива в виде процедур семейства sp_trace.

Процедуры sp_trace

Хранимые процедуры,  которые начинаются с префикса  sp_trace, служат в sql server-е для управления трассировкой. Они вовсе не такие сложные как может показаться на первый взгляд. Кстати, тот же самый профайлер, для создания трассировки, использует эти же функции. Мы это уже видели в предыдущем листинге.
Подробно и академически описывать каждую не имеет смысла, т.к. они все хорошо описаны в документации, по этому я их только перечислю и дам краткое описание, после этого сразу перейдем к практике.

sp_trace_create — создает трассировку (после создания трассировка находится в приостановленном состоянии).
sp_trace_setevent — устанавливает события и колонки, по которым ведется трассировка.
sp_trace_setstatus — устанавливает статус трассировки (0 — Останавливает указанную трассировку, 1 — Начинает указанную трассировку, 2 — Закрывает указанную трассировку и удаляет ее определение из сервера)
fn_trace_getinfo — получает в зависимости от параметров сведения об одной или всех трассировках.
fn_trace_gettable — получает непосредственно сами данные трассировки, из трассировочного файла.

Некоторые полезные представления, которые появились с 2005 версией:
sys.traces — выводит все текущие запущенные трассировки, используется для замены fn_trace_getinfo.
sys.trace_categories — выводит категории событий.
sys.trace_events — выводит события трассировки, в привязке к категории.
sys.trace_columns — выводит информацию о колонках трассировки, их название, размер тип.

Стратегия использования.

Параметры создания трассировки.
Создавая трассировку, вы можете указывать максимальный размер файла трассировки (по умолчанию 5 Мб), количество файлов трассировки (должно быть больше 1), и различные опции трассировки.
В их числе опция TRACE_FILE_ROLLOVER, она определяет будет ли создаваться новый файл трассировки, в том случае если размер файла достигнет значения, определенного параметром «максимальный размер файла».
Более подробно об этом можно почитать в документации. То, что наиболее важно для нас, это возможность варьировать параметры максимальный размер файла и кол-во файлов, при заданной опции TRACE_FILE_ROLLOVER.
Что это дает, объясню на примере.

Например, мы задаем имя файла трассировки MYTRACE.trc, устанавливаем опцию TRACE_FILE_ROLLOVER, задаем кол-во файлов равное 10, максимальный размер 1 мб. Это значит, что будет создан файл MYTRACE.trc, в него будут записываться данные трассировки, когда файл достигнет 1 Мб, будет создан новый файл, который получит название MYTRACE_1.trc (название файлов сервер формирует автоматически), после его заполнения, создастся новый файл MYTRACE_2.trc и т.д. до тех пор пока кол-во файлов не станет равным 10 (т.е. равным тому кол-ву, которое мы задали параметром «кол-во файлов»). Что произойдет после этого? после этого, самый старый файл MYTRACE.trc удалится, и вместо него будет создан новый файл MYTRACE_10.trc, потом удалится файл MYTRACE_1.trc, вместо него запишется файл MYTRACE_11.trc и т.д. по циклу, сервер удаляет старые файлы, замещая их новыми, увеличивая счетчик названий.

Возникает резонный вопрос, зачем эта возня с файлами, почему бы не писать все в один большой файл. Дело в том что в функции получения информации из файла, можно указывать начальный файл, и кол-во файлов, которое мы желаем прочитать. Если у нас будет один большой файл, то, чтобы получить последние изменения, каждый раз придется читать его целиком, что со временем будет приводить все к бОльшим потерям времени.
Как выбирать критерии размер/количество файлов? Каждый выбирает исходя из своих нужд, по принципу насколько быстро у него заполняются файлы и с какой глубиной он хочет хранить историю. Быстрота заполнения файлов зависит от количества выбранных событий (насколько подробны вы делаете трассировку), интенсивности возникновения этих событий на сервере (нагрузки на сервер). Я для себя эмпирически определил, что в часы пик высокой нагрузки 5 мб заполняются примерно за 30 минут, в часы простоя около 2 часов. В среднем в день на этом сервере заполняется примерно 10 файлов. Количество дней, которое я хочу хранить в истории примерно 2 дня. Т.е. образуется окно в 20 файлов.
Вот код процедуры, которая могла бы запускать подобную трассировку.

Spoiler for Trace_start

CREATE procedure [dbo].[Trace_start]
as
set nocount on;
--================================================================================================
-- 1. Создаем трассировку

-- опции трассировки
declare @TRACE_FILE_ROLLOVER int
select @TRACE_FILE_ROLLOVER = 2 -- Указывает, что при достижении размера аргумента max_file_size текущий трассировочный файл закрывается и создается новый.

-- параметры трассировки
declare
	@TraceID int, -- ид трассировки
	@Options int, -- опции трассировки
	@TraceFile nvarchar(245), -- файл трасссировки
	@MaxFileSizeInMB bigint, -- макс.размер файла в мб
	@StopTime datetime, -- время останвки трассировки
	@RollOverFileCount int -- кол.во автоматически создаваемых файлов трассировки

-- результат трассировки
declare @RC int

-- установим параемтры
select
	@TraceID = NULL,
	@Options = @TRACE_FILE_ROLLOVER,
	@TraceFile = N'E:\SQLTrace\MyDataBaseTrace',
	@MaxFileSizeInMB = 5,
	@StopTime = NULL, -- время остановки не задано
	@RollOverFileCount = 20 -- 20 файлов

-- создаем саму трассировку (после создания трассировка в приостановленном состоянии)
exec @RC = sp_trace_create @TraceID output, @Options, @TraceFile, @MaxFileSizeInMB, @StopTime, @RollOverFileCount
select RC = @RC, TraceID = @TraceID
if @@error <> 0 return

--================================================================================================
-- 2. Устанавливаем события
declare @RPC_Completed int, @On bit
select @RPC_Completed = 10, @On = 1

exec sp_trace_setevent @TraceID, @RPC_Completed, 15, @On -- EndTime (Время окончания события.)
exec sp_trace_setevent @TraceID, @RPC_Completed, 31, @On -- Error (Номер ошибки.)
exec sp_trace_setevent @TraceID, @RPC_Completed, 16, @On -- Reads (Число логических чтений диска, выполненное сервером для данного события.)
exec sp_trace_setevent @TraceID, @RPC_Completed, 48, @On -- RowCounts (Количество строк в пакете.)
exec sp_trace_setevent @TraceID, @RPC_Completed, 1, @On -- TextData (Текстовое значение, зависящее от класса событий, фиксируемых при трассировке.)
exec sp_trace_setevent @TraceID, @RPC_Completed, 9, @On -- ClientProcessID (Идентификатор, присвоенный клиентским компьютером процессу, в котором работает клиентское приложение.)
exec sp_trace_setevent @TraceID, @RPC_Completed, 17, @On -- Writes (Число логических обращений к дискам на запись, выполненное сервером для данного события.)
exec sp_trace_setevent @TraceID, @RPC_Completed, 49, @On -- RequestID (Идентификатор запроса, содержащего инструкцию.)
exec sp_trace_setevent @TraceID, @RPC_Completed, 2, @On -- BinaryData (Значение типа Binary, зависящее от класса событий, фиксируемых при трассировке.)
exec sp_trace_setevent @TraceID, @RPC_Completed, 18, @On -- CPU (Объем времени ЦП (в миллисекундах), использованного событием.)
exec sp_trace_setevent @TraceID, @RPC_Completed, 34, @On -- ObjectName (Имя объекта, к которому выполняется доступ.)
exec sp_trace_setevent @TraceID, @RPC_Completed, 51, @On -- EventSequence (Порядковый номер этого события.)
exec sp_trace_setevent @TraceID, @RPC_Completed, 12, @On -- SPID (Идентификатор процесса сервера, который SQL Server присвоил процессу, связанному с клиентом.)
exec sp_trace_setevent @TraceID, @RPC_Completed, 13, @On -- Duration (Длительность события (в микросекундах). Этот столбец данных не заполняется событием Hash Warning.)
exec sp_trace_setevent @TraceID, @RPC_Completed, 14, @On -- StartTime (Время начала события, если оно доступно.)
if @@error <> 0 return

--================================================================================================
-- 3. Устанавливаем фильтры
declare @dur_limit bigint
set @dur_limit = 0
exec sp_trace_setfilter @TraceID,35,0,6,N'MyDataBase' -- фильтр: DB like MyDataBase
exec sp_trace_setfilter @TraceID,13,0,1, @dur_limit -- исключаем все с нулевой продолжительностью
if @@error <> 0 return

--================================================================================================
-- 4. Запускаем на выполнение

-- статус трассирвоки
declare @Status int

-- 0 - Останавливает указанную трассировку.
-- 1 - Начинает указанную трассировку.
-- 2 - Закрывает указанную трассировку и удаляет ее определение из сервера.
set @Status = 1

exec sp_trace_setstatus @TraceID, @Status
if @@error <> 0 return

Посмотреть запущенные трассировки можно сделав запрос к представлению sys.traces.
Кстати, в списке активных трассировок вы можете увидеть трассировку с примерно таким файлом «C:\Program Files\Microsoft SQL Server\MSSQL.1\MSSQL\LOG\log_74.trc». Это трассировка по-умолчанию, которую ведет сервер в помощь dba для поиска и устранения неисправностей. Управлять ее включением и отключением можно при помощи параметра default trace enabled.

Загрузка в таблицу.

Трассировочные файлы это конечно хорошо, к их содержимому можно получить доступ функцией fn_trace_gettable, но хотелось бы иметь данные сразу в табличном виде.
Для этого я:
— создал таблицу в которой будут храниться данные трассировки;
— создал таблицу логирования фактов загрузки файлов трассировки в таблицу;
— написал относительно простую процедуру, которая загружает данные в таблицу из файла;
— зарядил эту процедуру в job по расписанию.

Процедура выполняет следующие действия. Получает имя текущего загружаемого файла, получает из таблицы предыдущих загрузок имя предыдущего загруженного файла, вычленяет из каждого номера, берет их разницу, и если таковая есть — формирует название файла, который необходимо загрузить и отдает его в функцию fn_trace_gettable, при помощи которой происходит загрузка.
Идея процедуры понятна, код тоже не сложный. Привожу его набросок.

Spoiler for Trace_populate_into_table

CREATE procedure [dbo].[Trace_populate_into_table]
as

declare @TraceID int
declare
	@TraceFilePathTemplate nvarchar(245),
	@CurrentTraceFile nvarchar(245),
	@PreviousTraceFile nvarchar(245)

set @TraceFilePathTemplate = 'E:\SQLTrace\MyDataBaseTrace'

-- получим ИД трассировки, и текущий файл, в который пишется трассировка
-- тоже самое, но чуть видоизмненным запросом можно получить и из sys.traces,
-- который рекомендуется вместо "утратившей доверие" fn_trace_getinfo =)
select
	@TraceID = TraceID,
	@CurrentTraceFile = convert(nvarchar(245), value)
from
	fn_trace_getinfo(default) ti
where
	ti.property = 2 and
	convert(nvarchar(245), value) like @TraceFilePathTemplate '%'

-- выберем файл, который был загружен ранее в таблицу данных трассировки
select top 1
	@PreviousTraceFile = TraceFile
from
	dbo.TraceTable
order by
	RowNumber desc
-- если таблица пустая, установим начальное название
if @PreviousTraceFile is null set @PreviousTraceFile = @TraceFilePathTemplate '.trc'

-- текущий загружаемый номер файла, и номер файла последней загрузки
declare
	@CurrentTraceFileNum int,
	@PreviousTraceFileNum int

declare @covert_buf nvarchar(245)

-- вычленяем номер из названия файла
set @covert_buf = null
set @covert_buf = replace(@CurrentTraceFile, @TraceFilePathTemplate, '')
set @covert_buf = replace(@covert_buf, '_', '')
set @covert_buf = replace(@covert_buf, '.trc', '')
if @covert_buf is null set @covert_buf = 0
set @CurrentTraceFileNum = convert(int, @covert_buf)

set @covert_buf = null
set @covert_buf = replace(@PreviousTraceFile, @TraceFilePathTemplate, '')
set @covert_buf = replace(@covert_buf, '_', '')
set @covert_buf = replace(@covert_buf, '.trc', '')
if @covert_buf is null set @covert_buf = 0
set @PreviousTraceFileNum = convert(int, @covert_buf)

-- если разница равна 0, то значит загруженный ранее файл текущим, в который пишется трассировка
-- значит загружать его нельзя (маловероятная ситуация)
-- если разница равна 1, то значит что предыдущий файл был загружен, а текущий имеет версию больше на 1,
-- т.е. является следующим и в него в данный момент пишется трассировка,
-- а значит пока он не будет полностью записан, загружать его - нельзя (штатная ситуация)
if @CurrentTraceFileNum - @PreviousTraceFileNum < 2 return

declare @TraceFileForSelect nvarchar(245)

-- читаем по-файлово и записываем в таблицу
declare @row_count int
declare @i int
set @i = @PreviousTraceFileNum   1
while @i < @CurrentTraceFileNum begin

	set @row_count = 0

	if @i = 0
		set @TraceFileForSelect = @TraceFilePathTemplate   '.trc'
	else
		set @TraceFileForSelect = @TraceFilePathTemplate   '_'   convert(varchar(10),@i)   '.trc'

	begin try

		insert into [dbo].[TraceTable](
			[TextData]
		  ,[BinaryData]
		  ,[SPID]
		  ,[Duration]
		  ,[StartTime]
		  ,[EndTime]
		  ,[Reads]
		  ,[Writes]
		  ,[CPU]
		  ,[EventClass]
		  ,[Error]
		  ,[ObjectName]
		  ,[RowCounts]
		  ,[RequestID]
		  ,[EventSequence]
		  ,[TraceFile]
		)
		select
			convert(varchar(max),ft.[TextData]),
			ft.[BinaryData],
			ft.[SPID],
			ft.[Duration],
			ft.[StartTime],
			ft.[EndTime],
			ft.[Reads],
			ft.[Writes],
			ft.[CPU],
			ft.[EventClass],
			ft.[Error] [int],
			ft.[ObjectName],
			ft.[RowCounts],
			ft.[RequestID],
			ft.[EventSequence],
			@TraceFileForSelect
		from
			fn_trace_gettable(@TraceFileForSelect, 1) ft
		where
			-- несмотря на то что мне ничего неизвестно о том, используются ли индексы внутри функции трэйс-тэйбл,
			-- опытным путем установлено, что выборка по условиям работает довольно быстро
			ft.[ObjectName] is not null and
			ft.[StartTime] is not null and
			ft.[EndTime] is not null

		set @row_count = @@rowcount

		-- логируем факт загрузки файла в отдельную таблицу
		insert into TraceLoadLog([TraceID], [CurrentTraceFile], [PreviousTraceFile], [LoadingTraceFile], [RowCount], [Msg], [Date])
		select @TraceID,  @CurrentTraceFile, @PreviousTraceFile, @TraceFileForSelect, @row_count, 'Добавлено', getdate()

	end try
	begin catch

		-- факт неудачной загрузки тоже логируем
		set @row_count = 0
		insert into TraceLoadLog([TraceID], [CurrentTraceFile], [PreviousTraceFile], [LoadingTraceFile], [RowCount], [Msg], [Date])
		select @TraceID,  @CurrentTraceFile, @PreviousTraceFile, @TraceFileForSelect, @row_count, error_message() , getdate()

		set @i = @i   1
		continue

	end catch

	set @i = @i   1

end

Spoiler for Таблица с данными трассировки

CREATE TABLE [dbo].[TraceTable](
	[RowNumber] [int] IDENTITY(1,1) NOT NULL,
	[TextData] [varchar](max) NULL,
	[BinaryData] [image] NULL,
	[SPID] [int] NULL,
	[Duration] [bigint] NULL,
	[StartTime] [datetime] NOT NULL,
	[EndTime] [datetime] NOT NULL,
	[Reads] [bigint] NULL,
	[Writes] [bigint] NULL,
	[CPU] [int] NULL,
	[EventClass] [int] NULL,
	[Error] [int] NULL,
	[ObjectName] [nvarchar](256) NOT NULL,
	[RowCounts] [bigint] NULL,
	[RequestID] [int] NULL,
	[EventSequence] [bigint] NULL,
	[TraceFile] [nvarchar](245) NOT NULL,
 CONSTRAINT [PK_TraceTable] PRIMARY KEY NONCLUSTERED
(
	[RowNumber] ASC
) ON [PRIMARY]
) ON [PRIMARY] TEXTIMAGE_ON [PRIMARY]

GO

Spoiler for Таблица лог загрузки файлов трассировки

CREATE TABLE [dbo].[TraceLoadLog](
	[LogID] [int] IDENTITY(1,1) NOT NULL,
	[TraceID] [int] NULL,
	[CurrentTraceFile] [nchar](245) NULL,
	[PreviousTraceFile] [nchar](245) NULL,
	[LoadingTraceFile] [nchar](245) NULL,
	[RowCount] [int] NULL,
	[Msg] [varchar](500) NULL,
	[Date] [datetime] NULL,
 CONSTRAINT [PK_TraceLoadLog] PRIMARY KEY CLUSTERED
(
	[LogID] ASC
) ON [PRIMARY]
) ON [PRIMARY]

GO

Частота срабатывания job-а может быть любой, разумно, наверное сделать ее такой, при которой процедура бы загружала 1-2 файла за раз. У меня это примерно раз в час. Еще можно создать второй джоб, в котором производить очистку данных в таблице, т.е. глубиной истории теперь можно управлять непосредственно там, удаляя ненужные старые данные.

На этом собственно все.
В завершении скажу, что проблема, из-за которой появлялись тормоза, оказалась в том, что при мониторинге пропустили один из счетчиков, потом прослеживая по трассе моменты просадки сервера и сопоставляя их с данными счетчиков, удалось выяснить причину. Ей оказалась нехватка оперативной памяти при определенном стечении обстоятельств.
Сейчас когда проблема решена, трассировка тоже работает, ловит долго выполняющиеся запросы, и скидывает их в отдельную таблицу, куда всегда можно заглянуть в поисках горячей десятки «Топ-10 тормознутых запросов» и позаниматься на досуге их оптимизацией =).
Надеюсь, кому-нибудь мой опыт окажется полезным.

 

Добавить комментарий

Ваш e-mail не будет опубликован. Обязательные поля помечены *

Анти-спам: введите результат (цифрами) *