На практике часто нужно знать затраты вычислительных ресурсов на выполнения отдельных логических частей программы. Профилем выполнения программы будем называть информацию о затратах вычислительных ресурсов в разрезе по отдельным подпрограммам.
Профиль выполнения может пригодиться при оптимизации программ. Как известно, применение оптимизаций часто делает программу более сложной, следовательно, менее читаемой и усложняет дальнейшее сопровождение. Поэтому оптимизировать следует только те участки, где это даст необходимый прирост производительности. В поисках этих участков как раз и поможет профиль выполнения программы.
Также по профилю программы можно обнаружить подпрограммы, которые вызываются чаще, чем ожидается. Это может помочь найти логические ошибки, допущенные при программировании.
Получить профиль выполнение программы можно при помощи различных методов мониторинга исполнением программы. В данной статье рассмотрены инструменты, использующие инструментирование кода, интерпретацию кода и аппаратные счетчики.
Мы рассмотрим три инструмента построения профилей выполнения: gprof, valgrind и oprofile. Все три имеют открытый исходный код и распространяются бесплатно. Все инструменты требуют, чтобы программа была скомпилирована и/или запущена особым способом и завершилась за разумное время. Некоторые методы приводят к дополнительному замедлению исполнения программы.
Для иллюстрации работы инструментов будем использовать программу решения СЛАУ методом Гаусса. Общая структура программы проста:
Полный текст программы приведен в приложении.
Инструмент gprof является частью коллекции компиляторов GCC и работает на всем разнообразии поддерживаемых платформ, включая ОС Windows и Linux.
Gprof использует инструментирование кода в процессе компиляции. Поэтому программа должна быть скомпилирована с явным указанием на режим сбора профиля. Для этого в ключи компиляции следует добавить ключи -pg и -g. Например
gnatmake -g -pg test.adb
Компилятор обрамляет каждую подпрограмму кодом, который подсчитывает количество вызовов подпрограммы и сохраняет информацию о вызвавшей процедуре.
Таким образом в любой момент в течении исполнения программы известна вся цепочка вызовов подпрограмм начиная от главной и до текущей. Кроме количества вызовов каждой подпрограммы, (которое вычисляется точно при помощи вставок, сделанных компилятором), gprof позволяет оценить время исполнения каждой подпрограммы при помощи следующего статистического метода. При запуске программы настраивается таймер, который через заданный интервал времени прерывает исполнение программы и фиксирует информацию о текущей исполняемой подпрограмме и всей цепочке вызовов. Допустим, период таймера 0.0001 сек. и за время работы 20 прерываний обнаружили процедуру Swap активной, значит, время работы Swap приблизительно составляло 0.002 сек.
Для сбора информации о профиле выполнения нужно запустить программу.
test
После завершения программы вся собранная информация записывается в файл gmon.out, который должен быть обработан gprof для получения читаемого отчета. gprof вызывается следующим образом:
gprof test gmon.out > report.txt
Результатом работы будет отчет из двух частей.
Первая часть отчета — таблица подпрограмм с указанием количества вызовов и примерным временем выполнения.
% cumulative self self total time seconds seconds calls ms/call ms/call name 98.11 0.94 0.94 1 936.00 936.00 matrices__resolve 1.89 0.95 0.02 ada__numerics__float_random__random 0.00 0.95 0.00 6 0.00 0.00 matrices__swap 0.00 0.95 0.00 1 0.00 936.00 _ada_test 0.00 0.95 0.00 1 0.00 0.00 adainit 0.00 0.95 0.00 1 0.00 0.00 matrices__set_random
Таблица содержит следующие колонки
Вторая часть отчета сложнее, но позволяет рассматривать вызовы подпрограмм в разных контекстах вызова.
Влияние дополнительного кода на скорость выполнения программы существенно зависит от количества вызовов подпрограмм. В нашем случае, количество вызовов всего 10, и заметного замедления нет, но в типичных случаях программа может работать в несколько раз медленнее эталонной.
Набор инструментов, Valgrind, использует технологию интерпретации машинного кода. Он способен раскодировать бинарный формат исполняемого файла, выделить отдельные ассемблерные инструкции и интерпретировать их. Для ускорения используется метод динамической трансляции. Valgrind функционирует на базе ОС Linux.
Различные инструменты Valgrind могут дополнительно обрабатывать отдельные инструкции, реализуя дополнительную функциональность.
Например, инструмент cachegrind эмулирует работу процессора с кешем и механизмом предсказывания ветвлений. Запустив им нашу программу, мы можем не только оценить затраты процессорного времени на отдельные процедуры, но и проанализировать интенсивность промахов в кеше.
Поскольку Valgrind интерпретирует машинные команды, то не требуются особые ключи при компиляции. Единственное условие — наличие информации отладчика. Таким образом, можно испытывать даже программу агрессивно оптимизированную во время компиляции.
Запуск на исполнение происходит специальным образом:
valgrind --tool=cachegrind ./test
За точную эмуляцию приходиться дорого платить — замедление выполнения программы в нашем случае было в 70 раз. После окончания работы появится файл с данными вида cachegrind.out.XXXX, который можно обработать программой cg_annotate:
cg_annotate cachegrind.out.XXXX
Вот результат для нашей программы, немного упрощенный для восприятия, с удаленными данными о работе кеша.
Ir file:function ------------------------------------------------------------------------------ 31,448,018 /home/max/ada/perf/matrices.adb:matrices__resolve 1,007,005 ???:ada__numerics__float_random__square_mod_n 496,736 ???:ada__numerics__float_random__random 337,154 /home/max/ada/perf/matrices.adb:matrices__set_random 145,951 ???:??? 114,696 /home/max/ada/perf/matrices.adb:matrices__swap
Первая колонка — количество исполненных псевдоинструкций, вторая имя файла и подпрограммы.
Еще одна интересная функция valgrind — возможность аннотировать отдельные строки, когда данные агрегируются не по отдельным подпрограммам, а по каждой строке программы:
Вот отрывок подобного листинга:
-- Auto-annotated source: /home/max/ada/perf/matrices.adb ------------------------------------------------------------------------------ Ir 81,799 for M in K + 1 .. A'Last (1) loop 1,094,500 C := A (M, K) / A (K, K); 10,964,900 for J in K .. A'Last (2) loop 231,039,000 A (M, J) := A (M, J) - C * A (K, J); 2,666,600 end loop; 19,701 end loop;
Когда точная эмуляция работы кеша не требуется можно воспользоваться более быстрым и гибким инструментом callgrind:
valgrind --tool=callgrind ./test
Программа выполниться примерно в два раза быстрее, чем в предыдущем случае. После запуска можно включать и выключать сбор данных, таким образом анализировать программы с бесконечным временем выполнения, либо отдельные этапы работы программы.
Аналогично происходит анализ результата:
callgrind_annotate --tree=both callgrind.out.XXXXX
В отчете виден контекст вызова подпрограммы:
Ir file:function
--------------------------------------------------------------------------------
247,444,979 < test.adb:_ada_test
247,125,604 * matrices.adb:matrices__resolve
319,375 > matrices.adb:matrices__swap
Управлять callgrind‐ом можно из наблюдаемой программы. Это позволяет избежать накладных расходов и чрезмерного замедления в тех частях программы, которые не нуждаются в анализе. Можно подсмотреть, как это делать в исходном коде GPS.
Ссылка http://valgrind.org
Следующий инструмент OProfile в полной мере использует возможности современных процессоров и ОС в плане мониторинга производительности программ. Это позволяет не только анализировать отдельную программу, но и отслеживать производительность в контексте работы операционной системы или даже совокупности взаимодействующих процессов.
Можно анализировать как отдельную программу, так и системные вызовы, модули ядра, загружаемые библиотеки и обработчики прерываний. При этом исследуемая программа работает на полной скорости, а накладные расходы на мониторинг очень скромные.
Достигается это за счет использования аппаратных счетчиков, реализованных во всех современных процессорах. Метод работы OProfile аналогичен используемому в gprof, только вместо прерываний таймера используется прерывания от аппаратного счетчика ресурсов ЦПУ. Измеряемым ресурсом может быть как время потраченное ЦПУ, так и кеш промахи, промахи предсказания ветвления, обращения к памяти, количество выполненных инструкций с плавающей точкой и многие другие, в зависимости от процессора и архитектуры.
Платой за эти возможности является необходимость выполнения почти всех команд отладки от лица суперпользователя root.
Простейший пример использования OProfile выглядит так
opcontrol --no-vmlinux opcontrol --start
С этого момента начнется сбор данных по всем процессам системы. Мы можем запустить свою программу и запросить данные о ее исполнении:
/home/max/ada/perf/test opreport -l /home/max/ada/perf/test CPU: P4 / Xeon, speed 2823.12 MHz (estimated) Counted GLOBAL_POWER_EVENTS events (time during which processor is not stopped) with a unit mask of 0x01 (mandatory) count 100000 samples % symbol name 148070 96.5770 matrices__resolve 3458 2.2554 ada__numerics__float_random__square_mod_n 1174 0.7657 ada__numerics__float_random__random 610 0.3979 matrices__set_random 6 0.0039 matrices__swap
Из отчета видно, что измеряемым ресурсом было время работы ЦПУ. Во время работы подпрограммы Matrices.Resolve счетчик ресурса сработал 148070, что составило 96% от всей программы.
Остановить мониторинг и очистить собранные данные можно так:
opcontrol --shutdown opcontrol --reset
Для демонстрации других возможностей инструмента выполним сбор статистики промахов кеша памяти для нашей программы:
opcontrol -e BSQ_CACHE_REFERENCE:3000:0x100:0:1 opcontrol --image /home/max/ada/perf/test opcontrol --start /home/max/ada/perf/test opreport -l
Отчет будет выглядеть следующим образом:
CPU: P4 / Xeon, speed 2823.12 MHz (estimated) Counted BSQ_CACHE_REFERENCE events (cache references seen by the bus unit) with a unit mask of 0x100 (read 2nd level cache miss) count 3000 samples % symbol name 59 98.3333 matrices__resolve 1 1.6667 matrices__swap
Oprofile также может делать построчную аннотацию исходных текстов собранной статистикой: opannotate --source --output-dir=/tmp/annotated-source /home/max/ada/perf/test
Пример аннотации:
: procedure Resolve /* matrices_resolve total: 59 98.3333 */ : (Input : in Matrix; : X : out Vector) : is 10 16.6667 : A : Matrix := Input; : C : Float; : begin : for K in A'Range (1) loop : if A (K, K) = 0.0 then : Swap (A, K); : end if; : : for M in K + 1 .. A'Last (1) loop 6 10.0000 : C := A (M, K) / A (K, K); : : for J in K .. A'Last (2) loop 42 70.0000 : A (M, J) := A (M, J) - C * A (K, J); : end loop; : end loop; : end loop; : : for K in reverse A'Range (1) loop : C := A (K, A'Last (2)); : : for J in K + 1 .. A'Last (1) loop 1 1.6667 : C := C - A (K, J) * X (J); : end loop; : : X (K) := C / A (K, K); : end loop; : end Resolve; : :end Matrices;
Ссылка http://oprofile.sourceforge.net
gperftools — средство анализа производительности и управления памятью. Устанавливается из пакетного менеджера дистрибутива Linux:
Либо собрать из исходных текстов.
Для анализа производительности нужно собрать нашу программу с библиотекой profiler, а для анализа управления памятью — с библиотекой tcmalloc.
Чтобы получить отчет о производительности нужно установить переменную окружения CPUPROFILE, запустить программу, а затем pprof:
CPUPROFILE=/tmp/cpuprofile.log ./test pprof ./test /tmp/cpuprofile.log
В pprof можно получить в текстовом виде (опция -text), либо в PDF (опция --pdf). Можно получить аннотированный исходный код.
Современные инструментальные средства с открытым исходным кодом предоставляют широкий выбор методов анализа потребления вычислительных ресурсов. Методы отличаются по степени точности и накладным расходам, поэтому чтобы выбрать подходящий для конкретного анализа инструмент нужно иметь представление о существующих продуктах.
package Matrices is type Vector is array (Positive range <>) of Float; type Matrix is array (Positive range <>, Positive range <>) of Float; procedure Set_Random (Object : out Matrix); procedure Resolve (Input : in Matrix; X : out Vector); end Matrices;
with Ada.Numerics.Float_Random; package body Matrices is ---------------- -- Set_Random -- ---------------- procedure Set_Random (Object : out Matrix) is use Ada.Numerics.Float_Random; Randomizer : Generator; Zero_Level : constant := 0.7; begin Reset (Randomizer, 12345); for K in Object'Range (1) loop for J in Object'Range (2) loop if Random (Randomizer) < Zero_Level then Object (K, J) := 0.0; else Object (K, J) := Random (Randomizer); end if; end loop; end loop; end Set_Random; ---------- -- Swap -- ---------- procedure Swap (A : in out Matrix; K : in Positive) is M : Positive := K; T : Float; begin for J in K + 1 .. A'Last (1) loop if abs A (J, K) > abs A (M, K) then M := J; end if; end loop; if M = K then raise Constraint_Error; end if; for J in K .. A'Last (2) loop T := A (K, J); A (K, J) := A (M, J); A (M, J) := T; end loop; end Swap; ------------- -- Resolve -- ------------- procedure Resolve (Input : in Matrix; X : out Vector) is A : Matrix := Input; C : Float; begin for K in A'Range (1) loop if A (K, K) = 0.0 then Swap (A, K); end if; for M in K + 1 .. A'Last (1) loop C := A (M, K) / A (K, K); for J in K .. A'Last (2) loop A (M, J) := A (M, J) - C * A (K, J); end loop; end loop; end loop; for K in reverse A'Range (1) loop C := A (K, A'Last (2)); for J in K + 1 .. A'Last (1) loop C := C - A (K, J) * X (J); end loop; X (K) := C / A (K, K); end loop; end Resolve; end Matrices;
with Ada.Text_IO; with Matrices; use Matrices; procedure Test is N : constant := 800; A : Matrix (1 .. N, 1 .. N + 1); X : Vector (1 .. N); R : Float := 0.0; begin Set_Random (A); Resolve (A, X); for J in 1 .. N loop R := R + X (J); end loop; Ada.Text_IO.Put_Line (Float'Image (R)); end Test;