Профилирование
Модуль Profile предоставляет инструменты, которые помогут разработчикам улучшить производительность их кода. При использовании он производит измерения работающего кода и создаёт вывод, который помогает понять, сколько времени тратится на отдельные строку(и). Наиболее распространённое использование — идентификация «узких мест» для оптимизации.
Profile реализует то, что известно как «выборочный» или статистический профилировщик. Он работает путём периодического взятия трассировки стека во время выполнения любой задачи. Каждая трассировка стека захватывает текущую выполняемую функцию и номер строки, а также полную цепочку вызовов функций, которые привели к этой строке, и, следовательно, является «мгновенным снимком» текущего состояния выполнения.
Если большая часть времени выполнения затрачивается на выполнение определённой строки кода, эта строка будет часто появляться в наборе всех трассировок стека. Другими словами, «стоимость» заданной строки — или, точнее, стоимость последовательности вызовов функций, включая эту строку, — пропорциональна тому, насколько часто она появляется в наборе всех трассировок стека.
Выборочный профилировщик не предоставляет полное строчно-построчное покрытие, так как трассировки стека происходят через определённые интервалы (по умолчанию 1 мс на системах Unix и 10 мс на Windows, хотя фактическое планирование зависит от нагрузки операционной системы). Кроме того, как обсуждается ниже, поскольку выборки собираются в разрозненном подмножестве всех точек выполнения, данные, собранные выборочным профилировщиком, подвержены статистическому шуму.
Несмотря на эти ограничения, у выборочных профилировщиков есть существенные преимущества:
- Для взятия измерений времени выполнения не требуется никаких изменений в вашем коде.
- Он может профилировать код ядра Julia и даже (по желанию) в библиотеках C и Fortran.
- Благодаря «редкому» выполнению накладные расходы на производительность очень малы; во время профилирования ваш код может выполняться практически с исходной скоростью.
По этим причинам рекомендуется попробовать использовать встроенный выборочный профилировщик, прежде чем рассматривать какие-либо альтернативы.
Основные возможности
Давайте поработаем с простым тестовым случаем:
julia> function myfunc()
A = rand(200, 200, 400)
maximum(A)
end
Хорошо сначала запустить код, который вы хотите профилировать, по крайней мере, один раз (если вы не хотите профилировать JIT-компилятор Julia):
julia> myfunc() # run once to force compilation
Теперь мы готовы профилировать эту функцию:
julia> using Profile julia> @profile myfunc()
Чтобы увидеть результаты профилирования, доступен графический браузер, но здесь мы будем использовать текстовый вывод, который поставляется со стандартной библиотекой:
julia> Profile.print()
80 ./event.jl:73; (::Base.REPL.##1#2{Base.REPL.REPLBackend})()
80 ./REPL.jl:97; macro expansion
80 ./REPL.jl:66; eval_user_input(::Any, ::Base.REPL.REPLBackend)
80 ./boot.jl:235; eval(::Module, ::Any)
80 ./<missing>:?; anonymous
80 ./profile.jl:23; macro expansion
52 ./REPL[1]:2; myfunc()
38 ./random.jl:431; rand!(::MersenneTwister, ::Array{Float64,3}, ::Int64, ::Type{B...
38 ./dSFMT.jl:84; dsfmt_fill_array_close_open!(::Base.dSFMT.DSFMT_state, ::Ptr{F...
14 ./random.jl:278; rand
14 ./random.jl:277; rand
14 ./random.jl:366; rand
14 ./random.jl:369; rand
28 ./REPL[1]:3; myfunc()
28 ./reduce.jl:270; _mapreduce(::Base.#identity, ::Base.#scalarmax, ::IndexLinear,...
3 ./reduce.jl:426; mapreduce_impl(::Base.#identity, ::Base.#scalarmax, ::Array{F...
25 ./reduce.jl:428; mapreduce_impl(::Base.#identity, ::Base.#scalarmax, ::Array{F...
Каждая строка этого вывода представляет собой определённую точку (номер строки) в коде. Отступы используются для обозначения вложенной последовательности вызовов функций, причём более отступающие строки находятся глубже в последовательности вызовов. В каждой строке первое «поле» — количество трассировок стека (выборок), взятых в этой строке или в любых функциях, выполняемых этой строкой. Второе поле — имя файла и номер строки, а третье поле — имя функции. Обратите внимание, что конкретные номера строк могут меняться по мере изменения кода Julia; если вы хотите следовать за примером, лучше всего запустить этот пример самостоятельно.
В этом примере мы видим, что функция верхнего уровня вызывается в файле event.jl. Это функция, которая запускает REPL при запуске Julia. Если вы изучите строку 97 файла REPL.jl, вы увидите, что здесь вызывается функция eval_user_input(). Это функция, которая оценивает то, что вы вводите в REPL, и так как мы работаем интерактивно, эти функции были вызваны при вводе @profile myfunc(). Следующая строка отражает действия, выполненные в макросе @profile.
Первая строка показывает, что 80 трассировок стека были взяты в строке 73 файла event.jl, но это не значит, что эта строка была «дорогой» сама по себе: третья строка показывает, что все 80 этих трассировок стека фактически были вызваны внутри её вызова функции eval_user_input, и так далее. Чтобы узнать, какие операции фактически занимают время, нам нужно посмотреть глубже в цепочке вызовов.
Первая «важная» строка в этом выводе такая:
52 ./REPL[1]:2; myfunc()
REPL относится к тому факту, что мы определили myfunc в REPL, а не поместили его в файл; если бы мы использовали файл, здесь было бы показано имя файла. [1] показывает, что функция myfunc была первым выражением, оценённым в этом сеансе REPL. Строка 2 файла myfunc() содержит вызов функции rand, и 52 (из 80) трассировок стека произошли в этой строке. Ниже вы можете увидеть вызов функции dsfmt_fill_array_close_open! внутри dSFMT.jl.
Немного ниже вы видите:
28 ./REPL[1]:3; myfunc()
Строка 3 файла myfunc содержит вызов функции maximum, и здесь были взяты 28 (из 80) трассировок стека. Ниже вы можете увидеть конкретные места в base/reduce.jl, которые выполняют трудоёмкие операции в функции maximum для этого типа входных данных.
В целом, мы можем предварительно заключить, что генерация случайных чисел примерно в два раза дороже, чем поиск максимального элемента. Мы могли бы увеличить уверенность в этом результате, собрав больше выборок:
julia> @profile (for i = 1:100; myfunc(); end)
julia> Profile.print()
[....]
3821 ./REPL[1]:2; myfunc()
3511 ./random.jl:431; rand!(::MersenneTwister, ::Array{Float64,3}, ::Int64, ::Type...
3511 ./dSFMT.jl:84; dsfmt_fill_array_close_open!(::Base.dSFMT.DSFMT_state, ::Ptr...
310 ./random.jl:278; rand
[....]
2893 ./REPL[1]:3; myfunc()
2893 ./reduce.jl:270; _mapreduce(::Base.#identity, ::Base.#scalarmax, ::IndexLinea...
[....]
В общем случае, если у вас N выборок, собранных в строке, вы можете ожидать неопределённости порядка sqrt(N) (исключая другие источники шума, например, насколько занят компьютер другими задачами). Основным исключением из этого правила является сборка мусора, которая выполняется редко, но часто бывает довольно дорогостоящей. (Так как сборщик мусора Julia написан на C, такие события можно обнаружить, используя режим вывода C=true , описанный ниже, или используя ProfileView.jl.)
Это демонстрирует стандартный вывод «дерева»; альтернативой является «плоский» вывод, который накапливает подсчёты независимо от их вложенности:
julia> Profile.print(format=:flat)
Count File Line Function
6714 ./<missing> -1 anonymous
6714 ./REPL.jl 66 eval_user_input(::Any, ::Base.REPL.REPLBackend)
6714 ./REPL.jl 97 macro expansion
3821 ./REPL[1] 2 myfunc()
2893 ./REPL[1] 3 myfunc()
6714 ./REPL[7] 1 macro expansion
6714 ./boot.jl 235 eval(::Module, ::Any)
3511 ./dSFMT.jl 84 dsfmt_fill_array_close_open!(::Base.dSFMT.DSFMT_s...
6714 ./event.jl 73 (::Base.REPL.##1#2{Base.REPL.REPLBackend})()
6714 ./profile.jl 23 macro expansion
3511 ./random.jl 431 rand!(::MersenneTwister, ::Array{Float64,3}, ::In...
310 ./random.jl 277 rand
310 ./random.jl 278 rand
310 ./random.jl 366 rand
310 ./random.jl 369 rand
2893 ./reduce.jl 270 _mapreduce(::Base.#identity, ::Base.#scalarmax, :...
5 ./reduce.jl 420 mapreduce_impl(::Base.#identity, ::Base.#scalarma...
253 ./reduce.jl 426 mapreduce_impl(::Base.#identity, ::Base.#scalarma...
2592 ./reduce.jl 428 mapreduce_impl(::Base.#identity, ::Base.#scalarma...
43 ./reduce.jl 429 mapreduce_impl(::Base.#identity, ::Base.#scalarma...
Если ваш код имеет рекурсию, одним потенциально путающим моментом является то, что строка в «дочерней» функции может накапливать больше подсчётов, чем общее количество трассировок стека. Рассмотрим следующие определения функций:
dumbsum(n::Integer) = n == 1 ? 1 : 1 + dumbsum(n-1) dumbsum3() = dumbsum(3)
Если вы хотите профилировать dumbsum3, и при выполнении dumbsum(1) была взята трассировка стека, то трассировка стека будет выглядеть так:
dumbsum3
dumbsum(3)
dumbsum(2)
dumbsum(1)
Следовательно, эта дочерняя функция получает 3 подсчёта, даже если родительская получает только один. Представление «дерева» делает это гораздо понятнее, и по этой причине (среди прочего) является, вероятно, наиболее полезным способом просмотра результатов.
Накопление и очистка
Результаты от @profile накапливаются в буфере; если вы запускаете несколько фрагментов кода под @profile, то Profile.print() покажет вам объединённые результаты. Это может быть очень полезно, но иногда вы хотите начать сначала; вы можете сделать это с помощью Profile.clear().
Параметры управления отображением результатов профилирования
Profile.print имеет больше параметров, чем мы описали до сих пор. Давайте посмотрим на полное объявление:
function print(io::IO = stdout, data = fetch(); kwargs...)
Давайте сначала обсудим два позиционных аргумента, а затем ключевые аргументы:
io— позволяет сохранять результаты в буфер, например, в файл, но по умолчанию вывод печатается вstdout(консоль).-
data— содержит данные, которые вы хотите проанализировать; по умолчанию они получаются изProfile.fetch(), который извлекает трассировки стека из предварительно выделенного буфера. Например, если вы хотите профилировать профилировщик, вы можете сказать:data = copy(Profile.fetch()) Profile.clear() @profile Profile.print(stdout, data) # Prints the previous results Profile.print() # Prints results from Profile.print()
Ключевые аргументы могут быть любой комбинацией:
-
format— введённый выше, определяет, будут ли трассировки стека выведены с (по умолчанию,:tree) или без (:flat) отступов, указывающих на структуру дерева. -
C— Еслиtrue, трассировки стека из кода C и Fortran будут показаны (обычно они исключаются). Попробуйте запустить вводный пример сProfile.print(C = true). Это может быть очень полезно для принятия решения, код Julia или C вызывает узкое место; установкаC = trueтакже улучшает интерпретируемость вложенности, ценой более длинных выводов профиля. -
combine— Некоторые строки кода содержат несколько операций; например,s += A[i]содержит как обращение к массиву (A[i]), так и операцию сложения. Они соответствуют разным строкам в сгенерированном машинном коде, и поэтому при трассировках стека в этой строке могут быть захвачены два или более разных адреса.combine = trueобъединяет их, и это, вероятно, то, что вам обычно нужно, но вы можете сгенерировать вывод для каждой уникальной точки входа сcombine = false. -
maxdepth— ограничение кадров на глубине болееmaxdepthв формате:tree. -
sortedby— управление порядком в формате:flat.:filefuncline(по умолчанию) сортирует по исходной строке, а:countсортирует в порядке количества собранных выборок. -
noisefloor— ограничение кадров, которые находятся ниже эвристического порога шума выборки (применяется только к формату:tree). Предлагаемое значение для этого параметра — 2.0 (по умолчанию 0). Этот параметр скрывает выборки, для которыхn <= noisefloor * √N, гдеn— количество выборок в этой строке, аN— количество выборок для вызываемой функции. -
mincount— ограничение кадров с менее чемmincountвхождениями.
Имена файлов/функций иногда усекаются (с ...), а отступы усекаются с +n в начале, где n — количество дополнительных пробелов, которые были бы вставлены, если бы места хватило. Если вы хотите получить полный профиль глубоко вложенного кода, часто хорошей идеей является сохранение в файл с широким displaysize в IOContext:
open("/tmp/prof.txt", "w") do s
Profile.print(IOContext(s, :displaysize => (24, 500)))
end
Конфигурация
@profile просто накапливает трассировки стека, а анализ происходит при вызове Profile.print(). Для длительных вычислений вполне вероятно, что предварительно выделенный буфер для хранения трассировок стека заполнится. Если это произойдёт, трассировки стека прекратятся, но ваши вычисления продолжатся. Вследствие этого, вы можете пропустить некоторые важные данные профилирования (вы получите предупреждение, когда это произойдёт).
Вы можете получить и настроить соответствующие параметры следующим образом:
Profile.init() # returns the current settings Profile.init(n = 10^7, delay = 0.01)
n — это общее количество указателей инструкций, которые вы можете сохранить, со значением по умолчанию 10^6. Если типичная трассировка стека содержит 20 указателей инструкций, то вы можете собрать 50000 трассировок стека, что предполагает статистическую неопределённость менее 1%. Это может быть достаточно для большинства приложений.
Следовательно, вам, скорее всего, потребуется изменить delay, выраженное в секундах, что задаёт интервал времени, за который Julia получает снимки для выполнения запрошенных вычислений. Для очень длительных задач может не потребоваться частые трассировки стека. Значение по умолчанию составляет delay = 0.001. Конечно, вы можете как уменьшить, так и увеличить задержку; однако издержки профилирования возрастают, когда задержка становится сопоставимой со временем, необходимым для создания трассировки стека (~30 микросекунд на ноутбуке автора).
Анализ распределения памяти
Один из наиболее распространённых методов повышения производительности заключается в уменьшении распределения памяти. Общий объём распределения можно измерить с помощью @time и @allocated, а конкретные строки, вызывающие распределение, часто можно определить из профилирования по стоимости сборок мусора, которые эти строки несут. Однако иногда эффективнее непосредственно измерить количество памяти, распределяемой каждой строкой кода.
Для измерения распределения по строкам начните Julia с опцией командной строки --track-allocation=<setting>, для которой вы можете выбрать none (по умолчанию, не измерять распределение), user (измерять распределение памяти везде, кроме ядра Julia), или all (измерять распределение памяти в каждой строке кода Julia). Распределение измеряется для каждой строки скомпилированного кода. При выходе из Julia кумулятивные результаты записываются в текстовые файлы с .mem, добавленным после имени файла, в той же директории, что и исходный файл. Каждая строка содержит общее количество распределённых байтов. Coverage пакет содержит некоторые базовые инструменты анализа, например, для сортировки строк по количеству распределённых байтов.
При интерпретации результатов есть несколько важных моментов. В настройке user первая строка любой функции, непосредственно вызываемой из REPL, будет демонстрировать распределение из-за событий, происходящих в самом коде REPL. Более существенно, что JIT-компиляция также добавляет к значениям распределения, потому что большая часть компилятора Julia написана на Julia (а компиляция обычно требует распределения памяти). Рекомендуемая процедура заключается в принудительной компиляции путём выполнения всех команд, которые вы хотите проанализировать, а затем вызов Profile.clear_malloc_data() для сброса всех счётчиков распределения. Наконец, выполните желаемые команды и выйдите из Julia, чтобы запустить генерацию файлов .mem.
Внешнее профилирование
В настоящее время Julia поддерживает Intel VTune, OProfile и perf в качестве инструментов внешнего профилирования.
В зависимости от выбранного инструмента, компилируйте с USE_INTEL_JITEVENTS, USE_OPROFILE_JITEVENTS и USE_PERF_JITEVENTS установленными в 1 в Make.user. Поддерживается несколько флагов.
Перед запуском Julia установите переменную среды ENABLE_JITPROFILING в 1.
Теперь у вас есть множество способов использования этих инструментов! Например, с OProfile вы можете попробовать простое протоколирование:
>ENABLE_JITPROFILING=1 sudo operf -Vdebug ./julia test/fastmath.jl >opreport -l `which ./julia`
Или аналогично с perf:
$ ENABLE_JITPROFILING=1 perf record -o /tmp/perf.data --call-graph dwarf ./julia /test/fastmath.jl $ perf report --call-graph -G
Существует множество других интересных вещей, которые можно измерить о вашей программе. Для получения полного списка прочитайте страницу примеров Linux perf здесь.
Помните, что perf сохраняет для каждого выполнения файл perf.data, который, даже для небольших программ, может стать довольно большим. Также модуль perf LLVM временно сохраняет объекты отладки в ~/.debug/jit, помните о необходимости часто очищать эту папку.
© 2009–2020 Jeff Bezanson, Stefan Karpinski, Viral B. Shah, and other contributors
Licensed under the MIT License.
https://docs.julialang.org/en/v1.4.2/manual/profile/
