SQL Server и ETW. Ч.3


В конце первой серии говорилось, что, начиная с Висты, в ETW поддерживается мультиплексирование. Это очень позитивное нововведение, которым мы сейчас конкретно займемся. Еще в посте про SQL Profiler я говорил о ценности консолидированной картины мира, когда мы сводили воедино профайлерную трассу с графиками Performance Monitor. Продолжу развивать эту мысль. Ясно, что настройка и отладка сложного многокомпонентного приложения - процесс нетривиальный.  Он становится еще нетривиальней, если каждая компонента пишет информацию о ходе своей работы в собственный журнал, и эти журналы затем приходится состыковывать, чтобы понять последовательность действий в общем масштабе приложения: чем занималась компонента А, вызвавшая компоненту Б, и компонента Б, вызвавшая компоненту В, прежде чем в компоненте В вылезла какая-нибудь бякость. В особенности если учесть, что А, Б, В могли быть разработаны независимо. Йа нопешу афегительно сложное преложенее, которое обращается к SQL Server, и сведу события от них обоих в единую трассу. В сценарии будут участвовать два ETW-провайдера: штатный SQL Serverный MSSQLServer Trace, который мы посмотрели во второй серии, и самопальный, задачей которого является трассировка кастомного клиентского приложения. Благодаря возможности мультиплексирования они будут шарить одну ETWшную сессию. Для начала стоит изобразить кастомный провайдер.


 


Программирование контроллера, провайдера и потребителя описывается в документации MSDN. Как говорилось в одном посте, those whose curiosity has been piqued can jump into the MSDN documentation, which is not very good IMO but better than nothing.


Там описываются примеры с использованием native API. Как говорилось в другом посте, The ETW API has been around for a number of years, so it’s implemented in unmanaged code. As I write this, there are no shipping managed libraries to make working with it simpler. Internally, various groups here are looking at the best way to make ETW a first class citizen in the managed world. Это писалось 5 лет назад, и сейчас в графе .NET-поддержка можно ставить галочку. Не слишком жирную, though. Написание своего провайдера обрисовано в посте .NET Event Tracing for Windows от апреля нынешнего года. В нем предлагается следующая последовательность действий. Во-первых, надлежит создать манифест провайдера в виде XML-документа. Апологеты инволюции к иерархическим БД под названием XML в качестве одного из преимуществ приводят его наглядность по сравнению с проприетарными бинарными форматами и самоописательность. Прекрасно, значит, поглядев примеры в %MSSDK%\Samples\WinBase\Eventing, свой манифест они смогут составить самостоятельно. Для всех остальных в %MSSDK%\bin существует тула ecmangen.exe, способная генерить этот манифест. Не зная, что допускается в узлах по правилам игры, от наглядности XML мало прока. С таким же успехом генератор, в который это знание заложено, мог бы производить манифест в бинарном формате. Без разницы, как воплощать это знание: в виде элементов и атрибутов или побайтно отсчитывая с такой-то позиции по такую-то. Хотя нет, XML занимает больше места.


Во-вторых, на основе манифеста при помощи тулы mc.exe (Message Compiler, также входит в SDK)  приготовляется 4 файла (временный, .bin, .h, .rc), из которых существенным в данном случае является ресурсный. В-третьих, берется rc.exe (Resource Compiler, также должен лежать в C:\Program Files\Microsoft SDKs\Windows\v6.0A\bin), при помощи которого из .rc файла делается ресурс .res. Ресурс затем вставляется в Project Properties вижуал студийного проекта, что образует класс с именем манифеста, используя который в коде, можно инициализировать и отправлять события. Все просто, если не считать, что .NET здесь несколько притянут за уши. Искреннее отношение человека к данному процессу можно почитать здесь.


 


Сергей Мелещук в своем блоге (How to do ETW logging from .NET application) приводит другой способ генерации событий из .NET. Он не рассматривает задачи создать произвольный собственный ETW-провайдер с нуля при помощи манифеста и класса System.Diagnostics.Eventing.EventProvider. В System.Diagnostics имеется класс TraceSource, который позволяет писать из приложения сообщения трассировки в разные места. Место определяется абстрактным классом TraceListener, который в .NET 2.0 воплощался в ConsoleTraceListener - вывод отладочных сообщений в консоль, TextWriterTraceListener - в текстовый файл, XmlWriterTraceListener - в XML, EventLogTraceListener - в журнал Windows. В 3.5 к ним добавился EventProviderTraceListener, направляющий отладочные сообщения в ETW. Добавление такого слушателя автоматически создает новый ETW-провайдер, хотя и не позволяет такой полноты контроля над его обликом, как в первом случае. Я взял за основу пример Сергея и немного его модифицировал применительно к нашему сценарию.


 


Удалим для чистоты эксперимента созданный в первой серии SqlDataCollector:


 


image001



Рис.1


 


Создадим каким-либо способом новый гуид. В моем случае это получился {4E7F098A-3E72-4D5B-9EA3-1B41A83527B0}.



 


image003


Рис.2


 


Создадим текстовый файл c:\Temp\SqlDataCollector.cfg, куда напишем следующие две строчки:


 


"MSSQLServer Trace" 6 0


{4E7F098A-3E72-4D5B-9EA3-1B41A83527B0}


 


image005



Рис.3


 


где вторая есть свежесозданный гуид.


Откроем окно командной строки и вобьем следующую команду. Сейчас поясню, что в ней к чему.


 


logman create trace AppDataCollector -o c:\Temp\SqlDataCollector.etl -pf c:\Temp\SqlDataCollector.cfg -ow --v


Скрипт 1


 


