Сводка по профилированию и оптимизации производительности

искусственный интеллект

Автор: Ван Лулу | Архитектор MegEngine

1. Предпосылки

В начале разработки императивной среды выполнения MegEngine мы столкнулись с некоторыми проблемами оптимизации производительности. В дополнение к некоторым известным областям, требующим рефакторинга (компромисс производительности за счет эффективности разработки на раннем этапе проектирования), существуют также некоторые неизвестные проблемы производительности, которые необходимо наблюдать и анализировать с помощью профилировщика. Императивная среда выполнения MegEngine представляет собой модуль, написанный на Python и C/C++, и существует огромное количество профилировщиков для таких программ. В процессе исследования различных профилировщиков мы тоже наступили на множество подводных камней.Например, мы обнаружили, что результаты профилирования двух профилировщиков для одной и той же программы сильно отличаются.Мы изначально подозревали, что проблема с точностью одного из профилировщиков и, наконец, обнаружил, что два наблюдения различаются: одно профилирует только время процессора программы, а другое профилирует время настенных часов. Хотя часть этой информации можно найти в некоторых углах документа, многие пользователи могут заметить ее только после того, как наступят на яму. Мы могли бы сэкономить много времени, если бы нашли статью с описанием возможностей, преимуществ, недостатков и сценариев использования различных профилировщиков.

Поэтому в этой статье делается попытка обобщить этот опыт, надеясь дать ссылку на читателей, которые используют эти инструменты впервые. Оптимизация производительности — это очень широкая тема, которая затрагивает ЦП, память, диск, сеть и т. д. Эта статья в основном посвящена оптимизации производительности расширений Python и C/C++ на ЦП. В статье основное внимание уделяется следующим трем вопросам:

  • Каковы общие цели оптимизации для расширений Python и C/C++?
  • Каковы возможности и ограничения распространенных инструментов, и как мы должны выбрать инструмент с учетом цели оптимизации
  • Как использовать различные инструменты и визуализировать результаты

Кроме того, в этой статье также будут представлены некоторые основные понятия, которые необходимо понимать при оптимизации производительности, а в конце статьи для демонстрации процесса оптимизации будет использован реальный случай оптимизации производительности в процессе разработки MegEngine.

2. Основные понятия

В этом разделе представлены некоторые основные понятия оптимизации производительности:

2.1 время настенных часов, процессорное время и внепроцессорное время

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

Команда time в системах Linux может дать нам некоторую приблизительную информацию, мы выводим следующую команду в командной строке, чтобы измерить время выполнения проверки кода проверки CRC файла:

time cksum \<some_file\>

Используя в качестве примера мой компьютер (MacBook Pro 2018), я получил следующий вывод:

8.22s user 1.06s system 96% cpu 9.618 total

Этот текст говорит нам, на что мы тратим время:

  • Общее время 9,618 с
  • пользовательское время 8,22 с
  • системное время 1.06с

Значения пользователя и системы - это время ЦП пользователя и время ЦП системы.Причина, по которой время выполнения ЦП делится на две части, заключается в том, что когда программа работает, в дополнение к выполнению кода самой программы и некоторой библиотеки коды, он также будет вызывать операции. Функции, предоставляемые системой (то есть системные вызовы, программы имеют более высокие привилегии при выполнении системных вызовов), поэтому программы обычно работают в двух состояниях: пользовательском и ядерном. ЦП при выполнении системных вызовов Состояние, а пользовательский режим — это состояние, когда ЦП выполняет несистемные вызовы (т. е. собственный код пользователя или некоторые библиотеки).

Следовательно, упомянутое выше время ЦП пользователя относится к времени, проведенному в пользовательском режиме, а время ЦП системы относится к времени, проведенному в режиме ядра.

Мы обнаружили, что время ЦП пользователя + время ЦП системы = 8,22 с + 1,06 с = 9,28 с не равно общему времени 9,618 с. Это связано с тем, что программа не всегда выполняется на ЦП во время выполнения этой команды. также возможно, что в состоянии сна, ожидания и т. д., например, ожидания загрузки файла с диска в память и т. д. Это время не учитывается ни во времени ЦП пользователя, ни во времени ЦП системы. Мы называем время выполнения программы на ЦП (т.е. время ЦП пользователя + время ЦП системы) временем ЦП (или временем на ЦП), а время, когда программа находится в спящем режиме и других состояниях, временем вне ЦП (или блокировкой). Время, которое программа фактически выполняет, называется временем настенных часов (буквально время на настенных часах, то есть время, прошедшее в реальном мире), для данного потока: время настенных часов = время ЦП + время вне ЦП .

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

