Как прикрутить трейсинг из браузера в любой проект

Всем привет! Меня зовут Костя, я занимаюсь разработкой Яндекс.Браузера. Недавно у нас в Новосибирском офисе в Академгородке проходила небольшая C++ party, на которой я рассказывал о том, какие инструменты мы применяем при разработке браузера и что можно позаимствовать для других больших проектов, например, про ninja, OWNERS. В ходе разработки мы очень пристально следим за производительностью: загрузка CPU, потребление памяти, время выполнения различных операций и так далее. При этом активно используются различные утилиты, но также и внутренние отладочные инструменты браузера, например, внутренняя страница browser://tracing (для Яндекс.Браузера, chrome://tracing для Chromium и Chrome).Скриншот browser://tracing 44a8e39ad03042399ac0287376136825.png Если коротко, то на этой странице можно проследить длительность выполнения разных функций и количество вызовов в разбивке по процессам, потокам и переданным аргументам. Само собой, в этом нет никакой магии и для того, чтобы это работало, по коду требуется расставить специальные макросы. Как мне кажется, это очень удобный инструмент, который позволяет найти кучу разных проблем. Я считаю, что такой инструмент может оказаться полезным и в других проектах, так что я решил показать как можно его применить.Зачем это нужно? Конечно, для того, чтобы трейсить проекты существуют самые разные инструменты, но у них всех есть огромный минус — их нельзя использовать у конкретного пользователя, хотя это может быть очень важным для понимания и диагностики проблемы. Диагностику, которую собирает браузер на browser://tracing можно собирать в любой момент. Ее можно включать только на определенный период, чтобы повторить баг, а в остальные моменты она не приносит большого оверхеда.Что нам понадобится? В первую очередь, конечно, будут нужны исходники. По большому счету то, что нам нужно находится в папке base/trace_event внутри нее используются в том числе и другие компоненты из подпапки base, например, time, threading, synchronization и т.д. Я решил поступить очень просто и просто слинковаться с base.dll из сборки хромиума. К счастью, репозиторий хромиума у меня есть даже на домашнем компьютере, не говоря уж о рабочих. Для тех, кто хочет пойти таким же путем, тут есть ссылки на инструкции для сборки под разные платформы. Важно: для компонентной сборки нужно установить переменную окружения GYP_DEFINES=«component=shared_library».Во-вторых нам нужны заголовочные файлы, которые можно взять здесь.Как вариант, вместо этих двух пунктов можно сделать проще и добавить файлы из base к себе в проект.Включаем трейсинг и пользуемся Для начала нам нужно включить трейсинг. Для этого требуется создать фильтр категорий, который мы хотим применять. Категория — это идентификатор некоторый группы отслеживаемой операции. Категории нужны, чтобы выбирать какие группы мы хотим отслеживать в данный момент. Затем нужно вызвать метод SetEnabled у синглтона класса TraceLog. const char kCategoryName[] = «my_category»;

void StartTracing () { base: trace_event: CategoryFilter category_filter (kCategoryName); base: trace_event: TraceLog: GetInstance ()→SetEnabled ( category_filter, base: trace_event: TraceLog: RECORDING_MODE, base: trace_event: TraceOptions (base: trace_event: RECORD_UNTIL_FULL)); } Теперь придумаем сложную задачу, время выполнения которой мы хотим отслеживать и добавим в нужных местах макрос TRACE_EVENT. Этот макрос разворачивается в инстанцирование объекта класса ScopedTracer, который, как можно догадаться, отчитается о длительности выполнения в рамках scope. Подробнее можно посмотреть здесь float SomeHardcoreTask (int max_num) { TRACE_EVENT1(kCategoryName, «SomeHardcoreTask», «max_num», max_num); float x = 1.5f; for (int i = 0; i < max_num; ++i) x *= sin(x) / atan(x) * tanh(x) * sqrt(x);

return x; }

void SomeHardcoreAsyncTask ( base: WaitableEvent* event, const base: Callback& out_cb) { TRACE_EVENT0(kCategoryName, «SomeHardcoreAsyncTask»); for (int i: {20000000, 5000000, 80000000}) out_cb.Run (SomeHardcoreTask (i));

event→Signal (); }

void AsyncTaskCb (float x) { }

void DoWork () { TRACE_EVENT0(kCategoryName, «DoWork»); base: Thread thread («HardcoreTaskThread»); thread.Start (); base: WaitableEvent event (false, false); thread.message_loop_proxy ()→PostDelayedTask ( FROM_HERE, base: Bind (&SomeHardcoreAsyncTask, &event, base: Bind (&AsyncTaskCb)), base: TimeDelta: FromSeconds (2));

for (int i: {10000000, 20000000, 50000000}) std: cout << SomeHardcoreTask(i);

event.Wait (); }

Осталась заключительная часть — нужно выключить трейсинг и сохранить результаты на диск. Сразу признаюсь, что в основном код взят отсюда const char kTracingJsonPath[] = «D:\\trace.json»;

