SQL Server и ETW. Ч.2

В предыдущем посте мы разбирали структуру ETW-события и выяснили, что даже в более или менее стандартном по структуре заголовке имеется лишь несколько полей, заполняющихся автоматически, и несколько наборов предопределенных значений для некоторых других полей. Все остальное отдано на откуп провайдерам, в результате чего творится полный бардак. Четких правил, регламентирующих категоризацию событий, в природе нет, и каждый провайдер изгаляется, кто во что горазд. Один может определить одно родовое событие, которое он дальше дробит на таски, опкоды и прочие ключевые слова, повышая уровень детализации события. Другой может не заморачиваться, а просто заводить на каждую деталь по событию. Также возможна масса промежуточных стадий помешательства. Глядя на " SQL Server и ETW. Ч.1"\Рис.9, можно видеть, что ETW-провайдер MSSQLSERVER Trace является сторонником капитального сноса крыши. Загрузим представленный XML в SQL Server:

declare @x xml = (select BulkColumn from openrowset(bulk 'c:\Temp\SqlDataCollector.xml', SINGLE_CLOB) t)

;with xmlnamespaces('https://schemas.microsoft.com/win/2004/08/events/event' as e, 'https://schemas.microsoft.com/win/2004/08/events/trace' as t)

select

x.value('(e:System/e:Provider/@Guid)[1]', 'uniqueidentifier') as ProviderGuid,

x.value('(e:RenderingInfo/t:EventName)[1]', 'nvarchar(255)') as EventName,

x.value('(t:ExtendedTracingInfo/t:EventGuid)[1]', 'uniqueidentifier') as EventGuid

from @x.nodes('Events/e:Event') t(x)

Скрипт 1

image001

Рис.1

чтобы выяснить, а) может ли одному профайлерному событию соответствовать несколько ETWшных и б) чем ProviderGuid отличается от EventGuid'a? Кстати, заодно пример совмещения with xmlnamespaces() и with cte (), которое иногда вызывает затруднения.

...

;with xmlnamespaces('https://schemas.microsoft.com/win/2004/08/events/event' as e, 'https://schemas.microsoft.com/win/2004/08/events/trace' as t),

cte as (

select

x.value('(e:System/e:Provider/@Guid)[1]', 'uniqueidentifier') as ProviderGuid,

x.value('(e:RenderingInfo/t:EventName)[1]', 'nvarchar(255)') as EventName,

x.value('(t:ExtendedTracingInfo/t:EventGuid)[1]', 'uniqueidentifier') as EventGuid

from @x.nodes('Events/e:Event') t(x)

)

select count(distinct ProviderGuid), count(distinct EventGuid), eventname from cte group by eventname

-------------------------

1 1 Audit Login

1 1 Audit Logout

1 1 EventTrace

1 1 RPC:Completed

1 1 SQL:BatchCompleted

Скрипт 2

Видим, что а) по-видимому, не может.

...

select * from cte where ProviderGuid <> EventGuid

----------------

ProviderGuid EventName EventGuid

9E814AAD-3204-11D2-9A82-006008A86939 EventTrace 68FDD900-4A3E-11D1-84F4-0000F80464E3

Скрипт 3

и б) практически, ничем.

Всякий раз специфика области, для которой писан провайдер, и его изрядная степень свободы приводят к тому, что автор провайдера должен добротно документировать изрекаемые им сообщения, иначе в них будет проблематично разобраться. Пример хорошо документированных провайдеров и форматов их сообщений можно, например, наблюдать здесь - .NET Framework 4 CLR ETW Events. В случае MSSQLSERVER Trace благодаря паре несложных запросов и знакомству с SQL Trace структура сообщения приобретает более-менее ясность. Все равно, глядя на Рис.9 в предыдущей серии, задаешься вопросом: какие именно профайлерные события собирает провайдер MSSQLSERVER Trace, неужто все? Какие колонки по каждому событию, тоже все автоматом? Можно ли ставить фильтры на события в зависимости от значения той или иной колонки, как в профайлере? В Books On-Line искать на них ответ, по обыкновению, бестолку. Лучше обратиться к блогу "Tips, Tricks, and Advice from the SQL Server Query Processing Team".

События, информацию по которым MSSQLSERVER Trace засылает в ETW, перечислены в файле %ProgramFiles%\Microsoft SQL Server\MSSQL10.MSSQLSERVER\MSSQL\Binn\etwcnf.xml в шаблонах:

image003

Рис.2

Здесь <Event id=...> - это идентификаторы профайлерных событий. Понять, что какой значит, можно, обратившись к посту "Программно сгенерить трассу профайлера. Ч. 1, 2"\Скрипт 3.

По умолчанию она берет список событий из template c id = 0. Вот эти события:

select * from sys.trace_events where trace_event_id in (10, 12, 14, 15, 17)

----------------------------------

trace_event_id category_id name

10 11 RPC:Completed

12 13 SQL:BatchCompleted

14 8 Audit Login

15 8 Audit Logout

17 10 ExistingConnection

Скрипт 4

Что совпадает со списком событий Скрипт 2, когда трасса была запущена из Reliability and Performance Monitor.

Какие колонки брать по каждому ивенту, оговаривается в файле %ProgramFiles%\Microsoft SQL Server\MSSQL10.MSSQLSERVER\MSSQL\Binn\etwcls.mof:

image005

Рис.3

Как в MSSQLSERVER Trace фильтровать события по типу "Программно сгенерить трассу профайлера. Ч. 1, 2"\(Рис.4 или Скрипт 4), я не нашел. Зато я знаю, как ему подсунуть произвольный шаблон из Рис.2. Создадим в etwcnf.xml еще один шаблон. Этот шаблон будет соостоять из всего одного профайлерного события UserConfigurable:0. UserConfigurable-события хороши тем, что с ними не нужно ждать милостей от природы. Можно их вызывать по своему усмотрению.

...

<Template id="6" Name="New Template">

      <!--82 = UserConfigurable:0 -->

       <Event id="82" />

</Template>

</EventConfiguration>

Скрипт 5

Запускаем ETW-сессию вручную из-за того, что я не знаю, как ей подсунуть параметр -p (или -pf) в случае запуска из-под Reliability and Performance Monitor.

logman start SqlDataCollector -ets -o c:\Temp\SqlDataCollector.etl -p "MSSQLServer Trace" 6 0

Скрипт 7

Параметры логмана можно посмотреть на технете. -ets : создает и стартует сессию event trace session с опциями в командной строке. -о : выходной файл. Несмотря на то, что у коллектора по имени SqlDataCollector, созданного в Reliability and Performance Monitor, выходной файл был прописан - см. предыдущий пост\Рис.7, при ручном запуске она на него не обращает внимания и создает в той директории, откуда был запущен логман, если не указать явно. -p { GUID | provider [( flags [ ,flags ... ])] Level ] | -pf { FileName } : Specifies the providers (trace data collectors) to use for trace data collection... Use the -pf option to list multiple providers. The -pf option identifies the input file containing the provider names. The provider names are enclosed by quotation marks (""), or with GUIDs enclosed by braces, flag masks, and integers (enable level). The flags are either in hexadecimal (OXFFFF) or (flag, flag) format. "MSSQLServer Trace" - это название ETW-провайдера. 6 - id только что созданного темплейта в etwcnf.xml. 0 - запустить.

Если выглянуть из командной строки в Reliability and Performance Monitor, можно заметить, что SqlDataCollector в списке сессий (предыдущий пост\Рис.6) перешел из состояния Stopped в состояние Running.

Чтобы не открывать SSMS, оттуда же из командной строки инициируем событие 82, чтобы MSSQLSERVER Trace его поймал и заслал в ETW:

sqlcmd -S (local) -E -Q "exec sp_trace_generateevent @eventid = 82, @userinfo = N'Пользовательское событие №0', @userdata = 0x12345"

Скрипт 8

Стопим сессию:

logman stop SqlDataCollector -ets

Скрипт 9

Превращаем c:\Temp\SqlDataCollector.etl в читабельный формат - см. предыдущий пост\Рис.9.

image007

Рис.4

 

image009

Рис.5

Мы видим, что, помимо традиционной шапки в виде первого события EventTrace, теперь файл содержит только одно событие, и оно соответствует SQL Trace'ному событию №82. Это действительно результат Скрипта 8, в чем можно убедиться по элементам <EventData>\<TextData> и <BinaryData>.

 

В следующей серии мы напишем своего ETW-провайдера, которого попытаемся поженить с SQL Serverным. Stay tuned.