Logman create trace создает новый коллектор данных на основе одного или нескольких провайдеров данных. По условию задачи у нас должно быть два провайдера: MSSQLServer Trace и самопальный, пишущих в один файл. Если создавать два коллектора


 


logman create trace Коллектор1 -o c:\Temp\SqlDataCollector.etl -р Провайдер1


logman start Коллектор1


logman create trace Коллектор2 -o c:\Temp\SqlDataCollector.etl -р Провайдер2


logman start Коллектор2


 


при старте второго возникнет ошибка, что файл занят, следовательно, нужно их сводить в один коллектор. Ключ -р, как можно посмотреть в logman create trace /?, позволяет задать только одного провайдера - A single Event Trace provider to enable. В случае нескольких их нужно прописывать в отдельном файле, который передается в ключе -pf. В нашем случае это c:\Temp\SqlDataCollector.cfg (Рис.3). Первая строчка инициализирует провайдер MSSQLServer Trace. Мы ее уже видели во второй серии (Скрипт 7). Вторая соответствует самопальному провайдеру. С ним дело обстоит чуть хитрее. В примере Сергея используется класс EventProviderTraceListener. Как говорится в документации, конструктор EventProviderTraceListener инициализирует новый экземпляр класса с помощью указанного идентификатора поставщика. Где ж его взять, коли поставщик еще не создан? Команда logman create trace ... -р Провайдер будет ругаться, если ей указать имя несуществующего провайдера. К счастью, если вместо имени подсунуть гуид, она поверит взаймы, что такой есть. Это может быть совершенно произвольный гуид. На рис.3 он передается во второй строчке. Ключ -ow говорит перезаписывать файл c:\Temp\SqlDataCollector.etl, ежели таковой уже имеется. Ключ --v отменяет действие ключа -v, чтобы файл выхлопа был один. Иначе он будет создавать SqlDataCollector_000001.etl, SqlDataCollector_000002.etl и т.д. Пускаем сессию сбора данных для свежесозданного коллектора


 


logman start AppDataCollector


Скрипт 2


 


и выполняем следующее консольное приложение.


 


using System;


using System.Diagnostics;


using System.Diagnostics.Eventing;


using System.Data.SqlClient;


 


class Program


{


    private static Guid etwProviderId = new Guid("{4E7F098A-3E72-4D5B-9EA3-1B41A83527B0}");


    private static string etwProviderName = "AppDataCollector";


 


    static void Main(string[] args)


    {


        EventProviderTraceListener etwListener = new EventProviderTraceListener(etwProviderId.ToString(), etwProviderName);


        TraceSource ts = new TraceSource(etwProviderName, SourceLevels.All);


        ts.Listeners.Clear();


        ts.Listeners.Add(etwListener);


        ts.TraceEvent(TraceEventType.Information | TraceEventType.Start, 0, "Поехали");


        ts.TraceData(TraceEventType.Verbose, 0, String.Format("Здравствуйте. Я - приложение {0}", System.Reflection.Assembly.GetEntryAssembly().Location));


        SqlConnection cnn = new SqlConnection("server=localhost;database=TestFS;trusted_connection=true"); cnn.Open();


        SqlCommand cmd = new SqlCommand("exec sp_trace_generateevent @eventid = 82, @userinfo = N'Пользовательское событие №0', @userdata = 0x12345", cnn);


        ts.TraceData(TraceEventType.Verbose, 0, String.Format("Отправляю на SQL Server команду {0}", cmd.CommandText));


        cmd.ExecuteNonQuery();


        ts.TraceInformation("И смотрю, что из этого получилось");


        cnn.Close(); ts.Close();


    }


}


Скрипт 3


 


Это одновременно будет обращающийся к SQL Server клиент и сам себе режиссер, то есть ETW-провайдер. Все свои действия он протоколирует, посылая их в TraceSource. К любому TraceSource по умолчанию подстегивается консольный слушатель, нам он неинтересен, отсюда ts.Listeners.Clear(). Вместо него добавляется EventProviderTraceListener, отсылающий трассировку ETW-провайдеру, которого он сам же и создает. Единственно, мы говорим, чтобы он создал его с определенным гуидом, тем самым, который нам поверил в долг логман. Обращаю внимание, что это может быть совершенно произвольный гуид, потому что некоторые упорно выбирают {E13C0D23-CCBC-4E12-931B-D9CC2EEE27E4} (провайдер .NET Common Language Runtime). Не буду отвлекаться на рассказ про методы TraceEvent, TraceData и TraceInformation. Можно посмотреть в документации или в совершенно замечательном .NET Instrumentation Workshop. TraceSource отправляет информацию с этих методов привязанным к нему слушателям, то есть в данном случае ETW-провайдеру с гуидом {4E7F098A-3E72-4D5B-9EA3-1B41A83527B0}. Затем на SQL Server отправляется запрос. Это Скрипт 8 из предыдущей серии. Как и в прошлый раз, SQL Server на него реагирует, отправляя событие своему провайдеру MSSQLServer Trace. Оба провайдера: и MSSQLServer Trace, и самопальный {4E7F098A-3E72-4D5B-9EA3-1B41A83527B0}, - завязаны в данном случае на одну сессию:


 


image007



Рис.4


 


которая кидает сообщения в c:\Temp\SqlDataCollector.etl (см. Скрипт 1). Туда же после реакции SQL Server падает заключительное TraceInformation от приложения. В итоге имеем объединенный трейс-лог, что и требовалось продемонстрировать. Останавливаем сессию, конвертируем etl и смотрим:


 


logman stop AppDataCollector


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


Скрипт 4


 


image009



Рис.5


 


image011



Рис.6


Comments (0)

Skip to main content