// Функция-коллбек, которая принимает построчно результаты трейсинга и пишет их в файл. void WriteTraceDataCollected ( base: File* output_file, const scoped_refptr& events_str, bool has_more_events) { output_file→WriteAtCurrentPos (events_str→data ().c_str (), events_str→data ().length ()); if (has_more_events) output_file→WriteAtCurrentPos (»,», 1); }

// Останавливаем трейсинг и флашим данные на диск. void StopTracingAndFlushToDisk () { base: trace_event: TraceLog: GetInstance ()→SetDisabled (); base: File output (base: FilePath: FromUTF8Unsafe (kTracingJsonPath), base: File: FLAG_CREATE_ALWAYS | base: File: FLAG_WRITE); CHECK (output.IsValid ()); static const char kStart[] = »{\«traceEvents\»:[»; static const char kEnd[] = »]}»; output.WriteAtCurrentPos (kStart, strlen (kStart)); base: trace_event: TraceLog: GetInstance ()→SetDisabled (); base: trace_event: TraceLog: GetInstance ()→Flush ( base: Bind (&WriteTraceDataCollected, &output)); output.WriteAtCurrentPos (kEnd, strlen (kEnd)); output.Close (); } Итак, все необходимое есть, осталось только собрать все в одну кучу.

int main () { StartTracing (); DoWork (); StopTracingAndFlushToDisk (); return 0; }

Весь код вместе #define NOMINMAX

#include

#include #include #include

namespace {

const char kCategoryName[] = «my_category»; const char kTracingJsonPath[] = «D:\\trace.json»;

void WriteTraceDataCollected ( base: File* output_file, const scoped_refptr& events_str, bool has_more_events) { output_file→WriteAtCurrentPos (events_str→data ().c_str (), events_str→data ().length ()); if (has_more_events) output_file→WriteAtCurrentPos (»,», 1); }

void StartTracing () { base: trace_event: CategoryFilter category_filter (kCategoryName); base: trace_event: TraceLog: GetInstance ()→SetEnabled ( category_filter, base: trace_event: TraceLog: RECORDING_MODE, base: trace_event: TraceOptions (base: trace_event: RECORD_UNTIL_FULL)); }

void StopTracingAndFlushToDisk () { base: trace_event: TraceLog: GetInstance ()→SetDisabled (); base: File output (base: FilePath: FromUTF8Unsafe (kTracingJsonPath), base: File: FLAG_CREATE_ALWAYS | base: File: FLAG_WRITE); CHECK (output.IsValid ()); static const char kStart[] = »{\«traceEvents\»:[»; static const char kEnd[] = »]}»; output.WriteAtCurrentPos (kStart, strlen (kStart)); base: trace_event: TraceLog: GetInstance ()→SetDisabled (); base: trace_event: TraceLog: GetInstance ()→Flush ( base: Bind (&WriteTraceDataCollected, &output)); output.WriteAtCurrentPos (kEnd, strlen (kEnd)); output.Close (); }

float SomeHardcoreTask (int max_num) { TRACE_EVENT1(kCategoryName, «SomeHardcoreTask», «max_num», max_num); float x = 1.5f; for (int i = 0; i < max_num; ++i) x *= sin(x) / atan(x) * tanh(x) * sqrt(x);

return x; }

void SomeHardcoreAsyncTask ( base: WaitableEvent* event, const base: Callback& out_cb) { TRACE_EVENT0(kCategoryName, «SomeHardcoreAsyncTask»); for (int i: {20000000, 5000000, 80000000}) out_cb.Run (SomeHardcoreTask (i));

event→Signal (); }

void AsyncTaskCb (float x) { }

void DoWork () { TRACE_EVENT0(kCategoryName, «DoWork»); base: Thread thread («HardcoreTaskThread»); thread.Start (); base: WaitableEvent event (false, false); thread.message_loop_proxy ()→PostDelayedTask ( FROM_HERE, base: Bind (&SomeHardcoreAsyncTask, &event, base: Bind (&AsyncTaskCb)), base: TimeDelta: FromSeconds (2));

for (int i: {10000000, 20000000, 50000000}) std: cout << SomeHardcoreTask(i);

event.Wait (); }

} // namespace

int main () { StartTracing (); DoWork (); StopTracingAndFlushToDisk (); return 0; }

Результат В результате получаем файл trace.json, который можно открыть на browser://tracing и увидеть следующее: 87b02b8316a14100a1e1ff79e9a84800.pngЗаключение Как можно заметить, получилось очень несложно позаимствовать достаточно полезный функционал из хромиума и применить его. Хотелось бы подчеркнуть, что кроме этого в исходниках хромиума очень много интересных подходов и просто-напросто готовых решений, которые так или иначе можно применить у себя в проекте.Если у кого-то есть еще подобные примеры — расскажите о них в комментариях. От себя могу добавить, что, например, в фреймворке распределенных вычислений Яндекса YT используются хромиумовские коллбеки, которые были слегка доработаны напильником. Еще я однажды слышал байку про индусов, которые на базе хромиума сделали клиент для облачного диска, но не могу найти пруфов сейчас.Полезные ссылки https://www.chromium.org/developers/design-documentshttps://code.google.com/p/chromium/codesearch#chromium/src/base/https://www.chromium.org/developers/how-tos/trace-event-profiling-tool

© Habrahabr.ru