python

Разработка графического профайлера Python FunctionTrace

  • вторник, 6 октября 2020 г. в 00:31:35
https://habr.com/ru/company/skillfactory/blog/521836/
  • Блог компании SkillFactory
  • Firefox
  • Open source
  • Python
  • Программирование




Сегодня мы делимся с вами переводом статьи создателя FunctionTrace — профайлера Python с интуитивно понятным графическим интерфейсом, который может профилировать многопроцессорные и многопоточные приложения и потребляет на порядок меньше ресурсов, чем другие профайлеры Python. Неважно, только учитесь ли вы веб-разработке на Python, либо уже давно используете его — всегда полезно понимать, что делает ваш код. О том, как появился этот проект, о деталях его разработки — далее под катом.


Введение


Профайлер Firefox стал краеугольным камнем работы Firefox во времена Project Quantum. Когда вы открываете запись примера, то видите мощный веб-интерфейс анализа производительности, включающий деревья вызовов, диаграммы стека, огненные диаграммы и многое другое. Все действия по фильтрации данных, масштабированию, разрезанию и преобразованию сохраняются по URL, которым можно поделиться. О результатах можно рассказать в баг-репорте, задокументировать свои выводы, сравнить с другими записями или передать информацию для дальнейшего исследования. Firefox DevEdition имеет встроенный поток профилирования. Этот поток делает коммуникации удобными. Наша цель — дать возможность всем разработчикам, даже за пределами Firefox, сотрудничать в смысле производительности.

Раньше Firefox Profiler импортировал другие форматы, начиная с Linux perf и профилей Chrome. Со временем разработчики добавили больше форматов. Сегодня появляются первые проекты, адаптирующие Firefox для инструментов анализа. FunctionTrace — один из таких проектов. Мэтт рассказывает историю создания инструмента.

FunctionTrace


Недавно я создал инструмент, помогающий разработчикам лучше понять, что происходит в их коде на Python. FunctionTrace — это профайлер без семплирования для Python, который работает на немодифицированных приложениях с очень низкими накладными расходами — менее 5%. Важно отметить, что он интегрирован с Firefox Profiler. Это позволяет взаимодействовать с профилями графически, облегчая обнаружение шаблонов и внесение изменений в кодовую базу.

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


Пример профиля FunctionTrace, открытого в Firefox Profiler.

Технический долг как мотивация


Со временем кодовые базы, как правило, становятся больше. Особенно при работе над сложными проектами с большим количеством людей. Некоторые языки лучше справляются с этой проблемой. Например, возможности IDE Java разрабатывались десятилетиями. Или Rust и его сильная типизация, которая делает рефакторинг очень легким. Иногда кажется, что по мере роста кодовые базы на других языках все сложнее поддерживать. Это особенно верно для старого кода Python. По крайней мере, мы все сейчас на Python 3, верно?

Вносить масштабные изменения или делать рефакторинг незнакомого кода может быть чрезвычайно сложно. Мне гораздо проще правильно изменять код, когда я вижу все взаимодействия программы и то, что она делает. Часто я даже обнаруживаю, что переписываю куски кода, которые вообще не собирался трогать: неэффективность очевидна, когда я вижу ее в визуализации.

Я хотел понимать, что происходит в коде, без необходимости читать сотни файлов. Но не нашел инструменты, соответствующие моим потребностям. Кроме того, я потерял интерес к созданию такого инструмента самостоятельно из-за объема работы с пользовательским интерфейсом. А интерфейс был необходим. Мои надежды на быстрое понимание выполнения программы возродились, когда я наткнулся на профайлер Firefox.

Профайлер предоставил все тяжелые в реализации элементы — интуитивно понятный пользовательский интерфейс с открытым исходным кодом, который отображает графики стека, привязанные ко времени маркеры лога, огненные диаграммы и дает стабильность, природа которой — привязка к известному веб-браузеру. Любой инструмент, способный записывать правильно отформатированный JSON-профиль, может повторно использовать все упомянутые ранее возможности графического анализа.