2.2 Инструменты наблюдения за эффективностью

Мы знаем время процессора и время вне процессора во время выполнения потока.Если мы хотим оптимизировать производительность программы, этого недостаточно.Нам нужно дополнительно знать, что произошло на процессоре в течение периода времени процессора time. , Сколько времени заняли эти вещи, где поток был заблокирован, как долго он блокировался и т. д. Нам нужны инструменты наблюдения за производительностью, чтобы получить эту подробную информацию. Обычно мы также называем этот инструмент наблюдения профилировщиком.

Разным объектам наблюдения соответствуют разные профилировщики, а что касается процессора, то профилировщиков бесчисленное множество.

По объему наблюдения профилировщик на ЦП можно условно разделить на две категории: уровень процесса (для каждого процесса, также иногда называемый уровнем приложения) и системный уровень (для всей системы), из которых:

  • Уровень процесса наблюдает только за тем, что происходит в одном процессе или потоке.
  • Системный уровень не ограничивается определенным процессом, объектом наблюдения являются все программы, работающие на всей системе

Следует отметить, что некоторые инструменты могут наблюдать как за системой в целом, так и за отдельными процессами, например perf, поэтому такие инструменты попадают в обе категории.

В соответствии с методом наблюдения его можно условно разделить на две категории: на основе событий и на основе выборки. в:

  • Основанный на событии: на указанном наборе событий, таких как вход или выход из определенной функции, выделение памяти, создание исключений и другие события. Профилировщик на основе событий также называется профилировщиком трассировки или трассировщиком в некоторых статьях.
  • На основе выборки: выборка некоторой информации о работающей программе с заданной частотой, обычно объектом выборки является стек вызовов программы.

Даже если будет установлено, что оптимизируемые нами объекты относятся к одной из вышеперечисленных категорий, существуют еще более тонкие классификации. Прежде чем выбрать инструмент, нам нужно выяснить, что представляет собой конкретный объект оптимизации.Один профилировщик, как правило, не может удовлетворить все наши потребности.Для различных объектов оптимизации (таких как потоки Python, потоки C/C++ и т. д.) нам нужно использовать разные профайлеры. И для одного и того же объекта оптимизации, если мы сосредоточимся на разной информации, нам также может понадобиться использовать разные профилировщики.

2.3 Модель процесса Python

Эта статья в основном посвящена оптимизации программ Python (включая расширение C/C++) Процесс типичной программы расширения Python и C/C++ показан на следующем рисунке:

Процесс Python должен содержать основной поток Python и может содержать несколько подпотоков Python и несколько подпотоков C/C++. Поэтому дополнительно разделим объекты оптимизации на три категории:

  • Код Python в потоке Python
  • Код расширения C/C++ в потоке Python
  • Потоки C/C++

Поток Python здесь относится конкретно к потоку интерпретатора CPython, а поток C/C++ относится к потоку C/C++, который не содержит стека вызовов Python.

3. Классификация и выбор профайлера

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

  • Поддерживать ли время профилирования, время вне ЦП и время настенных часов (время ЦП + время вне ЦП)
  • Поддерживать ли профилирование стека C/C++
  • Можно ли проанализировать стек вызовов Python из стека вызовов интерпретатора CPython.

В нашем введении будут представлены 6 профилировщиков, а именно py-spy, cProfile, pyinstrument, perf, systemtap и eu-stack. Чтобы облегчить вам выбор, мы делим эти профилировщики на 4 категории в соответствии с приведенными выше характеристиками и суммируем их в следующей таблице (где ✔, ⚠, × обозначают поддержку, неполную поддержку и неподдерживаемые соответственно):

Первый в таблице — это чистый профилировщик Python, который может наблюдать только за стеком вызовов функций Python в потоках Python, что подходит для оптимизации чистого кода Python. -party Python profiler), таких профилировщиков много, например, scalene, line-profiler, pprofile и т.д. Поскольку эти профилировщики мало чем отличаются в возможностях, они не будут здесь представлены по одному.

