EventTrace for Windows. Высокоскоростная передача отладочных сообщений драйвера по сети

Существует разные техники отладки: кто-то зарывается в отладчик, кто-то медитирует, ожидая просветления, кто-то судорожно меняет код в надежде на удачу, но почти ни кто не откажется от файла в котором будет сохранены последние мгновения жизни процесса, что происходило, в каких нитях, на каких ядрах, в какое время. Заботливо и педантично сохраненная отладочная информация может сохранить многие рабочие часы, особенно если речь идет о отладке драйвера и аппаратного обеспечения с которым он работает. Ну, а в случае когда ошибка случайная и воспроизводиться на 1 системе из 20 в течении недели, то без отладочной информации медитация может затянуться.
В данной статье пойдет речь об утилитах ^[1], помогающих в перехвате отладочных сообщений драйверов, работающих на нескольких машинах одновременно и передаче сообщений на сервер для сохранения и анализа.

Предыстория

Технология EventTrace for Windows ^[2] впервые была включена в Windows 2k и с тех пор она была верным спутником всех последующих ОС, постепенно проникая во все большее количество ПО: от драйверов до пользовательских приложений.
Трудно сказать, что это был прорыв, но изюминка у ETW имеется – скорость. Десятки тысяч отладочных сообщений в секунду из глубин драйвера с мизерным влиянием на производительность дает простор для фантазии инженера. А если к этому добавить детальность и точность получаемой информации, то жизнь начинает казаться безоблачной.
Окрыленные этим чувством, мы приступили к внедрению. Трудности начались почти сразу, и имя этим трудностям было — TraceView ^[3]. Данная утилита, предназначенная для получения и просмотра отладочных сообщений, упорно не желала делать то, ради чего создавалась.
Если технология доставки сообщений была проработана достаточно хорошо — ETW с лёгкостью проглатывал десятки тысяч, то вот с получением не заладилось, создавалось впечатление, что TraceView был создан для собственных нужд одиноким инженером в недрах корпорации и по случайности попал в DDK.

Проблема

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

Поиск не дал результатов, ближе всех к требованиям была утилита ETViewer ^[4], но и она не покрывала всех необходимых потребностей, к тому же работа над ней была заброшена и в данный момент список разработчиков пуст ^[5].
Надежды на быстрое решение наших проблем пошли прахом. Чтоб свыкнуться с этим фактом потребовалось время, в течение которого мы все так же использовали TraceView, копили силы и идеи.

Решение

Идея самостоятельной разработки была встречена руководством нашего R&D отдела с пониманием и энтузиазмом, однако после составления списка задач и оценки в попугаях — стало очевидно, что такими свободными ресурсами мы не располагаем. Речь шла приблизительно о 6 человеко-месяцах только для самого базового функционала. А, как известно – аппетит приходит во время еды.
Несмотря на серию «неудач» выбросить и забыть идею я не смог. Так началась череда вечеров длинной почти в год когда, придя с одной работы, я приступал к другой. Как результат этой работы на свет появились следующие приложения и библиотеки (исходные коды распространяются под лицензией Apache 2.0 ^[6]):

• Байкал – серверное приложение-каркас, к которому подключаются модули расширения (провайдеры, хранилища, просмотрщики);
• Ангара – клиентское приложение управляющее сессией ETW, получающее сообщения и переправляющее их Байкалу;
• P7.Trace – C++ библиотека, ответственная за обработку отладочных сообщений разрабатываемого приложения, и передачу их Байкалу. По сути это замена ETW, способная работать и под Windows и под Linux;

В чем изюминка всего этого добра? Как и в случае с ETW — это скорость. Речь идет о миллионах отладочных сообщений в секунду для современных домашних ПК. К примеру: дуэт I7-870 и гигабитной сети способен проглотить более 2 миллионов сообщений формата:

 Trace(“Here is my trace and here are my values: %d %d”, iVal1, iVal2);

Помимо очевидной формат строки и параметров передаются так же следующие данные:

• Уровень «тревожности» (trace, info, warning, error, etc) ;
• Время с точностью до 100 нано секунд;
• Номер процессора, на котором выполнился код;
• ID текущей нити;
• ID модуля;
• Имя функции, файла, номер линии в файле;
• Порядковый номер;
• Информация о процессе (имя, ID, время создания);

