Куда уходит процессорное время? Этот вопрос встает перед разработчиком встраиваемой системы как при поиске узких мест, так и при разборе ситуаций, когда система укладывается в сроки на стенде и перестает укладываться на объекте.
В статье расскажем, почему инструменты построены вокруг системной трассы ядра, как они связаны с планировщиком потоков и пройдем весь путь от сборки инструментированной программы до готовых отчетов.
Введение
В следующем релизе ЗОСРВ «Нейтрино» в состав средств разработчика войдут инструменты профилирования прикладных программ. Они состоят из двух компонентов: библиотеки libprof, которая работает на целевой системе и записывает события входа и выхода функций в системную трассу, и утилиты prof-report, которая на инструментальной системе конвертирует собранную трассу в отчет о профилировании.
В Linux ответ на вопрос о процессорном времени дает целая экосистема инструментов: perf со статистическим сэмплированием, gprof, ftrace, инструментирование компилятором. Каждый инструмент показывает свой срез системы, и целостную картину приходится собирать из нескольких источников.
Отличия в исходных условиях «Нейтрино» продиктовали необходимость альтернативного подхода. В итоге фундаментом для архитектуры новых инструментов стали следующие ключевые аспекты:
«Нейтрино» — микроядерная ОС. Драйверы, сетевой стек, файловые системы, графика работают как обычные процессы. Прикладным кодом здесь является почти все, что исполняется в системе. Поэтому профилирование прикладного уровня в «Нейтрино» покрывает и те подсистемы, которые в монолитных ОС спрятаны в ядре. Профилировать драйвер можно тем же способом и теми же инструментами, что и обычную пользовательскую программу.
В системе уже есть готовый канал для событий с точными метками времени: системная трасса. Инструментированное ядро записывает в нее события планировщика, прерываний, обмена сообщениями, а утилита tracelogger сохраняет поток событий в файл. Этот механизм давно применяется для анализа поведения системы (инструмент TraceKev) в реальном времени.
По своей архитектуре планировщик «Нейтрино» вытесняющий, со строгими приоритетами и их наследованием. Поток может быть вытеснен в любой момент, включая середину измеряемой функции. Честное измерение ее длительности требует понимания, когда поток занимал процессор, а когда простаивал.
Из этих трех наблюдений и появились инструменты профилирования: если трасса ядра уже существует и в ней уже есть события перепланирования, события входа и выхода функций нужно записывать туда же. Тогда один файл трассы будет содержать и профиль программы, и контекст всей системы, причем на общей временной шкале. Отчет о профилировании получает возможность учитывать вытеснения потоков без синхронизации двух разных таймлайнов, потому что источник только один.
Отметим и отличие от сэмплирующих профилировщиков. Сэмплирование дешевле по накладным расходам и не требует пересборки, зато дает статистическую картину. Компиляторное инструментирование фиксирует каждый вход и выход функции, поэтому структура и порядок вызовов в отчете детерминированы, а короткоживущие вызовы не теряются между выборками. Это свойство оказывается востребованным для систем реального времени, где интересует не только как в среднем исполнялся код, но и что произошло при конкретном запуске.
Архитектура инструментов
Инструменты разделены на две части по принципу: на целевой системе выполняется только то, что нельзя выполнить позже.
libprof — библиотека профилирования. Компилятор с флагом -finstrument-functions вставляет в начало и конец каждой функции вызовы __cyg_profile_func_enter() и __cyg_profile_func_exit(). Библиотека реализует эти две функции, производит в них runtime-анализ со сбором нужных метрик и пересылку в системную трассу.
Кроме этого, конструктор библиотеки при загрузке процесса записывает в трассу событие начала сессии профилирования и регистрирует обработчик динамического загрузчика. Обработчик сообщает в трассу о каждой загруженной и выгруженной динамической библиотеке, фиксируя ее адрес, размер и путь. Эти события позволят затем сопоставить адреса из трассы с именами функций.
На этом обязанности целевой стороны заканчиваются. Накладные расходы профилирования для программы — одно событие трассы на вход и одно на выход функции. Для встраиваемых систем с ограниченными ресурсами такое разделение принципиально, благодаря ему разбор трассы, восстановление стеков и работа с ELF-файлами не отнимают ни памяти, ни процессорного времени у целевой системы.
prof-report: вся обработка на инструментальной системе
prof-report читает файл tracebuffer.kev и восстанавливает модель выполнения программы, находя сессию профилирования, отслеживая жизненный цикл потоков и собирая стеки вызовов по парным событиям входа и выхода. Затем утилита загружает таблицы символов из основного ELF-файла и динамических библиотек, сопоставляет адреса с именами функций и экспортирует результат в выбранном формате.
Сбор трассы на целевой системе
Порядок работы показан на сквозном примере: программа app загружает динамическую библиотеку libapp.so.1, трасса сохраняется в файл tracebuffer.kev.
Сначала собирается программа с флагом инструментирования и линкуется с libprof:
CCFLAGS += -finstrument-functions
Флаг нужен и для app, и для исходников libapp.so.1, если необходимо видеть вызовы функций библиотеки. Таблица символов в ELF-файлах должна быть сохранена: без нее в отчете останутся адреса вместо имен.
Служебные функции, которые профилировать нет необходимости, помечаются атрибутом:
__attribute__((no_instrument_function))
Атрибут пригодится для низкоуровневого логирования, аллокаторов и прочих функций, которые вызываются часто и способны заметно увеличить размер трассы.
Затем запускается сбор трассы. tracelogger стартует до программы, потому что libprof записывает стартовое событие из конструктора при загрузке процесса:
$ tracelogger -f tracebuffer.kev -c & $ ./app $ slay tracelogger
После остановки трассировки на инструментальную систему переносятся три файла: трасса tracebuffer.kev, основной ELF-файл app и библиотека libapp.so.1. Удобная структура каталогов выглядит так:
work/ |-- app |-- tracebuffer.kev `-- libs/ `-- libapp.so.1
Каталог libs можно наполнять двумя способами: сохранить в нем те же относительные пути, что и на целевой системе (libs/usr/lib/libapp.so.1), или сложить нужные .so в один каталог. prof-report проверит оба варианта.
Построение отчета
Отчет строится одной командой:
$ prof-report -f app -l libs -t calltree -o calltree.txt tracebuffer.kev
Здесь -f задает основной ELF-файл, -l — каталог с динамическими библиотеками, -t — формат отчета, -o — файл результата, а последним аргументом идет файл трассы.
Утилита поддерживает несколько форматов экспорта. Остановимся на четырех, которые покрывают большинство задач.
calltree: быстрый ответ в терминале
Текстовое дерево вызовов, которое читается без дополнительных инструментов:
Inc(%) Exc(%) Name 100.00 0.00 ./app 34.47 0.00 |- Thread #0 (tid=1) 34.47 0.00 | `- [_start] 34.47 19.71 | `- main
Колонка Inc показывает время функции вместе с дочерними вызовами, Exc — время в самой функции. Имена в квадратных скобках, например [_start], обозначают неинструментированные функции: prof-report восстановил их по адресу вызова.
Формат хорош для быстрой оценки в терминале и как артефакт CI: текстовый отчет легко приложить к сборке и сравнить между версиями.
flamegraph: обзор одним файлом
Экспорт в формате свернутых стеков для инструмента FlameGraph:
$ prof-report -f app -l libs -t flamegraph -o flamegraph.txt tracebuffer.kev $ perl FlameGraph/flamegraph.pl flamegraph.txt > flamegraph.svg
На выходе один SVG-файл с интерактивной диаграммой стеков: ширина каждого блока пропорциональна суммарному времени функции. Такой отчет удобно прикладывать к задаче или письму и использовать для сравнения агрегированных профилей до и после оптимизации.
speedscope: интерактивный анализ
Экспорт -t speedscope создает JSON для просмотрщика speedscope. Файл можно открыть на сайте, а можно и полностью автономно путем скачивания релиза speedscope, распаковки архива и открытия index.html в браузере.
Просмотрщик строит отдельный профиль на каждый поток и предлагает три режима: Time Order показывает выполнение на временной шкале в исходной хронологии, Left Heavy агрегирует стеки и выводит наверх самые дорогие пути, Sandwich собирает статистику по одной выбранной функции со всеми ее вызывающими и вызываемыми. Это самый удобный формат для подробного изучения поведения отдельных потоков.
chrome: временная шкала в браузере
Экспорт -t chrome создает JSON в формате Chrome Trace. Для просмотра не нужно ничего устанавливать: файл загружается на странице chrome://tracing в браузере Chrome или Chromium. Браузер найдется на любой инструментальной системе, поэтому именно с этого формата удобно начинать знакомство. Рекомендуемый совместимый вариант chrome://tracing — просмотрщик Perfetto: он открывает тот же файл и предлагает более современный интерфейс.
Формат показывает единую временную шкалу всех потоков процесса с вложенностью вызовов. Он незаменим, когда важны порядок входов и выходов функций и распределение работы между потоками во времени. Изображения в следующем разделе получены именно из этого формата в просмотрщике Perfetto.
Влияние планировщика: режим коррекции времени
Теперь о возможности, ради которой события профилирования и попали в системную трассу.
В режиме по умолчанию prof-report показывает интервалы в исходном виде, сохраняя реальную длительность функций и реальный порядок событий. Но в системе с вытесняющим планировщиком длительность функции от входа до завершения и время, которое ее код исполнялся на процессоре, являются разными величинами. Если посередине функции поток был вытеснен более приоритетным, пауза войдет в измеренную длительность.
Чтобы увидеть чистое процессорное время, у prof-report есть опция -i. Утилита учитывает события перепланирования, которые инструментированное ядро записало в ту же трассу, и вычитает из длительности функций интервалы, когда поток не исполнялся на процессоре.
-i: из временной шкалы пропали участки, где main был заблокирован в ожидании дочерних потоковЭффект хорошо виден на тестовом наборе, где несколько потоков выполняют функции одинаковой сложности. Потоки, запущенные одновременно, конкурируют за процессор, и в обычном отчете их функции выглядят в разы дольше, чем те же функции в одиночном потоке. Отчет с опцией -i выравнивает эти времена: конкуренция за процессор перестает маскировать истинную сложность вычислений.
-i, где времена всех наборов функций сравнялисьПодчеркнем: возможность появилась без каких-либо накладных расходов со стороны libprof. События профилирования и события планировщика лежат в одной трассе с общей временной шкалой, поэтому сопоставить их — чисто вычислительная задача инструментальной стороны.
Объединение потоков
Опция -m объединяет потоки. При этом отчет строится не по каждому потоку отдельно, а суммарно по процессу. В сочетании с calltree или flamegraph такой режим показывает, какие функции дороже всего обходятся процессу в целом, скрывая распределение работы между потоками.
Заключение
Инструменты профилирования «Нейтрино» опираются на штатную системную трассу, и из этого решения следуют их сильные стороны:
целевая система несет минимальные накладные расходы, вся обработка выполняется на инструментальной системе;
отчет показывает как реальную длительность функций, так и чистое процессорное время, поскольку один файл трассы включает и профиль программы и события планировщика;
метод применим почти ко всему коду системы, включая драйверы и системные сервисы (при особой сноровке и даже к ядру), благодаря микроядерной архитектуре;
результаты экспортируются в распространенные форматы, от текстового дерева вызовов для терминала и CI до интерактивных просмотрщиков.
Однако должны подчеркнуть отдельно, что системная трассировка и прикладное профилирование являются сугубо отладочными инструментами.
Подробное руководство с описанием всех форматов, режимов и разбором типовых сценариев использования войдет в будущие редакции документации разработчика.