Второй тип — это профилировщик потоков Python. Основное отличие от первого типа заключается в том, что в дополнение к наблюдению за стеком вызовов Python в потоке Python он также может наблюдать за стеком вызовов, расширенным c/c++.Этот тип вводит только py- шпион.

Третий тип — профилировщик системного уровня. Мы в основном используем его для наблюдения за расширенным стеком вызовов C/C++ и чистым потоком C/C++ в потоке Python.Хотя этот тип профилировщика может наблюдать за стеком вызовов интерпретатора CPython, он не предназначен для Python.Разработанный профилировщик не анализирует стек вызовов функций Python, поэтому он не подходит для наблюдения за стеком Python. В этой категории инструментов мы представим perf и systemtap.

Последняя категория является дополнением к третьей категории.Поскольку ни один из двух инструментов, представленных в третьей категории, не может отслеживать программы по времени настенных часов (время ЦП + время вне ЦП), eu-stack может выполнять выборку программ по времени настенных часов. Стек вызовов C/C++, поэтому его можно использовать в качестве профилировщика в этом сценарии.

Накладные расходы в таблице относятся к влиянию работающего профилировщика на программу профилирования.Чем больше накладные расходы, тем ниже точность результатов профилирования. Следует отметить, что ни один профайлер не может быть абсолютно точным, на результаты будет влиять влияние самого профилировщика на программу и случайность выборки. следует рассматривать как оценку (даже предвзятую) того, что происходит на самом деле.

В дополнение к профилировщику нам также нужны некоторые инструменты для визуализации результатов профилирования для анализа узких мест в производительности. В отличие от профилировщика, инструменты визуализации, как правило, очень универсальны. Широко используемый инструмент — пламенный граф. В этой статье рассказывается, как использовать пламенный граф. Кроме того, в нем будет представлена ​​улучшенная версия пламенного графа: speedscope.

Поскольку введение профилировщика должно относиться к инструменту визуализации, мы сначала представим инструмент визуализации, а затем представим профилировщик.

4. Инструменты визуализации

4.1 flamegraph

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

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

Основная функция flamegraph — отображать частотное распределение стека вызовов, выбранное профилировщиком.Вертикальный стек на рисунке представляет стек вызовов, а ширина прямоугольного блока в стеке вызовов представляет частоту, с которой функция run (время выполнения определенного пути выполнения. Доля пропорциональна вероятности его выборки, поэтому частота выборки примерно равна доле времени пути выполнения). Наблюдая за графиком пламени, мы можем увидеть, какие пути выполнения имеет программа, и долю времени каждого пути выполнения, а затем оптимизировать узкое место производительности (или «горячую точку») с большой долей времени для достижения цели оптимизации производительности. .

Если вы хотите узнать больше о flamegraph, вы можете обратиться к домашней странице автора или репозиторию github:

4.2 speedscope

Еще один инструмент, который стоит представить, — это speedscope. Использование speedscope похоже на flamegraph, и он совместим с выходным форматом flamegraph. По сравнению с flamegraph, speedscope имеет два преимущества: 1) speedscope очень хорош в визуализации, интерактивности и т. д., 2) скорость выполнения speedscope намного ниже, чем у SVG, а одновременное открытие многих окон не вызовет явной зависшей паузы. Поэтому мы рекомендуем комбинировать speedscope с flamegraph: использовать flamegraph для обработки выходных данных от разных инструментов, а speedscope использовать для визуализации. speedscope — это веб-приложение, автор предоставляет адрес, который можно использовать напрямую:www.speedscope.app/, мы также можем развернуть локально, но первое удобнее. В этой статье в основном используется speedscope для визуализации результатов профилирования. Ниже приводится краткое введение в его использование:

Входитьwww.speedscope.app/, откройте результат профилирования в формате json (ниже мы расскажем, как преобразовать результат в этот json при использовании различных профилировщиков). Вы можете увидеть следующий интерфейс (одно отличие от flamegraph в том, что стек вызовов speedscope перевернут):