На стороне Байкала все это выглядит вот так

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

Ангара

Вот я и добрался в своем повествовании до той его части, ради которой оно и затевалось. В этой главе я расскажу о том, как сконфигурировать и запустить Ангару. Предполагается, что Вы уже знакомы с ETW и Ваш драйвер уже инструментирован подобными сообщениями.

Параметры ETW сессии

Отправной точкой каждой ETW сессии является Control GUID, в одном из Ваших исходных файлов есть похожие строки:

 
//{63423ADB-D156-4281-BA74-8ACAEDDBD810}
#define WPP_CONTROL_GUIDS 
    WPP_DEFINE_CONTROL_GUID(ProviderGuid, (63423ADB, D156, 48d5, B0BC, 8ACAEDDBD810),
    WPP_DEFINE_BIT(DBG_PROVIDER)           /* bit  0 = 0x00000001 */ 
    /* You can have up to 32 defines. If you want more than that,
    you have to provide another trace control GUID */
    )

Нас интересует значение WPP_DEFINE_CONTROL_GUID, которое может быть записано в форме {63423ADB-D156-4281-BA74-8ACAEDDBD810}, запомните его — оно еще понадобиться.

Вторым по важности элементом, который потребуется от Вашего драйвера будет Trace Message Format File (TMF). Файл описывает формат отладочных сообщений, а так же содержит дополнительную информацию о сообщении. Наиболее простой способ получить этот файл – это выполнить следующую команду после успешной сборки вашего драйвера:

Tracepdb.exe -f MyDriver.pdb -o MyTraceMessageFormatFile.tmf

Утилита «Tracepdb.exe» поставляется вместе с DDK, путь по умолчанию следующий: C:WinDDK{Version}toolstracing

Настройки. Провайдер

Итак, мы вооружились Control GUID и TMF файлом – настало время редактировать конфигурационный файл Ангары, называется он незатейливо — «Angara.xml» и находится в той же папке что и исполняемые файлы. Откройте его любым редактором, понимающим UTF-16, и можем приступать к редактированию.

Первая интересующая нас секция посвящена ETW провайдеру:

<Provider TMF="."
          GUID="{63423ADB-D156-48d5-B0BC-8ACAEDDBD810}"
          Level="5"
          Flags="0xFFFFFFFFFFFFFFFF"
          Filter=""
          Platform="X32"
/>

Обязательных параметра всего два:

• TMF – путь к папке с TMF файлами, которые Вы же и сгенерировали;
• GUID – тот самый Control GUID;

Важными, но не обязательными параметрами являются параметры «Flags» и «Level» они позволяют фильтровать нежелательные в данный момент сообщения на стороне драйвера, тем самым снижая нагрузку на ETW и систему в целом.
Остальные опциональные параметры достаточно подробно описаны в документации ^[7], а так же в самом XML файле и приводить их описание здесь излишне.

Настройки. Сеть

Следующая секция посвящена сетевому соединению:

<P7Trace Address="localhost"
         Port="9009"
         Packet="1472"
         Name="MyChannel"
         Verbosity="1"
/>

Обязательный параметр лишь один – Address, в него необходимо вписать IP адрес (IPv4/ IPv6) или символьное имя ПК на котором запущен Байкал. Опциональные параметры подробно описаны в документации ^[8].

Настройки. Уровни

Последняя секция представляет собой карту, по которой происходит преобразование уровня сообщений ETW в уровень сообщений понятный Байкалу:

<Levels>
    <Trace>
        <WPP Text="TRACE_LEVEL_VERBOSE"/>
    </Trace>
    <Debug>
        <WPP Text="TRACE_LEVEL_NONE"/>
    </Debug>
    <Info>
        <WPP Text="TRACE_LEVEL_INFORMATION"/>
    </Info>
    <Warning>
        <WPP Text="TRACE_LEVEL_WARNING"/>
    </Warning>
    <Error>
        <WPP Text="TRACE_LEVEL_ERROR"/>
    </Error>
    <Critical>
        <WPP Text="TRACE_LEVEL_FATAL"/>
        <WPP Text="TRACE_LEVEL_CRITICAL"/>
    </Critical>