Дизайн FunctionTrace


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

Цели


У нас было несколько целей, когда мы начали разработку FunctionTrace:

  1. Возможность видеть все происходящее в программе.
  2. Обрабатывать программы с многопоточным и многопроцессорным исполнением.
  3. Низкий оверхед, чтобы работать без компромиссов с производительностью.

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

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

Первоначальная реализация


Чтобы поддерживать множество процессов и потомков мы остановились на клиент-серверной модели. Клиенты Python посылают данные трассировки на сервер Rust. Сервер агрегирует и сжимает данные перед созданием профиля, который может потребляться профайлеру Firefox. Мы выбрали Rust по нескольким причинам, включая сильную типизацию, стремление к стабильной производительности и предсказуемое использованию памяти, а также легкость прототипирования и рефакторинга.

Мы прототипировали клиента как модуль Python, вызываемый python -m functiontrace code.py. Это позволило легко пользоваться встроенными хуками трассировки для логирования выполнения. Первоначальная реализация была похожа на это:

def profile_func(frame, event, arg):
    if event == "call" or event == "return" or event == "c_call" or event == "c_return":
        data = (event, time.time())
        server.sendall(json.dumps(data))

sys.setprofile(profile_func)


На сервере прослушивается доменный сокет Unix. Затем с клиента считываются данные и конвертируются в JSON профайлера Firefox.

Профайлер поддерживает различные типы профилей, например, perf logs. Но мы решили генерировать JSON внутреннего формата профайлера. Он требует меньше места и сопровождения, чем добавление нового поддерживаемого формата. Важно отметить, что профайлер поддерживает обратную совместимость версий профилей. Это означает, что любой профиль, предназначенный для текущей версии формата, при загрузке в будущем автоматически конвертируется в последнюю версию. Также профайлер ссылается на строки целочисленными идентификаторами. Это позволяет значительно сэкономить место с помощью дедупликации (при этом тривиально использовать indexmap).

Несколько оптимизаций


В основном первоначальный код работал. При каждом вызове функции и возврате Python вызывал хук. Хук посылал серверу JSON-сообщение через сокет, чтобы преобразовать его в нужный формат. Но это было невероятно медленно. Даже после пакетирования вызовов сокетов мы наблюдали, как минимум, восьмикратные накладные расходы на некоторые тестовые программы.

Увидев такие расходы, мы опустились на уровень C с помощью C API для Python. И получили коэффициент оверхеда 1,1 на тех же программах. После этого мы смогли провести еще одну ключевую оптимизацию, заменив вызовы time.time() на rdtsc операции через clock_gettime(). Мы снизили накладные расходы на производительность при вызове функций до нескольких инструкций и генерации 64 бит данных. Это гораздо эффективнее, чем цепь вызовов Python и сложная арифметика на критически важном пути выполнения.

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

Поддержка нескольких потоков


Обработчик на все потоки устанавливается через threading.setprofile(). Мы регистрируемся через подобный этому обработчик, когда настраиваем состояние потока. Так мы убеждаемся, что Python запущен, а GIL удерживается. Это позволяет упростить некоторые допущения:

// This is installed as the setprofile() handler for new threads by
// threading.setprofile().  On its first execution, it initializes tracing for
// the thread, including creating the thread state, before replacing itself with
// the normal Fprofile_FunctionTrace handler.
static PyObject* Fprofile_ThreadFunctionTrace(..args..) {
    Fprofile_CreateThreadState();

    // Replace our setprofile() handler with the real one, then manually call
    // it to ensure this call is recorded.
    PyEval_SetProfile(Fprofile_FunctionTrace);
    Fprofile_FunctionTrace(..args..);
    Py_RETURN_NONE;
}


