Инструмент uftrace: трассировка и анализ выполнения программы, написанной на C/C++

Инструмент uftrace предназначен для трассировки и анализа выполнения программы, написанной на языках C и C++. Он был создан под сильным влиянием фреймворка ftrace в ядре Linux (особенно его компонента трассировщика графа функций) и поддерживает программы пользовательского пространства. Инструмент поддерживает различные команды и фильтры, которые помогают анализировать выполнение программы и её производительность.

Особенности

uftrace отслеживает каждую функцию в исполняемом файле и показывает продолжительность времени её выполнения. Также он может отслеживать вызовы внешних библиотек, но обычно поддерживается только вход и выход из них. При необходимости можно отслеживать другие (вложенные) внешние вызовы библиотек и/или внутренние вызовы функций в этих вызовах.

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

Можно настроить фильтры для исключения или включения определённых функций при трассировке. Кроме того, инструмент может сохранять и показывать аргументы функций и возвращаемые значения.

Он поддерживает многопроцессные и/или многопоточные приложения. С правами суперпользователя он также может отслеживать функции ядра (с опцией -k), если система включает трассировщик графа функций в ядре (CONFIG_FUNCTION_GRAPH_TRACER=y).

Как собрать и установить uftrace

В дистрибутивах Linux файл misc/install-deps.sh устанавливает необходимое программное обеспечение в вашей системе. Это программное обеспечение предназначено для дополнительных расширенных функций, но рекомендуется устанавливать его вместе.

После установки необходимого программного обеспечения в вашей системе его можно собрать и установить следующим образом:

• $ ./configure
• $ make
• $ sudo make install

Для более продвинутой настройки обратитесь к файлу INSTALL.md.

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

Команда uftrace имеет следующие подкоманды:

• record — запускает программу и сохраняет данные трассировки;
• replay — показывает выполнение программы по данным трассировки;
• report — показывает статистику производительности по данным трассировки;
• live — выполняет запись и воспроизведение подряд (по умолчанию);
• info — показывает системную и программную информацию по данным трассировки;
• dump — показывает низкоуровневые данные трассировки;
• recv — сохраняет данные трассировки из сети;
• graph — показывает граф вызовов функций по данным трассировки;
• script — запускает скрипт для записанных данных трассировки;
• tui — показывает текстовый пользовательский интерфейс для графа и отчёта.

Вы можете использовать опции -h или --help, чтобы увидеть доступные команды и параметры. Перевод текста на русский язык:

-finstrument-functions) — опция, которая генерирует код профилирования (вызов mcount или __cyg_profile_func_enter/exit) для каждой функции.

