SQL Server и ETW. Ч.1

Вначале небольшая вводная на тему ETW, чтобы не получилось, как здесь - https://bytes.com/topic/net/answers/405066-what-windows-event-trace-windows-event-tracing.

Классической статьей по ETW служит https://msdn.microsoft.com/ru-ru/magazine/cc163437.aspx.

Event Tracing for Windows (ETW) является базовым унифицированным механизмом трассировки событий в Windows. По сути, ETW - это однонаправленный пакетный ввод/вывод, предназначенный для журналирования. Под журналирование на уровне каждого процессора отводятся буфера, которые скидываются на диск в асинхронном режиме специальным потоком. Эти операции выполняются в режиме ядра, и оттого занимают копейки в сравнении с, допустим, fprintf(). Даже на древних пентиумах ETW с темпом 20 тыс. событий в секунду сажала процессор не более, чем на 5%. Механизм реализован на уровне ядра; использовать его, т.е. производить события и потреблять их могут как драйверы ядра, так и пользовательские приложения. Данные о событии могут иметь какую угодно структуру на усмотрение приложения, его производящего, т.е. это просто блок бинарщины. Однако к нему прикрепляется заголовок со служебной и идентифицирующей информацией, которую мы посмотрим ниже на примере Рис.9.

Провайдер событий - это dll или ехе, которая их производит, - потребитель, соответственно, тот, кто потребляет. Список зарегистрированных провайдеров можно посмотреть при помощи утилиты командной строки logman:

logman -query providers

image001

Рис.1

Либо можно пойти в Administrative Tools \ Reliability and Performance Monitor (или вызвать в команде Run perfmon.msc) и создать новый пользовательский Data Collector Set

 image003 image005

Рис.2

который будет собирать данные из ETW

image007

Рис.3

следующим шагом будет предложено выбрать ETW-провайдера из списка доступных:

image009 image011

Рис.4

Справа высветился тот же список, что и на Рис.1. В списке провайдеров к SQL Server имеют отношение MSSQLSERVER Trace (в случае именованного экземпляра вместо MSSQLSERVER будет стоять имя инстанса - см. пост "Именованый экземпляр по умолчанию"), RsFx0102 Kernel Log (драйвер FileStream), XEvent Package 0 (расширенные события) и др. В данном посте нас будет интересовать первый товарищ. Он просто тупо шлет в ETW все, что происходит в SQL Trace.

Помимо провайдера и потребителя, есть еще контроллер, который управляет этим процессом. Контроллер обращается к ядру с просьбой начать трейс-сессию, создается хэндл (через callback в пользовательском режиме или прерывание в ядерном), контроллер идет к провайдеру и вручает ему этот хэндл. Это называется, он его заенейблил. Чтобы посмотреть активные трейс-сессии, можно написать собственное приложение, а можно это сделать из Reliability and Performance Monitor, выбрав слева Data Collector Sets \ Event Trace Sessions. Можно оттуда же запустить новую сессию. Кликнем правой кнопкой в Event Trace Sessions и выберем New -> Data Collector Set. Откроется диалог создания группы сборщиков податей Рис.2-4. Скажем ей, чтобы результаты своей жизнедеятельности она сохраняла в c:\Temp и чтобы стартовала без проволочек:

image013 image015

Рис.5

У нас появилась новая сессия:

image017

Рис.6

Сразу по открытии сессии провайдер начинает слать события в этот хэндл, а ядро их принимает и рассовывает по буферам. Если буфера заполнились или таймаут проэкспайрился, буфера флушатся в файл .etl, который читает потребитель. Директория для файла задавалась на Рис.5, а имя оговаривается в параметрах трейс-сессии. Там же указываются количество буферов и таймаут. Кликнем два раза по сессии SqlDataCollector:

image019 image021

Рис.7

В принципе, потребителю возможно напрямую цепануться к хэндлу и получать события в реальном времени.

Ну ладно, давайте смотреть, что она насобирала. Остановим сессию SqlDataCollector, выбрав Stop из ее контекстного меню или кликнув на черный квадрат Малевича на Рис.6. Когда контроллер заканчивает сессию, провайдер извещается и прекращает производить события. Файл C:\Temp\SqlDataCollector.etl имеет неудобоваримый формат для чтения. Лучше превратить его во что-нибудь осмысленное, например, csv:

tracerpt -l C:\Temp\SqlDataCollector.etl -of CSV -o C:\Temp\SqlDataCollector.csv

image023

image025

Рис.8

или что-нибудь еще:

tracerpt C:\Temp\SqlDataCollector.etl -lr -o C:\Temp\SqlDataCollector.xml

image027

Рис.9

В элементе <System> находится стандартный заголовок сообщения, структура которого одинакова что для провайдера MSSQLSERVER Trace, что для какого-нибудь еще. Level характеризует строгость и может принимать предопределенные значения 1 - критическое, 2 - ошибка, 3 - предупреждение, 4 - информационное и 5 - подробное. Также ETW-провайдер может определить свои собственные значения до 255. Task и Opcode - категоризация на уровне приложение/метод. Имена туда писать не получится, т.к. под Task выделено два байта, под Opcode - 1. Придется кодировать. Кодировка является усмотрением ETW-провайдера. Предопределенными считаются опкоды 1 - старт и 2 - стоп. Keywords позволяет дальше категоризировать события. Это 56 бит, что может, например, соответствовать маске из 56 категорий событий. В маске взводятся те биты, в какие соответствующие категории попадает событие. Опять-таки категоризация является прерогативой конкретного провайдера. TimeCreated - временная отметка момента происхождения события. Channel используется, в основном, если трасса предназначается для просмотра в Event Viewer; это Application, System и пр., что виднеется в дереве слева под Event Viewer. В элементе <EventData>/<Data> передается полезная нагрузка. Ее структура варьируется в зависимости от провайдера и типа сообщения. В данном случае в ней передается информация о событии SQL Trace. Каждый элемент <DataName> есть, по сути, колонка в профайлере. Само название профайлерного события присутствует в элементе <RenderingInfo>/<EventName>.

ETW существует в Windows, наверное, с версии 2000. Начиная с Висты, поддерживается мультиплексирование, т.е. отношение "многие-ко-многим" между провайдерами и сессиями. Например, этот вывод (Рис.9) можно замикшировать с результатами еще каких-нибудь ETW-провайдеров и получить согласованную по времени целостную картину мира в одном флаконе.