Профилирование: сравниваем инструменты pt-pmp и perf на реальных примерах

Привет, Хабр! В предыдущей статье был разобран первичный анализ работы приложения, какие инструменты стоит использовать для сбора информации и как с этими инструментами работать. Напомню, что речь шла о двух утилитах: poor man’s profile (pt‑pmp), которая позволяет комплексно оценивать работу приложения, отображая off-cpu и on-cpuчасти; и perf, которая обладает высокой точностью и мощной функциональностью в целом. Оба этих инструмента применяются для анализа производительности, так как их комбинация позволяет целиком и со всех сторон осмотреть «пациента».

Однако есть один пункт, который не был раскрыт в прошлой части: использование этих инструментов на настоящих продуктах. Синтетический пример на базе open‑source‑проекта — это хорошо, но будет не лишним показать, какие реальные проблемы были найдены, исправлены и какой прирост производительности удалось в итоге получить. В этой статье мы поговорим о практическом применении pt-pmp и perf, с помощью которых удалось обнаружить места для оптимизации работы программы. Меня по‑прежнему зовут Александр Слепнев, устраивайтесь поудобнее, начинаем!

Использование pt-pmp

Первичный анализ приложения

Основное преимущество pt-pmp по сравнению с perf — возможность отобразить on-cpuи off-cpu-части. И это может быть полезно при анализе многопоточных приложений: оценить взаимодействие потоков между собой, определить, есть ли длительное ожидание в их работе и прочее. В качестве примера рассмотрим проект syslog module, который предназначен для пассивного сбора событий MaxPatrol SIEM и используется для приема сообщений стандарта syslog и их дальнейшей обработки. Не будем сильно погружаться в логику работы с пакетом, нам интересна структура модуля. Он состоит из одного потока‑производителя (producer) и множества потоков‑потребителей (consumers). Когда producer получает на вход пакет, он перемещает его в специальную очередь, откуда consumers вычитывают сообщение и начинают обработку — таким образом ведется параллельная работа над пакетами. Очередь формируется с помощью std::conditional_variable и std::list. Producer‑поток работает следующим образом:

// Через std::conditional_variable проверяем, что в очереди есть место std::unique_lock<std::mutex> notFullLock{m_NotFullMutex}; m_NotFull.wait(notFullLock,     [this] { return m_queue.size() < m_queueSize; } ); notFullLock.unlock();  // Помещаем новое сообщение в очередь {     std::lock_guard<std::mutex> queueLock{m_QueueMutex};     m_queue.emplace_back(std::move(message)); }  // Пробуждаем один поток-consumer для обработки сообщения m_NotEmpty.notify_one();

Теперь посмотрим на код consumers‑потоков:

while (!m_Stopped) {     // Через std::conditional_variable проверяем, что в очереди есть сообщение     std::unique_lock<std::mutex> notEmptyLock{m_NotEmptyMutex};     m_NotEmpty.wait(notEmptyLock,         [this] { return !m_queue.empty(); }     );     notEmptyLock.unlock();      // Вычитываем сообщение из очереди     Message message;     {         std::lock_guard<std::mutex> queueLock{m_QueueMutex};         if (m_queue.empty())             continue;          message = m_queue.front();         m_queue.pop_front();     }      // Пробуждаем другие потоки и начинаем обработку     m_NotFull.notify_one();     message.process(); }

Видно, что потоки могут блокировать друг друга в двух местах:

• проверка std::conditional_variable на пустую (полную) очередь;

• добавление (вычитывание) сообщения из очереди.

При обычной работе модуля такой код может не вызвать проблем, однако если его сильно нагрузить и послать на вход много пакетов, producer или consumers могут перейти в режим ожидания (например, при быстрой обработке сообщений producer не успевает наполнить очередь). Чтобы понять, как ведет себя модуль под нагрузкой, были проведены нагрузочные тесты, в которых использовалось восемь потоков‑потребителей. При помощи pt-pmp удалось построить флеймграф:

Здесь отображена только часть флеймграфа, а именно методы потоков‑потребителей (корневой метод — Workers::ExecuteTask). Видно, что consumers тратят примерно 77% времени на обработку пакета, остальные 23% ждут разблокировку мьютекса, тем самым блокируя работу друг друга. Становится понятно, что для оптимизации работы потребителей необходимо уменьшить время, в течение которого они простаивают, и направить эти ресурсы непосредственно на работу с сообщениями.

Проработка решения проблемы

Эффективный способ ускорить работу потоков в приведенном примере — поменять концепцию std::conditional_variable + std::list и полностью убрать работу с мьютексами. Отличным вариантом кажется lock-free queue — это структура данных, предназначенная для хранения элементов без использования механизмов блокировки. Lock-free queue использует атомарные операции и другие методы синхронизации, которые позволяют нескольким потокам одновременно добавлять и извлекать элементы из очереди без блокировки друг друга (больше подробностей про такие очереди можно прочитать в данной статье).

В случае модуля SysLog очередь должна подходить под следующие требования:

• соответствовать шаблону single producer — many consumers;

• быть ограниченной: нельзя добавить в очередь бесконечное количество сообщений;

• иметь возможность блокировать потоки: если очередь пустая, потоки‑потребители должны вставать в ожидание нового сообщения. Если очередь полная, поток‑производитель должен вставать в ожидание нового места.

Под такое описание подходит concurrentqueue — это реализация lock‑free‑очереди на базе последовательных блоков вместо связанных списков. Она состоит из набора подочередей, по одной для каждого производителя. Когда поток‑потребитель хочет вычитать сообщение из очереди, он проверяет все подочереди, пока не найдет ту, которая не пуста (в нашем случае используется только одна подочередь, так как производитель один). Более подробное описание с деталями реализации и бенчмарками можно посмотреть в статье от автора библиотеки.

После интеграции очереди код потока‑производителя выглядит так:

// Создаем очередь (используем вариант с блокировкой потоков) static constexpr std::size_t EXPLICIT_PRODUCERS_NUMBER = 1; static constexpr std::size_t IMPLICIT_PRODUCERS_NUMBER = 0; static moodycamel::BlockingConcurrentQueue<Message> m_queue{queueSize, EXPLICIT_PRODUCERS_NUMBER, IMPLICIT_PRODUCERS_NUMBER};  // Создаем токен для потока-производителя static moodycamel::ProducerToken token(m_queue);  // Помещаем сообщение в очередь if (!m_queue.try_enqueue(token, std::move(message)))     m_queue.wait_enqueue(token, std::move(message)); 

Изначально используется метод try_enqueue, который помещает сообщение в очередь, если есть место. В случае, если оно отсутствует, вызываем wait_enqueue, который сделает это, когда место будет свободно. На момент написания статьи BlockingConcurrentQueue не содержит этого метода, поэтому я реализовал его следующим образом:

// Отправляем поток «спать», затем пытаемся добавить сообщение в очередь. // Время ожидания увеличивается в два раза с каждой последующей итерацией. inline void wait_enqueue(producer_token_t const& token, T&& item) {     auto sleepTime = 100;      do     {         std::this_thread::sleep_for(std::chrono::nanoseconds(sleepTime));         sleepTime = std::min(sleepTime * 2, 10000000);      } while (!add_item_busy_wait(token, std::move(item))); }  // Пробуем добавить сообщение в очередь. Если места нет, используем spin lock для ожидания // (предполагается, что место в очереди появится быстро и короткой паузы будет достаточно) bool add_item_busy_wait(producer_token_t const& token, T&& item) {     for (auto i = 0; i < 1000; i++)     {         if (try_enqueue(token, std::move(item)))             return true;         _mm_pause();     }      return false; }

Ниже представлен код потока‑потребителя:

static constexpr std::int64_t QUEUE_WAITING_PERIOD_USEC = 100000; // Создаем токен для потока-потребителя thread_local moodycamel::ConsumerToken token(m_queue);  while (!m_Stopped) {    Message message;      if (!m_Tasks.wait_dequeue_timed(token, message, QUEUE_WAITING_PERIOD_USEC))         continue;      message.process(); }

Здесь логика простая: ожидаем сообщение в очереди, вычитываем его и обрабатываем.

Тестирование оптимизации

Теперь посмотрим, как изменились флеймграфы после добавления патча. pt-pmp показал такие результаты:

Видно, что обработка сообщения теперь занимает 97,5% времени, ожидание заметно уменьшилось, на графе не видны мьютекс‑блокировки, так как используется lock-free queue. По сравнению с предыдущей версией модуль SysLog стал работать примерно на 50% быстрее. Ниже представлены результаты сравнения двух версий через MPS (message per second). Красным обозначена версия до оптимизации, синим — после:

Сравнение с perf-флеймграфами

Остается ответить на вопрос: что в данном случае показывает флеймграф на основе perf? Получилось бы найти описанную оптимизацию, если бы использовался только on-cpuпрофилировщик?

Ответ: флеймграфа на базе perf недостаточно. Вот так выглядит работа потребителя с точки зрения perf:

Здесь полностью отсутствуют блокировки, в которых consumer на самом деле проводит довольно много времени. Создается ощущение, что поток только обрабатывает сообщения и практически не находится в ожидании.

Теперь посмотрим на perf‑флеймграф после внедрения lock-free queue:

Картина практически не изменилась, видим 97% полезной работы по сравнению с 95,5%. Можно сделать вывод, что для анализа приложения c точки зрения off-cpu части больше подходит pt-pmp, нежели perf.

Использование perf

Основное преимущество этого профилировщика по сравнению с pt-pmp — более высокая точность измерений, поэтому рассмотрим пример, в котором эта особенность пригодилась. Будем анализировать нормализатор событий (компонент MaxPatrol SIEM), его основная задача — преобразовать все события в один вид, чтобы другие компоненты могли его корректно обработать после.

Проблема изменения регистра

Один из популярных методов, который используется при нормализации, — преобразование строки из uppercase в lowercase. Код базируется на open‑source‑библиотеке ICU:

inline static std::string toLowerIcu(std::string_view src) {     static UErrorCode err = U_ZERO_ERROR;     static const UCaseMap *csm = ucasemap_open(nullptr, U_FOLD_CASE_DEFAULT, &err);     std::string dst(src.size(), char{});      ucasemap_utf8ToLower(csm, dst.data(), static_cast<std::int32_t>(dst.size()),         src.data(), static_cast<std::int32_t>(src.size()), &err);      return dst; }

На perf‑флеймграфе преобразование выглядит следующим образом:

Видно, что оно состоит целиком из ICU‑функции и занимает 1,5–2% от общего времени работы, поэтому здесь есть, что оптимизировать.

Подготовка решения и тестирование

Одна из особенностей нормализатора заключается в том, что он должен корректно обрабатывать как строки формата ASCII, так и более обширный набор строк формата UTF-8 (именно поэтому и используется ICU). Однако этот способ довольно медленный, особенно для ASCII‑строк. Для того чтобы сконвертировать такую строку из верхнего регистра в нижний, достаточно вызвать стандартную функцию tolower, которая работает быстрее. Но перед этим необходимо убедиться, что входная строка соответствует формату ASCII.

Обновленный код конвертации выглядит так:

// Вспомогательная функция для проверки ASCII-строки inline static void isAsciiAndLowercase(std::string_view str,                                         bool &isAscii,                                         bool &needsConvToLower) {     const uint8_t *pos;     size_t len;     uint64_t acc1 = 0;     uint64_t acc2 = 0x2020202020202020UL;           // Предполагается, что входные данные этой функции достаточно короткие,      // то есть сканирование всей строки в векторизуемом цикле должно быть      // быстрее, чем проверка условий внутри циклаь чтобы выйти из него раньше.     //     // Используются следующие предположения:     //     // - у всех символов ASCII (и только у них) старший бит      // (бит // #8) их первого и единственного байта установлен в 0;     //     // - ни для одного символа верхнего регистра ASCII не установлен бит #6      // ('A' - 'Z' кодируются в двоичные значения 0100 0001 - 0101 1010).      // Это означает, что, если бит #6 для всех символов установлен, строка      // гарантированно не будет содержать символов верхнего регистра      // и, следовательно, ее не нужно будет преобразовывать в нижний регистр      // (needsConvToLower == false);     //     // - Наоборот, если все символы в строке меньше 64      // (то есть их бит № 7 очищен), преобразования не требуются;     //     // - если оба условия выше ложные, строка может иметь или не иметь буквы     // верхнего регистра, но функция вернет (needsConvToLower == true),      // то есть ложноположительные срабатывания для этой проверки возможны,      // но не ложноотрицательные.            for (pos = (const uint8_t *)str.data(), len = str.length(); len >= 8;           pos += 8, len -= 8) {         uint64_t val = *(const uint64_t *)pos;         acc1 |= val;         acc2 &= val;     }      uint8_t acc3 = 0x20;     for (; len > 0; pos++, len--) {         acc1 |= *pos;         acc3 &= *pos;     }      isAscii = (acc1 & 0x8080808080808080UL) == 0;     needsConvToLower =         !((acc1 & 0x4040404040404040UL) == 0 ||           ((acc2 & 0x2020202020202020UL) == 0x2020202020202020UL &&             (acc3 & 0x20) == 0x20)); }  // Функция конвертации ASCII-строки  inline static std::string asciiToLower(std::string_view src) {     std::string dst(src.size(), char{});      for (size_t i = 0; i < src.size(); i++) {         dst[i] = ::tolower(src[i]);     }      return dst; }    // Функция преобразования с проверкой ASCII-строки inline static std::string toLowerAscii(std::string_view src) {     bool isAscii;     bool needsConvToLower;      pt::isAsciiAndLowercase(src, isAscii, needsConvToLower);     if (isAscii) {         return needsConvToLower ? asciiToLower(src) : std::string{src};     }      // Вызываем оригинальный метод на базе ICU,      // если строка не подходит под ASCII-формат      return toLowerIcu(src); }

Сравним его производительность на микробенчмарке:

$ lscpu ... Vendor ID:            GenuineIntel CPU family:           6 Model:                62 Model name:           Intel(R) Xeon(R) CPU E5-2695 v2 @ 2.40GHz ...  $ ./bin/benchmark_string_upper_to_lower 2024-07-29T12:31:18+00:00 Running ./bin/benchmark_string_upper_to_lower Run on (12 X 2400 MHz CPU s) CPU Caches:   L1 Data 32 KiB (x12)   L1 Instruction 32 KiB (x6)   L2 Unified 256 KiB (x6)   L3 Unified 30720 KiB (x0) Load Average: 4.60, 4.39, 3.88 ------------------------------------------------------------ Benchmark                  Time             CPU   Iterations ------------------------------------------------------------ IcuConversion        1815000 ns      1815000 ns          314 ToLowerConversion     837000 ns       836966 ns          835 

Видно, что оптимизированный алгоритм работает примерно в два раза быстрее, чем первоначальная версия. Теперь посмотрим, как это отразится на perf‑флеймграфе:

Метод занимает около 0,6% от общего времени, что на процент меньше оригинальной версии. Это также повлияло на общий EPS (events per second) нормализатора, ускорив его примерно на 1%.

Сравнение с pt-pmp-флеймграфами

Если бы в качестве профилировщика использовался только pt-pmp, то проблему конвертации было бы тяжело обнаружить, поскольку он обладает менее высокой точностью по сравнению с perf и не показывает lower‑метод на флеймграфе.

Выглядит это следующим образом:

Для наглядности продублирую perf‑флеймграф до оптимизации, только с таким же масштабом, как у pt-pmp, чтобы точно увидеть разницу:

Можно сделать вывод, что для нахождения локальных оптимизаций лучше использовать perf, нежели pt-pmp.

Заключение

Описанные примеры демонстрируют сильные и слабые стороны pt-pmp и perf и показывают, когда и в каких случаях был применен каждый из них на практике. Как уже было сказано в первой части статьи, нам нет необходимости выбирать что‑то одно, эффективный вариант — применять оба профилировщика сразу, таким образом получится проанализировать приложение с разных сторон: как с точки зрения взаимодействия потоков и различных ожиданий, так и с точки зрения точечных оптимизаций и ускорения специализированных алгоритмов.

Стоит уточнить: хотя производительность в примерах отличается (при помощи pt-pmp удалось найти оптимизацию в 50%, в 1% — с использованием perf), это не значит, что perf слабее и его не надо использовать. Здесь делается акцент на сильных и слабых сторонах данных инструментов, так как при помощи pt-pmp тяжело находить проблемы, закрытие которых даст прирост в 1–2%. Но таких проблем может быть много, и, если постепенно их исправлять, производительность приложения ощутимо ускорится.

#include <vector> #include <string> #include <random> #include <algorithm>  #include <benchmark/benchmark.h> #include <casemap/casemap.h>  static constexpr size_t STR_MAX_SIZE = 100; static constexpr size_t VECTOR_SIZE = 3000;    static std::string getRandomString(size_t length) {     static constexpr std::string_view CHARACTERS = "0123456789ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz";     std::default_random_engine generator;     std::uniform_int_distribution<> distribution(0, CHARACTERS.size());      std::string string;     string.reserve(length);     for (std::size_t i = 0; i < length; ++i)     {         string.push_back(CHARACTERS[distribution(generator)]);     }      return string; }  static std::vector<std::string> getRandomStringVector() {      std::default_random_engine generator;     std::uniform_int_distribution<> distribution(1, STR_MAX_SIZE);     std::vector<std::string> vector{VECTOR_SIZE};      std::generate(vector.begin(), vector.end(), [&generator, &distribution]() {         auto length = distribution(generator);         return getRandomString(length);     });      return vector; }    static void IcuConversion(benchmark::State &state) {     auto vector = getRandomStringVector();      for( auto _: state ) {         for( auto &str: vector ) {             auto result = toLowerIcu(str);             benchmark::DoNotOptimize(result);         }     } }  BENCHMARK(IcuConversion);  static void ToLowerConversion(benchmark::State &state) {     auto vector = getRandomStringVector();      for( auto _: state ) {         for( auto &str: vector ) {             auto result = toLowerAscii(str);             benchmark::DoNotOptimize(result);         }     } }  BENCHMARK(ToLowerConversion);  BENCHMARK_MAIN();