GHC поставляется с системой профилирования времени и памяти, позволяющей ответить на вопросы типа «почему моя программа работает так медленно?» или «почему моя программа потребляет так много памяти?». Начнём с описания профилирования времени.
Профилирование времени программы — это трёхэтапный процесс:
- Перекомпилируйте программу для профилирования с помощью опции
-profи, вероятно, одной из опций для добавления автоматических аннотаций: рекомендуемая опция —-fprof-late. -
После компиляции программы для профилирования, вам необходимо запустить её для генерации профиля. Например, простой профиль времени можно создать, запустив программу с помощью
+RTS -p(см.-p), что сгенерирует файл с именемprog.prof, где ⟨prog⟩ — имя вашей программы (без расширения.exe, если вы работаете в Windows).Существует множество различных типов профилей, которые могут быть сгенерированы с помощью различных опций RTS. Мы будем описывать различные типы профилей в течение этой главы. Некоторые профили требуют дальнейшей обработки с использованием дополнительных инструментов после запуска программы.
- Проанализируйте сгенерированную информацию о профилировании, используйте её для оптимизации программы и повторите при необходимости.
Профилировщик времени измеряет время ЦП, затрачиваемое кодом Haskell в вашем приложении. В частности, время, затраченное на безопасные внешние вызовы, не отслеживается профилировщиком (см. Профилирование и внешние вызовы).
8.1. Центры затрат и стеки центров затрат
Система профилирования GHC назначает затраты центрам затрат. Затраты — это просто время или память (в байтах), необходимые для вычисления выражения. Центры затрат — это програмные аннотации вокруг выражений; все затраты, понесенные аннотированным выражением, присваиваются окружающему центру затрат. Кроме того, GHC будет запоминать стек окружающих центров затрат для любого данного выражения во время выполнения и генерировать дерево вызовов с присвоением затрат.
Давайте рассмотрим пример:
main = print (fib 30) fib n = if n < 2 then 1 else fib (n-1) + fib (n-2)
Компилируйте и запускайте эту программу следующим образом:
$ ghc -prof -fprof-auto -rtsopts Main.hs $ ./Main +RTS -p 121393 $
Когда GHC-скомпилированная программа запускается с опцией RTS -p, она генерирует файл с именем prog.prof. В этом случае файл будет содержать что-то вроде этого:
Wed Oct 12 16:14 2011 Time and Allocation Profiling Report (Final)
Main +RTS -p -RTS
total time = 0.68 secs (34 ticks @ 20 ms)
total alloc = 204,677,844 bytes (excludes profiling overheads)
COST CENTRE MODULE %time %alloc
fib Main 100.0 100.0
individual inherited
COST CENTRE MODULE no. entries %time %alloc %time %alloc
MAIN MAIN 102 0 0.0 0.0 100.0 100.0
CAF GHC.IO.Handle.FD 128 0 0.0 0.0 0.0 0.0
CAF GHC.IO.Encoding.Iconv 120 0 0.0 0.0 0.0 0.0
CAF GHC.Conc.Signal 110 0 0.0 0.0 0.0 0.0
CAF Main 108 0 0.0 0.0 100.0 100.0
main Main 204 1 0.0 0.0 100.0 100.0
fib Main 205 2692537 100.0 100.0 100.0 100.0
Первая часть файла содержит имя программы и опции, а также общее время и общее выделение памяти, измеренные во время выполнения программы (обратите внимание, что общее выделение памяти не равно количеству активной памяти, необходимой программе в любой момент времени; последнее можно определить с помощью профилирования кучи, которое мы опишем позже в Профилирование использования памяти).
Вторая часть файла — это разбиение по центрам затрат наиболее дорогостоящих функций в программе. В этом случае в программе была только одна значимая функция, а именно fib, и она была ответственна за 100% как затрат времени, так и затрат выделения памяти программы.
Третья и последняя секция файла предоставляет разбиение по стеку центра затрат. Это примерно профиль дерева вызовов программы. В приведённом примере ясно, что дорогостоящий вызов fib пришёл из main.
Затраты времени и выделения памяти для заданной части программы отображаются двумя способами: «индивидуальные», которые представляют затраты, понесенные кодом, охваченным этим стеком центра затрат, и «унаследованные», которые включают затраты всех дочерних элементов этого узла.
Полезность стеков центров затрат лучше демонстрируется путём незначительного изменения примера:
main = print (f 30 + g 30)
where
f n = fib n
g n = fib (n `div` 2)
fib n = if n < 2 then 1 else fib (n-1) + fib (n-2)
Скомпилируйте и запустите эту программу, как и прежде, и посмотрите на новые результаты профилирования:
COST CENTRE MODULE no. entries %time %alloc %time %alloc
MAIN MAIN 102 0 0.0 0.0 100.0 100.0
CAF GHC.IO.Handle.FD 128 0 0.0 0.0 0.0 0.0
CAF GHC.IO.Encoding.Iconv 120 0 0.0 0.0 0.0 0.0
CAF GHC.Conc.Signal 110 0 0.0 0.0 0.0 0.0
CAF Main 108 0 0.0 0.0 100.0 100.0
main Main 204 1 0.0 0.0 100.0 100.0
main.g Main 207 1 0.0 0.0 0.0 0.1
fib Main 208 1973 0.0 0.1 0.0 0.1
main.f Main 205 1 0.0 0.0 100.0 99.9
fib Main 206 2692537 100.0 99.9 100.0 99.9
Теперь, хотя у нас было два вызова fib в программе, сразу же становится ясно, что вызов из f потребовал всего времени. Функциям f и g, определённым в where секции в main, присваиваются свои собственные центры затрат main.f и main.g соответственно.
Фактическое значение различных столбцов в выводе:
Количество раз, когда эта конкретная точка в дереве вызовов была введена.
Процент общего времени выполнения программы, затраченного в этой точке дерева вызовов.
Процент от общего выделения памяти (за исключением накладных расходов профилирования) программы, выполненный этим вызовом.
Процент общего времени выполнения программы, затраченного ниже этой точки в дереве вызовов.
Процент общего выделения памяти (за исключением накладных расходов профилирования) программы, выполненный этим вызовом и всеми его подвызовами.
Кроме того, вы можете использовать опцию RTS -P, чтобы получить следующую дополнительную информацию:
-
ticks -
Исходное количество «тиков» времени, которые были присвоены этому центру затрат; из этого мы получаем значение
%time, упомянутое выше. -
bytes -
Количество байтов, выделенных в куче во время нахождения в этом центре затрат; опять же, это исходное число, из которого мы получаем значение
%alloc, упомянутое выше.
Что насчёт рекурсивных функций и взаимно рекурсивных групп функций? Где присваиваются затраты? Ну, хотя GHC и сохраняет информацию о том, какие группы функций рекурсивно вызывали друг друга, эта информация не отображается в базовом профиле времени и выделения памяти; вместо этого граф вызовов сглаживается в дерево следующим образом: вызов функции, который происходит где-то в текущем стеке, не добавляет ещё одну запись в стек; вместо этого затраты на этот вызов агрегируются в вызывающую функцию [2].
8.1.1. Вставка центров затрат вручную
Центры затрат — это просто аннотации программы. Когда вы говорите -fprof-auto компилятору, он автоматически вставляет аннотацию центра затрат вокруг каждой привязки, не помеченной INLINE в вашей программе, но вы полностью свободны добавлять аннотации центров затрат самостоятельно. Будьте осторожны, добавляя слишком много аннотаций центров затрат, так как оптимизатор старается не перемещать их или удалять, что может существенно повлиять на оптимизацию вашей программы, а следовательно, и на время выполнения!
Синтаксис аннотации центра затрат для выражений
{-# SCC "name" #-} <expression>
где "name" — произвольная строка, которая станет именем вашего центра затрат в выводе профилирования, а <expression> — любое выражение Haskell. Аннотация SCC распространяется как можно дальше вправо при разборе, имея тот же приоритет, что и лямбда-абстракции, выражения let и условные выражения. Кроме того, аннотация не может появляться в позиции, где она изменит группировку подвыражений:
a = 1 / 2 / 2 -- accepted (a=0.25)
b = 1 / {-# SCC "name" #-} 2 / 2 -- rejected (instead of b=1.0)
Это ограничение необходимо для сохранения свойства, что вставка прагмы, подобно вставке комментария, не имеет непреднамеренных последствий для семантики программы, в соответствии с GHC Proposal #176.
SCC означает «Установить центр затрат». Двойные кавычки можно опустить, если name — идентификатор Haskell, начинающийся с маленькой буквы, например:
{-# SCC id #-} <expression>
Аннотации центров затрат также могут появляться на уровне верхнего уровня или в контексте объявления. В этом случае вам необходимо передать имя функции, определённой в том же модуле или области, что и аннотация. Пример:
f x y = ...
where
g z = ...
{-# SCC g #-}
{-# SCC f #-}
Если вы хотите дать центру затрат другое имя, отличное от имени функции, вы можете передать строку в аннотацию
f x y = ...
{-# SCC f "cost_centre_name" #-}
Вот пример программы с парой SCC:
main :: IO ()
main = do let xs = [1..1000000]
let ys = [1..2000000]
print $ {-# SCC last_xs #-} last xs
print $ {-# SCC last_init_xs #-} last (init xs)
print $ {-# SCC last_ys #-} last ys
print $ {-# SCC last_init_ys #-} last (init ys)
что даёт такой профиль при запуске:
COST CENTRE MODULE no. entries %time %alloc %time %alloc MAIN MAIN 102 0 0.0 0.0 100.0 100.0 CAF GHC.IO.Handle.FD 130 0 0.0 0.0 0.0 0.0 CAF GHC.IO.Encoding.Iconv 122 0 0.0 0.0 0.0 0.0 CAF GHC.Conc.Signal 111 0 0.0 0.0 0.0 0.0 CAF Main 108 0 0.0 0.0 100.0 100.0 main Main 204 1 0.0 0.0 100.0 100.0 last_init_ys Main 210 1 25.0 27.4 25.0 27.4 main.ys Main 209 1 25.0 39.2 25.0 39.2 last_ys Main 208 1 12.5 0.0 12.5 0.0 last_init_xs Main 207 1 12.5 13.7 12.5 13.7 main.xs Main 206 1 18.8 19.6 18.8 19.6 last_xs Main 205 1 6.2 0.0 6.2 0.0
8.1.2. Правила присвоения затрат
Во время выполнения программы с включённым профилированием GHC поддерживает стек центра затрат за кулисами и присваивает любые затраты (выделение памяти и время) тому текущему стеку центра затрат, который находится в момент возникновения затрат.
Механизм прост: всякий раз, когда программа вычисляет выражение с аннотацией SCC, {-# SCC c -#} E, центр затрат c помещается в текущий стек, и счётчик входов для этого стека увеличивается на единицу. Стек также иногда должен быть сохранён и восстановлен; в частности, когда программа создаёт кэширование (ленивую приостановку), текущий стек центра затрат сохраняется в кэше, и восстанавливается, когда кэш оценивается. Таким образом, стек центра затрат независим от фактического порядка оценки, используемого GHC во время выполнения.
При вызове функции GHC берёт стек, сохранённый в вызываемой функции (который для функции верхнего уровня будет пустым), и присоединяет его к текущему стеку, игнорируя любой префикс, идентичный префиксу текущего стека.
Ранее мы упоминали, что ленивые вычисления, то есть кэширования, сохраняют текущий стек при их создании и восстанавливают этот стек при их оценке. А что насчёт кэширований верхнего уровня? Они «создаются» при компиляции программы, так какой стек мы должны им дать? Техническое название кэширования верхнего уровня — CAF («Постоянная прикладная форма»). GHC присваивает каждому CAF в модуле стек, состоящий из единственного центра затрат M.CAF, где M — имя модуля. Также можно дать каждому CAF другой стек, используя опцию -fprof-cafs. Это особенно полезно при компиляции с помощью -ffull-laziness (как по умолчанию с -O и выше), поскольку константы в телах функций будут подняты на верхний уровень и станут CAF. Вероятно, вам придётся обратиться к ядру (-ddump-simpl), чтобы определить, чему соответствуют эти CAF.