В левом верхнем углу есть три режима на выбор:

  • Порядок времени: режим временной оси, представляющий направление времени слева направо, а каждый столбец в середине представляет собой стек вызовов, выбранный в разное время.
  • Левый тяжелый: отображение в соответствии с пропорцией времени функции стека вызовов (пропорция времени выборки для оценки пропорции времени), то есть каждый слой стека вызовов сортируется в том порядке, в котором время с левой стороны больше. чем время на правой стороне короче. Нажмите на любую функцию в стеке вызовов:
    • Вы можете увидеть общую стоимость (Total) и собственную стоимость (Self) функции в текущем стеке вызовов (This Instance) в левом нижнем углу рисунка, а также общую стоимость функции во всех стеках вызовов (Все Экземпляры) появившихся (Всего) и себестоимости (Сам), целое число на рисунке представляет собой количество раз выборки, а процент — долю выборки (примерно равную доле времени).
    • Внутри белого прямоугольника под рисунком находится стек вызовов функции.
  • Сэндвич: сортировка по общей стоимости функции и ее собственной стоимости, нажмите на функцию, чтобы увидеть вызывающую и вызываемую функции.

Для более подробного ознакомления, пожалуйста, обратитесь к официальному репозиторию speedscope:GitHub.com/Carrefour My That/SPE…

5. Инструмент наблюдения за производительностью

Далее мы представим несколько профилировщиков, обычно используемых в процессе оптимизации расширений Python и C/C++. Мы познакомим вас с преимуществами и ограничениями каждого профилировщика, и вы должны выбрать подходящий инструмент в соответствии с вашими реальными потребностями.

5.1 py-spy

py-spy — это профилировщик на основе выборки, его объект профилирования — это стек вызовов, расширенный Python и C/C++. Накладные расходы py-spy средние, и это не слишком сильно влияет на скорость работы программы. И он поддерживает прямой вывод результатов в формате Speedscope и Flamegraph.

repo: GitHub.com/Бен Фред/Друзья-…

Вы можете установить его напрямую, используя pip:

pip install py-spy

Инструкции:

# 基本使用方法:
py-spy record --format speedscope -o output.json --native -- python3 xxx.py
  
# =====
# 主要参数:
# --format: 输出格式，默认是flamegraph，推荐使用speedscope格式
# --output: 输出文件名
# --native: 是否采样C/C++调用栈，不加--native只会对Python调用栈进行采样
  
# =====
# 其他参数
# --rate:          采样频率，默认值为100，打开--native会增大overhead，建议打开--native时调低--rate
# --subprocesses:  是否对子进程进行采样，默认为否
# --gil:           是否只对拿到Python GIL的线程进行采样
# --threads:       在输出中显示thread id
# --idle:          是否对idle(即off-CPU time)的thread进行采样，默认为否，根据具体场景选择是否打开
  
# =====
# 例子:
py-spy record -sti --rate 10 --format speedscope --native -o output.json -- python3 xxx.py
 
# 除了在启动时运行py-spy，还可以对一个已经运行的python进程进行采样，如:
py-spy record --format speedscope -o output.json --native --pid 12345

Другие функции:

В дополнение к подкоманде записи, py-spy также предоставляет подкоманду top:, которая может динамически отображать порядок самых ресурсоемких функций в командной строке, и подкоманду dump: которая печатает стек вызовов запущенного процесса Python. Для конкретного использования, пожалуйста, обратитесь к документации:GitHub.com/Бен Фред/Друзья-…

py-spy поддерживает выборку стека вызовов программы по времени процессора или по настенным часам (время процессора + время вне процессора).Объектом выборки является стек вызовов python потока Python или стек вызовов, расширенный c/c++.

Хотя py-spy также может сэмплировать стек вызовов потоков C/C++, в настоящее время (v0.3.4) он объединяет стек вызовов Python со стеком вызовов C/C++ (подробности см. в проблеме, связанной с GitHub:GitHub.com/Бен Фред/Друзья-…) , независимо от того, существует ли между ними реальная взаимосвязь вызовов, результаты профилирования потоков C/C++ будут агрегироваться в соответствии со стеком вызовов Python во время визуализации, что затрудняет анализ. подходит для чистого кода Python и Python.Расширение C/C++ в потоке (между Python и C/C++ существует взаимосвязь вызова) не подходит для наблюдения за независимыми потоками C/C++, что является недостатком py-spy.

5.2 cProfile