</Levels>

Редактировать эту секцию необходимо, только если вы переопределили макросы в исходном коде Вашего драйвера, например вот так:

 
// Define debug levels
#define     NONE      0 //  Tracing is not on
#define     FATAL      1 // Abnormal exit or termination
#define     ERROR      2 // Severe errors that need logging
#define     WARNING    3  // Warnings such as allocation failure
#define     INFO       4  // Includes non-error cases such as Entry-Exit
#define     TRACE      5 // Detailed traces from intermediate steps
#define     LOUD       6  // Detailed trace from every step

В таком случае XML секция примет следующий вид:

<Levels>                                     
    <Trace>                                  
        <WPP Text="LOUD"/>    
    </Trace>                                 
    <Debug>                                  
        <WPP Text="TRACE"/>    
    </Debug>                                 
    <Info>                                   
        <WPP Text="INFO"/>
    </Info>                                  
    <Warning>                                
        <WPP Text="WARNING"/>    
    </Warning>                               
    <Error>                                  
        <WPP Text="ERROR"/>      
    </Error>                                 
    <Critical>                               
        <WPP Text="FATAL"/>      
    </Critical>                              
</Levels>       

Старт

Вот и все, редактирование конфигурационного файла закончено, можно приступать к запуску. В каком порядке Вы будете запускать Байкал и Ангару — не имеет значения, но разумно запустить Байкал первым, чтоб иметь возможность принять все отправленные сообщения, только не забудьте вежливо попросить Ваш межсетевой экран (Firewall) не блокировать трафик между Ангарой и Байкалом.
Запуск Ангары очень прост:

Angara_32.exe Angara.xml
#либо
Angara_64.exe Angara.xml

Пример работы Ангары:

N.B. : На старых ОС (Windows 2k, XP) сессия ETW не может стабильно работать без промежуточного файла, поэтому при запуске Ангары на этих версиях ОС следует помнить, что Ангара попытается создать несколько временных файлов суммарным объемом от 250 Мб до 1 Гб, в случае неудачи – процесс завершится.

Внешний вид

Весь графический интерфейс, а вернее — его отсутствие, можно описать следующей картинкой:

Помимо статической информации о сессии, предоставляются 12 различных счетчиков, достаточно большое и, на данный момент, избыточное кол-во информации. Они были нужны на этапе активной отладки программы и позволяли достаточно точно детектировать проблемное место, сейчас это лишь исторический пережиток, который оставлен с целью технической возможности мониторинга. Счетчики делятся на 3 группы:

• Главная статистика (Angara):
  • Send – количество отправленных сообщений
  • Rejected – суммарное (по всем причинам) количество отклоненных к отправке сообщений
  • Unknown – количество неопознанных сообщений, этот счетчик увеличивается каждый раз когда приходит сообщение описание которого не может быть найдено в TMF файлах. Возможная причина – отсутствие необходимого TMF файла либо TMF файл устарел (не был сгенерирован после компиляции драйвера)
  • TPS – приблизительное количество отсылаемых сообщений в секунду

• Сетевая статистика (P7):
  • Free mem. – процент свободной внутренней памяти.
  • Rej. No connect. — количество отклоненных к отправке сообщений по причине отсутствия соединения с сервером (Байкал)
  • Rej. No Memory — количество отклоненных к отправке сообщений по причине нехватки памяти
  • Rej. Internal — количество отклоненных к отправке сообщений по причине внутренних сбоев

• Статистика ETW:
  • Traces lost – количество потерянных сообщений внутри ETW
  • Buffers lost — количество потерянных буферов внутри ETW
  • RealT. Buf. lost — количество потерянных буферов реального времени внутри ETW
  • Broken Seq. – количество неучтенных потерь ETW, мониторинг происходит исходя из предположения, что номера приходящих сообщений увеличиваются линейно на единицу

Заключение

На этом мое повествование заканчивается, я надеюсь, что представленные здесь утилиты облегчат нелегкую, но творческую жизнь разработчиков драйверов и прикладного ПО.

PS: Сайт ^[1] проекта с исходными кодами и бинарными файлами, а так же англоязычная справка ^[9].
PPS: Baical — это не случайная опечатка.

Автор: Lau

Источник ^[10]