Обратите внимание, что существует экспериментальная поддержка динамической трассировки на x86_64 и AArch64(ARM64), которая не требует такой (пере-)компиляции. Также последние компиляторы имеют некоторые опции, которые помогают uftrace уменьшить накладные расходы на трассировку аналогичным образом (хотя это всё ещё требует перекомпиляции вашей программы). Подробнее см. в разделе «Динамическая трассировка» (doc/uftrace-record.md#динамическая-трассировка).

$ uftrace tests/t-abc
# ДЛИТЕЛЬНОСТЬ    TID     ФУНКЦИЯ
  16,134 мкс [ 1892] | __monstartup();
 223,736 мкс [ 1892] | __cxa_atexit();
            [ 1892] | main() {
            [ 1892] |   a() {
            [ 1892] |     b() {
            [ 1892] |       c() {
   2,579 мкс [ 1892] |         getpid();
   3,739 мкс [ 1892] |       } /* c */
   4,376 мкс [ 1892] |     } /* b */
   4,962 мкс [ 1892] |   } /* a */
   5,769 мкс [ 1892] | } /* main */

Для более глубокого анализа лучше сначала записать его, чтобы можно было запускать такие команды анализа, как replay, report, graph, dump и/или info несколько раз.

$ uftrace record tests/t-abc

Будет создан каталог uftrace.data, содержащий файлы данных трассировки. Другие команды анализа ожидают, что каталог существует в текущем каталоге, но можно использовать другой с помощью опции -d.

Команда replay показывает информацию о выполнении, подобную приведённой выше. Как видите, t-abc — это очень простая программа, которая просто вызывает функции a, b и c. В функции c она вызвала getpid(), которая является библиотечной функцией, реализованной в библиотеке C (glibc) на обычных системах — то же самое относится и к __cxa_atexit().

Пользователи могут использовать различные параметры фильтра, чтобы ограничить функции, которые он записывает/печатает. Фильтр глубины (-D) предназначен для пропуска функций ниже заданной глубины вызова. Временной фильтр (-t) предназначен для пропуска функций, работающих менее заданного времени. А фильтры функций (-F и -N) предназначены для отображения/скрытия функций в пределах заданной функции.

Опция -k позволяет также отслеживать функции ядра (требуется доступ root). С классической программой «Hello world» вывод будет выглядеть следующим образом (Примечание: я изменил её, чтобы использовать fprintf() с stderr вместо простого printf(), чтобы она напрямую вызывала системный вызов):

$ sudo uftrace -k tests/t-hello
Hello world
# DURATION    TID     FUNCTION
   1,365 мкс [21901] | __monstartup();
   0,951 мкс [21901] | __cxa_atexit();
            [21901] | main() {
            [21901] |   fprintf() {
   3,569 мкс [21901] |     __do_page_fault();
  10,127 мкс [21901] |     sys_write();
  20,103 мкс [21901] |   } /* fprintf */
  21,286 мкс [21901] | } /* main */

Вы можете видеть, что обработчик ошибок страницы и обработчик системного вызова записи были вызваны внутри вызова fprintf().

Также он может записывать и показывать аргументы функции и возвращаемое значение с опциями -A и -R соответственно. Следующий пример записывает первый аргумент и возвращаемое значение функции «fib» (число Фибоначчи).

$ uftrace record -A fib@arg1 -R fib@retval tests/t-fibonacci 5

$ uftrace replay
# ДЛИТЕЛЬНОСТЬ    TID     ФУНКЦИЯ
   2,853 мкс [22080] | __monstartup();
   2,194 мкс [22080] | __cxa_atexit();
            [22080] | main() {
   2,706 мкс [22080] |   atoi();
            [22080] |   fib(5) {
            [22080] |     fib(4) {
            [22080] |       fib(3) {
   7,473 мкс [22080] |         fib(2) = 1;
   0,419 мкс [22080] |         fib(1) = 1;
  11,452 мкс [22080] |       } = 2; /* fib */
   0,460 мкс [22080] |       fib(2) = 1;
  13,823 мкс [22080] |     } = 3; /* fib */
            [22080] |     fib(3) {
   0,424 мкс [22080] |       fib(2) = 1;
   0,437 мкс [22080] |       fib(1) = 1;
   2,860 мкс [22080] |     } = 2; /* fib */
  19,600 мкс [22080] |   } = 5; /* fib */
  25,024 мкс [22080] | } /* main */

Команда report позволяет узнать, какая функция тратит больше всего времени, включая её дочерние элементы (общее время).

$ uftrace report
  Общее время   Самостоятельное время **Вызовы функции**

| 25,024 мкс | 2,718 мкс || главная | |----------|----------||--------| | 19,600 мкс | 19,600 мкс || фиб | | 2,853 мкс | 2,853 мкс || __monstartup | | 2,706 мкс | 2,706 мкс || atoi | | 2,194 мкс | 2,194 мкс || __cxa_atexit |

Команда graph показывает граф вызовов функций данной функции. В приведённом примере граф функций функции «main» выглядит следующим образом:

$ uftrace graph main

Function Call Graph for 'main' (session: 073f1e84aa8b09d3)

=============== BACKTRACE =============== backtrace #0: hit 1, time 25.024 us [0] main (0x40066b)

========== FUNCTION CALL GRAPH ========== 25.024 us : (1) main 2.706 us : +-(1) atoi : | 19.600 us : +-(1) fib 16.683 us : (2) fib 12.773 us : (4) fib 7.892 us : (2) fib

Команда dump показывает необработанный вывод каждой записи трассировки. Вы можете увидеть результат в браузере Chrome после обработки данных с помощью команды uftrace dump --chrome. Ниже приведена трассировка clang (LLVM), компилирующего небольшую C++ шаблонную метапрограмму.

Команда также поддерживает вывод в виде пламени-графа. Данные можно обработать с помощью uftrace dump — flame-graph и передать в flamegraph.pl. Ниже приведён результат пламени-графа gcc, компилирующего простую программу на C.

Команда info показывает системную и программную информацию во время записи.

$ uftrace info

system information

==================

program version : uftrace v0.8.1

recorded on : Tue May 24 11:21:59 2016

cmdline : uftrace record tests/t-abc

cpu info : Intel(R) Core(TM) i7-3930K CPU @ 3.20GHz

number of cpus : 12 / 12 (online / possible)

memory info : 20.1 / 23.5 GB (free / total)

system load : 0.00 / 0.06 / 0.06 (1 / 5 / 15 min)

kernel version : Linux 4.5.4-1-ARCH

hostname : sejong

distro : "Arch Linux"

process information

===================

number of tasks : 1

task list : 5098

exe image : /home/namhyung/project/uftrace/tests/t-abc

build id : a3c50d25f7dd98dab68e94ef0f215edb06e98434

exit status : exited with code: 0

elapsed time : 0.003219479 sec

cpu time : 0.000 / 0.003 sec (sys / user)

context switch : 1 / 1 (voluntary / involuntary)

max rss : 3072 KB

page fault : 0 / 172 (major / minor)

disk iops : 0 / 24 (read / write)

Команда script позволяет пользователю запускать пользовательский скрипт на записанных данных. На данный момент поддерживаются типы скриптов Python 2.7 и Lua 5.1.

Команда tui предназначена для интерактивного текстового пользовательского интерфейса с использованием ncurses. Она предоставляет базовую функциональность команд graph, report и info.

Ограничения

— Можно отслеживать нативное приложение C/C++ в Linux. — Нельзя отслеживать уже запущенный процесс. — Нельзя использовать для системного отслеживания. — Поддерживает x86 (32 и 64 бит), ARM (v6 или позже) и AArch64 на данный момент.

Лицензия

Программа uftrace выпущена под GPL v2. Подробнее см. файл COPYING.