При вызове хук Fprofile_ThreadFunctionTrace(), он выделяет структуру ThreadState. Эта структура содержит информацию, необходимую потоку для логирования событий и связи с сервером. Затем мы отправляем инициализирующее сообщение на сервер профиля. Здесь мы уведомляем сервер о запуске нового потока и предоставляем некоторую начальную информацию: время, PID и т.д. После инициализации мы заменяем хук на Fprofile_FunctionTrace(), который выполняет реальную трассировку.

Поддержка дочерних процессов


При работе с несколькими процессами мы предполагаем, что дочерние процессы запускаются через интерпретатор Python. К сожалению, дочерние процессы не вызываются с -m functiontrace, поэтому мы не знаем, как их отследить. Чтобы гарантировать отслеживание дочерних процессов, при запуске изменяется переменная среды $PATH. Это гарантирует, что Python указывает на исполняемый файл, который знает о functiontrace:

# Generate a temp directory to store our wrappers in.  We'll temporarily
# add this directory to our path.
tempdir = tempfile.mkdtemp(prefix="py-functiontrace")
os.environ["PATH"] = tempdir + os.pathsep + os.environ["PATH"]

# Generate wrappers for the various Python versions we support to ensure
# they're included in our PATH.
wrap_pythons = ["python", "python3", "python3.6", "python3.7", "python3.8"]
for python in wrap_pythons:
    with open(os.path.join(tempdir, python), "w") as f:
        f.write(PYTHON_TEMPLATE.format(python=python))
        os.chmod(f.name, 0o755)


Интерпретатор с аргументом -m functiontrace вызывается внутри обёртки. В завершение при запуске добавляется переменная окружения. В переменной указано, какой сокет используется для связи с сервером профилей. Если клиент инициализируется и видит уже установленную переменную окружения, он распознает дочерний процесс. Затем он подключается к существующему экземпляру сервера, позволяя соотнести его трассировку с трассировкой оригинального клиента.

FunctionTrace сейчас


Реализация FunctionTrace сегодня имеет много общего с описанной выше реализацией. На высоком уровне клиент отслеживается через FunctionTrace при вызове вот так: python -m functiontrace code.py. Эта строка загружает модуль Python для некоторых настроек, а затем вызывает модуль на C для установки различных хуков трассировки. Эти хуки включают в себя упомянутые выше sys.setprofile, хуки выделения памяти, а также пользовательские хуки с интересными функциями, такими как builtins.print или builtins.__import__. Кроме того, порождается экземпляр functiontrace-server, устанавливается сокет для коммуникации с ним и гарантируется, что будущие потоки и дочерние процессы ведут коммуникации с тем же сервером.

При каждом событии трассировки клиент Python посылает запись MessagePack. Она содержит минимальную информацию о событиях и временную метку в потоковом буфере памяти. Когда буфер заполняется (каждые 128KB), он сбрасывается на сервер через общий сокет, и клиент продолжает выполнять свою работу. Сервер асинхронно прослушивает каждого клиента, быстро поглощая трассировки в отдельный буфер, чтобы избежать их блокировки. Затем поток, соответствующий каждому клиенту, может разобрать каждое событие трассировки и преобразовать его в соответствующий конечный формат. После выхода всех подключенных клиентов, логи по каждой теме объединяются в полный лог профиля. Наконец, все это отправляется в файл, который затем может использоваться с профайлером Firefox.

Извлеченные уроки


Модуль Python на C дает значительно большую мощность и производительность, но в то же время имеет высокую стоимость. Требуется больше кода, сложнее найти хорошую документацию, немногие функции легко доступны. Модули на C кажутся недостаточно используемым инструментом для написания высокопроизводительных модулей Python. Я говорю это, основываясь на некоторых профилях FunctionTrace, которые я видел. Мы рекомендуем соблюдать баланс. Напишите большую часть непроизводительного критически важного кода на Python и вызовите внутренние циклы или установочный код на C для тех частей программы, где Python не блещет.

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

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

image

Получить востребованную профессию с нуля или Level Up по навыкам и зарплате, можно пройдя онлайн-курсы SkillFactory:


Eще курсы