cProfile — это профилировщик на основе событий, который работает, отслеживая каждый вызов функции Python и накладные расходы времени на интерпретатор Python. cProfile — это встроенный в Python профилировщик, который теоретически имеет относительно высокую поддержку Python. Есть много ограничений cProfile:

  • Можно наблюдать только чистые вызовы функций Python, а расширенные стеки вызовов C/C++ не видны.
  • Поддерживает только время настенных часов
  • Накладные расходы относительно велики

Инструкции:

python3 -m cProfile xxx.py

Выходной формат cProfile представляет собой таблицу следующего вида:

    2173 function calls (2145 primitive calls) in 10.230 seconds
 
Ordered by: standard name
 
ncalls  tottime  percall  cumtime  percall filename:lineno(function)
    1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:103(release)
    1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:143(__init__)
    1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:147(__enter__)
    1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:151(__exit__)
    1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:157(_get_module_lock)
    1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:176(cb)
    1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:211(_call_with_frames_removed)
   32    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:222(_verbose_message)
    1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:307(__init__)
    1    0.000    0.000    0.000    0.000 <frozen importlib._bootstrap>:311(__enter__)
 
....

Также можно указать выходной файл:

python3 -m cProfile -o xxx.cprof xxx.py

Необработанный вывод неудобен для анализа, нужны сторонние инструменты для обработки и визуализации выходных данных, ниже описаны два метода:

  • Преобразуйте его в изображение графа вызовов
# dependency: gprof2dot, graphviz
# sudo apt install graphviz
# pip3 install gprof2dot
  
gprof2dot -f pstats xxx.cprof | dot -Tpng -o xxx.png && feh

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

  • Преобразовать в пламенный граф
# dependency: flameprof
# pip3 install flameprof
 
flameprof xxx.cprof > flamegraph.svg

Для получения дополнительной информации обратитесь к документации cProfile:docs.Python.org/3/library/… страх…

5.3 pyinstrument

pyinstrument — это профилировщик на основе выборки, аналогичный по функциям cProfile, поддерживает только стек вызовов Sampling pure Python, аналогично поддерживает только время настенных часов, но накладные расходы ниже, чем cProfile, и поставляется с различными методами визуализации.

Официальный адрес репо:GitHub.com/Джо Рик/дешево…

Установить:

pip3 install pyinstrument

Инструкции:

python3 -m pyinstrument xxx.py

Вывод по умолчанию находится в командной строке следующим образом:

  _     ._   __/__   _ _  _  _ _/_   Recorded: 15:50:07  Samples:  8794
 /_//_/// /_\ / //_// / //_'/ //     Duration: 23.332    CPU time: 31.381
/   _/                      v3.4.1
 
Program: train.py
 
23.331 <module>  train.py:9
├─ 22.641 main  train.py:29
│  └─ 22.631 worker  train.py:114
│     ├─ 10.077 item  megengine/core/tensor/array_method.py:391
│     │  └─ 10.067 numpy  megengine/tensor.py:113
│     │     └─ 10.067 Tensor.numpy  <built-in>:0
│     ├─ 8.056 train_step  train_random.py:159
│     │  ├─ 5.396 __call__  megengine/module/module.py:120
│     │  │  └─ 5.392 forward  model.py:170
│     │  │     └─ 5.348 __call__  megengine/module/module.py:120
│     │  │        └─ 5.239 forward  megengine/module/sequential.py:94
│     │  │           └─ 5.198 __call__  megengine/module/module.py:120
│     │  │              └─ 4.838 forward  model.py:87
...

Вы также можете вывести HTML-файл, чтобы просмотреть приведенные выше результаты в браузере:

python3 -m pyinstrument \--html xxx.py

Эффект следующий:

img

5.4 perf

perf — официальный профилировщик Linux, который можно найти вLinux kernelНайдите его исходный код в . Функция perf очень мощная. Она поддерживает как наблюдение за всей операционной системой, так и наблюдение за отдельным заданным процессом. Кроме того, perf может отслеживать указанное событие, а также поддерживает выборку стека вызовов процесса. perf работает в режиме ядра, и его собственные накладные расходы очень малы.

Установить производительность:

sudo apt-get install linux-tools-common linux-tools-generic linux-tools-\uname -r\

Версия perf должна соответствовать версии ядра Linux, а uname -r в команде установки гарантирует это.

Инструкции:

# 直接运行程序并进行采样，如python3 xxx.py
perf record -F 99 --call-graph dwarf python3 xxx.py
 
# 或对给定线程id(TID)进行采样
perf record -F 99 --call-graph dwarf --tid <TID>
 
# 其中-F 99是采样频率，这里指每秒采样99次; 也可以用--pid指定采样的进程id，此时perf会对该进程的所有线程进行采样

После запуска в текущем каталоге будет создан файл с именем perf.data.

Визуализируйте результаты:

Результаты профилирования можно проанализировать с помощью подкоманд, входящих в состав perf:

perf report \--stdio -i perf.data

Мы предпочитаем преобразовать его в график пламени:

# 将perf.data转成调用栈
perf script -i perf.data > perf.unfold
 
# clone FlameGraph
git clone https://github.com/brendangregg/FlameGraph
cd FlameGraph
  
# 假设perf.unfold放在了<result_dir>里
stackcollapse-perf.pl <result_dir>/perf.unfold > perf.fold
 
# 可以直接在speedscope里打开perf.fold，或者将其转化为svg:
# 将perf.fold转为svg文件
flamegraph.pl perf.fold > perf.svg

Для пользователей с версией ядра Linux выше или равной 5.8, perf поддерживает прямое преобразование результата в график пламени:

perf script report flamegraph -i perf.data

Для оптимизации программ на Python perf также имеет некоторые ограничения, поскольку perf не является профилировщиком, настроенным для python.Для вызовов функций на python perf сэмплирует стек вызовов интерпретатора CPython, поэтому невозможно напрямую увидеть конкретные функции Python. , как показано ниже показано:

Поэтому perf менее подходит для оптимизации чистого кода Python и больше подходит для наблюдения за потоками C/C++. Кроме того, команда perf record, использованная выше, выберет только стек вызовов процессорного времени программы.Если вы хотите наблюдать за внепроцессорным временем, вам нужно использовать команду perf trace, которая здесь не будет подробно описана. , пожалуйста, обратитесь к этой статье. статья:Woohoo. Брендан GRE Reform.com/blog/2015-0…. Пока perf не поддерживает одновременное наблюдение за процессорным и внепроцессорным временем, и эти два случая можно анализировать только независимо друг от друга.

5.5 systemtap

systemtap — это инструмент динамической трассировки для операционных систем. Он более мощный, и мы можем просто думать о systemtap как о программируемом трассировщике системного уровня. systemtap предоставляет язык сценариев, пользователи могут писать сценарии для отслеживания и мониторинга различных системных вызовов, вызовов функций пользовательского режима и других пользовательских событий. Таким образом, пользователи могут писать сценарии в соответствии со своими потребностями для получения различной информации, которую необходимо соблюдать при работе программы.Systemtap скомпилирует сценарии, написанные пользователями, в код C, затем скомпилирует их в модули ядра, а затем загрузит их. в середину работающего ядра операционной системы.

В этой статье мы не собираемся подробно знакомить с systemtap, мы сосредоточимся только на ее применении в профилировании (читатели, интересующиеся systemtap, могут обратиться кSystemTap Beginners Guide) Кроме того, в этой статье не будет показано, как написать скрипт для реализации профилировщика, команда openresty предоставляет набор инструментов systemtap (openresty-systemtap-toolkit) можно использовать напрямую.

Далее мы представляем установку systemtap и использование вышеуказанных наборов инструментов:

Установить системный тап:

sudo apt install systemtap systemtap-runtime

В дополнение к этому нам также необходимо установить различные зависимости ядра для среды выполнения systemtap: мы можем напрямую запускатьsudo stap-prepЧтобы установить зависимости, если эта команда не удалась, вам нужно установить ее вручную:

sudo apt install kernel-debuginfo-`uname -r`
sudo apt install kernel-debuginfo-common-`uname -r`
sudo apt install kernel-devel-`uname -r`

Для работы systemtap требуются привилегии sudo.Мы можем запустить следующую команду, чтобы проверить, прошла ли установка успешно:

sudo stap -e \'probe begin { printf(\"Hello, World!\\n\"); exit() }\'

Если Hello World выводится нормально, установка выполнена успешно.

Используйте системный тап:

Нам нужно использовать два инструмента, предоставляемых openresty-systemtap-toolkit:

git clone https://github.com/openresty/openresty-systemtap-toolkit.git
cd openresty-systemtap-toolkit
 
# 对程序cpu time的调用栈进行采样, 采样时间为10s, 采样对象为user space调用栈, 并将结果保存为cpu.bt
sudo ./sample_bt -u -t 10 -p PID > cpu.bt
 
# 对程序off cpu time的调用栈进行采样，采样时间为10s, 采样对象为user space调用栈，并将结果保存为off_cpu.bt
sudo ./sample_bt_off_cpu -u -t 10 -p PID > off_cpu.bt
 
# 命令中的-u选项指采样user space调用栈，还可以选择-k来采样kernel space的调用栈；-t指采样时间，这里都设置为10s；-p是待采样程序的pid

Подобно perf, systemtap работает в режиме ядра с очень низкими издержками. А для потоков Python systemtap также выбирает стек вызовов интерпретатора CPython, поэтому он больше подходит для наблюдения за потоками C/C++.

Визуализируйте результаты:

Метод визуализации похож на perf, а flamegraph поддерживает обработку вывода systemtap:

# 处理cpu.bt或off_cpu.bt
stackcollapse-stap.pl <result_dir>/cpu.bt > cpu.fold
 
# 可以直接在speedscope里打开cpu.fold，或者将其转化为svg:
# 将perf.fold转为svg文件
flamegraph.pl cpu.fold > cpu.svg

5.6 eu-stack

eu-стек это elfutils(sourceware.org/elfutils) набор инструментов, основной функцией которого является выборка стека вызовов программы:

eu-stack -p <pid>
 
#===== 可以得到类似下面的输入:
#0  0x00007f5f96bbadd7 __select
#1  0x00007f5f95868278 call_readline
#2  0x0000000000425182 PyOS_Readline
#3  0x00000000004a84aa tok_nextc.cold.140
#4  0x00000000005a7774 tok_get
#5  0x00000000005a8892 parsetok
#6  0x00000000006351bd PyParser_ASTFromFileObject
#7  0x00000000004ad729 PyRun_InteractiveOneObjectEx
#8  0x00000000004afbfe PyRun_InteractiveLoopFlags
#9  0x0000000000638cb3 PyRun_AnyFileExFlags
#10 0x0000000000639671 Py_Main
#11 0x00000000004b0e40 main
#12 0x00007f5f96ac5bf7 __libc_start_main
#13 0x00000000005b2f0a _start

В отличие от perf и systemtap, eu-stack по-прежнему может получать свой стек вызовов C/C++, даже если программа находится вне ЦП. Следовательно, мы можем написать простой скрипт для непрерывной выборки стека вызовов потока, чтобы реализовать профилировщик на основе выборки по времени настенных часов.

Простая реализация профайлера:

#!/bin/bash -xe
pid=$1
for x in $(seq 0 1000)
do
eu-stack -p $pid > d_$x.txt || true
sleep 0.2
done

Выполнение eu-stack не требует привилегий root, время однократного запуска составляет порядка десятков миллисекунд, а влияние на программу не слишком велико.

Инструкции:

# 1. 安装elfutils
sudo` `apt ``install` `elfutils

# 2. 运行上面的脚本
.``/profiler``.sh <pid>

Метод визуализации:

Flamegraph также поставляется с инструментом для обработки вывода eu-stack, который может преобразовывать собранные сэмплы в flamegraph, который также можно просмотреть в speedscope:

# 假设采样结果放在了<result_path>里
stackcollapse-elfutils.pl <result_path>/d*txt > eu_perf.txt
 
# 可视化：
# 方法1: use speedscope.app
# 直接在speedscope.app里打开eu_perf.txt即可
 
# 方法2: use flamegraph
flamegraph.pl eu_perf.txt output.svg
# 在浏览器里打开output.svg

6. Примеры

Наконец, представлен реальный пример оптимизации производительности в процессе разработки MegEngine, чтобы показать процесс от профилирования до поиска узких мест и оптимизации производительности.

В начале разработки MegEngine мы обнаружили, что скорость обучения модели обнаружения на одной машине с параллельными данными с 8 картами очень низкая, а время выполнения одного шага более чем в два раза больше, чем для одной карты. Нашим первым подозрением было влияние накладных расходов All Reduce при синхронизации градиентов между несколькими картами.Чтобы подтвердить это, мы отключили синхронизацию градиента между картами, чтобы сделать обучение каждой карты независимым друг от друга, и обнаружили, что скорость была лишь немного улучшена. , скорость 8 карт по-прежнему примерно в 2 раза выше, чем у одиночной карты.

Поскольку 8-карточное обучение запустит 8 процессов, чтобы полностью устранить помехи, вызванные возможной связью между 8 процессами, мы изменили 8-карточное обучение, чтобы начать 8 независимых однокарточных тренировок, и обнаружили, что скорость почти без изменений. Кроме того, мы также заметили, что время выполнения шага положительно связано с количеством инициированных тренировок с одной картой Скорость лишь немного медленнее, когда начинается обучение с 2 одиночными картами, и примерно на 50% медленнее, когда 4 одиночных. -карточное обучение начато.

Поэтому мы подозреваем, что замедление может быть вызвано конкуренцией за ресурсы ЦП между 8 процессами.Для подтверждения мы привязываем к каждому процессу одинаковое количество ядер ЦП, то есть количество ядер ЦП, используемых каждым процессом в одиночном режиме. процесс обучения и 8-процессное обучение.Количество ЦП остается прежним, и еще раз обнаруживается, что скорость почти не меняется, поэтому медленная скорость 8 карт не должна быть связана с конкуренцией за ресурсы ЦП.

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

  • Основной поток Python: выполнение сценария обучения Python и отправка задач в очередь
  • Рабочий поток: это чистый поток C++, отвечающий за получение задач из очереди и их выполнение.

Сначала мы профилировали основной поток Python.Так как мы хотели одновременно наблюдать за расширением C/C++, чистый профилировщик Python не мог удовлетворить наши потребности, поэтому мы использовали py-spy и включили параметр --idle, чтобы сделать так, чтобы результаты включали отключение выборок по времени процессора, и, наконец, получили следующие результаты:

Мы обнаружили, что основной поток тратит около 80% своего времени на ожидание, как показано красным прямоугольником на изображении выше. Есть два места, чтобы получить numpy ndarray тензора, и одно место, чтобы получить форму тензора, Ожидания в обоих случаях вызваны рабочим потоком синхронизации. В MegEngine основной поток отправляет команду, а воркер выполняет команду асинхронно.Когда нам нужно получить numpy ndarray тензора, нам нужно дождаться, пока воркер выполнит расчет на CUDA и скопирует результат в память, поэтому синхронизация будет активирована. Другая ситуация - получить форму тензора.Если форму вывода определенного оператора нельзя предсказать заранее, ему также необходимо дождаться, пока рабочий завершит расчет, чтобы узнать, поэтому синхронизация также будет запущена.

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

Поэтому мы планируем профилировать рабочий поток.Поскольку рабочий поток представляет собой чистый поток C/C++, нашими дополнительными инструментами являются perf, systemtap и eu-stack.Мы не уверены, связана ли проблема с процессорным или внепроцессорным временем. Чтобы иметь возможность наблюдать результаты двух состояний вместе, мы решили использовать eu-стек и получили следующие результаты:

Мы обнаружили, что рабочий поток проводит более 85% своего времени в том месте, где оператор topk вызывает cudaGetDeviceProperties (красная рамка на рисунке).После ознакомления с документом мы обнаружили, что накладные расходы этого API относительно велики, и io трафик будет возникать при одновременном вызове нескольких процессов Конкуренция, поэтому потребление времени ioctl в 8 процессах слишком велико. Впоследствии мы модифицировали реализацию topk (commit), избегаем вызова cudaGetDeviceProperties, а затем снова тестируем, и обнаруживаем, что скорость работы модели возвращается к норме: скорость одного процесса увеличивается примерно на 13%, а скорость 8 процессов увеличивается более чем в 1 раз.

7. Ссылки

Добро пожаловать, друзья, присоединяйтесь к нам MegEngine Megvii Tianyuan по обмену разработчиками Группа QQ: 1029741705

Для связи или отзывов, связанных с использованием фреймворка, посетите форум:обсудить.Meg engine.org.capable;Адрес проекта на GitHub:GitHub.com/Мег двигатель/М…; Официальный сайт MegEngine:megengine.org.cn/ ~~~

Категории