Профилирование позволяет вам изучить, где ваша программа расходует свое время и какие функции вызывали другие функции, пока программа исполнялась. Эта информация может указать вам на ту часть программы, которая исполняется медленнее, чем вы ожидали, и которая может быть кандидатом на переписывание, чтобы ускорить выполнение программы. Эта информация также подскажет вам, какие функции вызывались чаще или реже, чем вы ожидали. Это может помочь вам отметить ошибки, которые иначе остались бы незамеченными.
Так как профилятор использует информацию, собранную в процессе реального исполнения вашей программы, он может быть использован для исследования программ, которые слишком большие или слишком сложные, чтобы анализировать их, читая исходный текст. Однако то, как ваша программа исполняется, будет влиять на информацию, отображаемую в данных о профиле. Если вы не используете некоторую возможность вашей программы в процессе ее профилирования, то никакой профильной информации не будет порождено для этой возможности.
Профилирование состоит из нескольких шагов:
Результатом анализа является файл, содержащий две таблицы - "Простой профиль" ("flat profile") и "Граф вызовов" ("call graph") (плюс замечания, кратко объясняющие содержимое этих таблиц).
Простой (flat) профиль показывает, сколько времени потратила ваша программа на исполнение каждой функции и сколько раз эта функция вызывалась. Если вам надо просто узнать, какие функции требуют большинства времени, то это устанавливается именно отсюда. *См. Простой профиль::.
Граф вызовов показывает, для каждой функции, какие функции ее вызывали, какие функции вызывала она сама и сколько раз. Также здесь показано, сколько времени было затрачено на выполнение подпрограмм в каждой функции. Это может подсказать вам места, в которых вы можете попытаться исключить вызовы функций, требующих достаточно много времени на выполнение. *См. Граф вызовов::.
Первым шагом для порождения профильной информации о вашей программе является ее компилирование и сборка (линковка) с разрешенным профилированием.
При компиляции исходного файла для профилирования, укажите опцию `-pg' компилятору. (Эта опция должна быть добавлена к другим опциям, которые вы обычно используете).
При сборке (линковке) программы для профилирования, если вы пользуетесь компилятором типа `cc', который обеспечивает сборку, просто укажите `-pg' вдобавок к вашим обычным опциям. Эта опция, `-pg', изменит и компиляцию, и сборку так, как необходимо для профилирования. Например:
cc -g -c myprog.c utils.c -pg
cc -o myprog myprog.o utils.o -pg
Опция `-pg' также сработает и с командой, которая выполняет сразу
и компиляцию, и сборку:
cc -o myprog myprog.c utils.c -g -pg
Если вы запускаете сборщик (линкер) `ld' непосредственно, а не
через компилятор типа `cc', то вы должны указать профилирующий начальный
файл `/lib/gcrt0.o' как первый входной файл вместо обычного начального
файла `/lib/crt0.o'. Вдобавок, вам, возможно, захочется указать
профилирующую библиотеку Си `/usr/lib/libc_p.a', задав опцию `-lc_p'
вместо обычной `-lc'. Это не является абсолютно необходимым, однако
позволяет вам получить информацию о количестве вызовов функций
стандартной библиотеки, таких как `read' или `open'. Например:
ld -o myprog /lib/gcrt0.o myprog.o utils.o -lc_p
Если вы компилируете только некоторые модули программы с `-pg', вы
еще сможете профилировать программу, но вы не получите полной информации
о модулях, которые были откомпилированы без `-pg'. Все, что вы узнаете
о функциях в этих модулях, это общее время, затраченное на их
выполнение; вы не узнаете, сколько раз они были вызваны или откуда. Это
не повлияет на простой профиль (за исключением поля `вызовы', которое
для таких функций останется пустым), но заметно уменьшит полезность
графа вызовов.
Когда программа скомпилирована для профилирования, вы должны запустить ее, чтобы породить информацию, необходимую для `gprof'. Просто запустите программу как обычно, используя обычные аргументы, имена файлов, и т.д. Программа должна выполниться, как обычно, с обычным выводом. Конечно, она будет исполняться несколько медленнее обычного, т.к. требуется время на сбор и запись данных о профиле.
Способ, которым вы выполняете программу--переданные аргументы и ввод, который вы ей даете--может иметь драматический эффект в том, какая информация о профиле будет предоставлена. Данные о профиле будут описывать только те части программы, которые активизировались из-за особенностей использованного вами ввода. Например, если первой командой, которую вы ввели в вашу программу, будет команда выхода, то данные о профиле покажут время, затраченное на инициализацию и закрытие программы, но ничего более.
Ваша программа запишет данные о профиле в файл, именуемый `gmon.out' только перед самым завершением. Если такой файл уже существует, то его содержимое будет перезаписано. В настоящий момент нет способа уведомить программу о необходимости записывать данные о профиле под другим именем, однако вы можете переименовать файл, если вас беспокоит, что он может быть впоследствии перезаписан.
Чтобы правильно записать файл `gmon.out', ваша программа обязана завершиться обычным способом: возвратом из `main()' или вызовом `exit()'. Вызов низко-уровневой функции `_exit()' не запишет данные о профиле, так же и аварийное завершение вследствие необрабатываемого (unhandled) сигнала.
Файл `gmon.out' записывается в *текущем рабочем директории* программы в момент выхода. Это значит, что если ваша программа называется `chdir' (CHange DIRectory--сменить текущий директорий), то `gmon.out' будет оставлен в последнем директории, который сменит ваша программа (в оригинале: "... in the last directory your program `chdir''d to."). Если вы не имеете прав доступа на запись в этот директорий, то файл не будет записан. Вы даже можете получить сообщение об ошибке, если такое случится. (Мы не изменяли ответственную за это часть Unix; когда дойдет до этого, мы сделаем сообщение об ошибке более точным (исчерпывающим)).
После получения файла `gmon.out' с данными о профиле, вы можете запустить `gprof', чтобы проинтерпретировать информацию из него. Программа `gprof' выводит простой профиль и граф вызовов на стандартный вывод. Обычно вы будете перенаправлять (redirect) вывод `gprof' в файл, используя `>'.
Вы запускаете `gprof' командой типа
gprof ОПЦИИ [ИСПОЛНЯЕМЫЙ-ФАЙЛ [ФАЙЛЫ-ДАННЫХ-О-ПРОФИЛЕ...]] [> ФАЙЛ-ВЫВОДА]
где квадратные скобки обозначают необязательные (опциональные) аргументы.
Если вы не указываете имя исполняемого файла, то принимается `a.out' по умолчанию. Если вы не задаете имя файла данных о профиле, то принимается `gmon.out' по умолчанию. Если любой из файлов оказывается в неверном формате или если файл данных о профиле оказывается не принадлежащим этому исполняемому файлу, то выводится сообщение об ошибке.
Вы можете указать более, чем один файл данных о профиле, введя их имена после имени исполняемого файла; тогда статистика из всех файлов данных складывается.
Следующие опции могут быть использованы для выборочного включения или исключения функций в выводе `gprof':
Опция `-a' указывает `gprof' подавить вывод статически объявленных функций. (Это функции, имена которых не перечислены, как глобальные и которые невидимы вне файла/функции/блока, где они были определены). Время, затраченное на исполнение этих функций, вызовы их и из них, и т.д. будут указаны для функции, которая вызывалась непосредственно перед ними во время исполнения. Эта опция влияет и на простой профиль, и на граф вызовов.
Опция `-D' указывает `gprof' игнорировать символы (имена), которые не известны, как функции. Эта опция выдает более точные данные о профиле в системах, которые это поддерживают (например, Solaris и HPUX).
Опция `-e ИМЯ_ФУНКЦИИ' указывает `gprof' не выводить информацию о функции ИМЯ_ФУНКЦИИ (и всех, вызванных из нее...) в граф вызовов. Функция будет показана, как вызванная из других функций, но ее индекс будет выводиться как `[нет]' (`[not printed]'). Может быть указана более, чем одна опция `-e'; только одно ИМЯ_ФУНКЦИИ может быть задано с каждой опцией `-e'.
Опция `-E ИМЯ_ФУНКЦИИ' работает так же, как и опция `-e', но время, затраченное на выполнение функции (и всех ее подпрограмм, которые больше ниоткуда не вызываются), не будет использовано для вычисления процента времени для графа вызовов. Может быть указана более, чем одна опция `-E'; только одно ИМЯ_ФУНКЦИИ может быть задано с каждой опцией `-E'.
Опция `-f ИМЯ_ФУНКЦИИ' указывает `gprof' ограничить граф вызовов функцией ИМЯ_ФУНКЦИИ и вызываемыми из нее (и вызываемыми из них...). Может быть указана более, чем одна опция `-f'; только одно ИМЯ_ФУНКЦИИ может быть задано с каждой опцией `-f'.
Опция `-F ИМЯ_ФУНКЦИИ' работает так же, как и опция `-f', но для определения общего времени и процента времени в графе вызовов будет использовано только время, затраченное на выполнение функции и всех ее подпрограмм (и их подпрограмм...). Может быть указана более, чем одна опция `-F'; только одно ИМЯ_ФУНКЦИИ может быть задано с каждой опцией `-F'. Опция `-F' перекрывает опцию `-E'.
Опция `-k' исключает из профиля все дуги (arcs) от функции ОТ до функции ДО.
Флаг `-v' указывает `gprof' вывести номер текущей версии и завершиться.
Если вы задаете опцию `-z', то `gprof' вносит все функции в простой профиль, даже если они никогда не вызывались и поэтому не имеют затраченного на их выполнение времени. Эта опция полезна в соединении с опцией `-c' для обнаружения никогда не вызываемых функций.
Порядок, в котором вы укажете эти опции, не имеет значения.
gprof -e boring -f foo -f bar myprogram > gprof.output
внесет в граф вызовов все функции, которые вызывались из `foo' и из
'bar' и не вызывались из `boring'.
Некоторые другие полезные опции `gprof':
Если указана опция `-b', `gprof' не будет выводить подробные пояснения ко всем полям в таблицах. Эта опция полезна, если вы намерены распечатать вывод или вас утомило созерцание пояснений.
Опция `-c' указывает, что граф вызовов статических функций программы будет создан эвристически, просмотром области кода в объектном файле. Статические вызывающие и вызываемые функции отмечаются счетчиком вызовов, равным 0.
Опция `-d NUM' специфицирует опции отладки.
Опция `-s' указывает `gprof' обобщить информацию из прочитанных файлов данных о профиле и вывести ее в файл данных о профиле `gmon.sum', который будет содержать всю информацию из файлов данных о профиле, прочитанных `gprof'. Файл `gmon.sum' может быть указан, как один из исходных файлов; эффектом этого будет слияние данных из прочих исходных файлов в `gmon.sum'. *См. Оценка ошибки::.
В конце концов вы сможете запустить `gprof' снова без опции `-s' для анализа собранных в `gmon.sum' данных.
Опция -T' указывает `gprof' оформлять свой вывод в "традиционном" стиле BSD.
Опция `--function-ordering' указывает `gprof' выводить функции в том порядке, в котором они расположены в исполняемом файле. Эта опция может упорядочить функции таким образом, что улучшится подкачка страниц памяти и поведение кэша для программы в системах, которые поддерживают произвольный порядок функций в исполняемом файле.
Точные детали того, как заставить сборщик (линкер) поместить функции в нужном порядке, зависят от системы и не рассматриваются в данном руководстве.
Опция `--file-ordering MAP_FILE' указывает `gprof' выводить функции в том порядке, в котором они встретились сборщику (линкеру) в строке .o-файлов. Эта опция может упорядочить функции таким образом, что улучшится подкачка страниц памяти и поведение кэша для программы в системах, которые не поддерживают произвольный порядок функций в исполняемом файле.
В высшей степени рекомендуется с этой опцией использовать опцию `-a'.
Аргумент MAP_FILE--это полный путь к файлу, в котором перечислены имена функций в соответствии с их расположением в объектном файле. Формат этого файла такой же, как и выход программы `nm'.
c-parse.o:00000000 T yyparse
c-parse.o:00000004 C yyerrflag
c-lang.o:00000000 T maybe_objc_method_name
c-lang.o:00000000 T print_lang_statistics
c-lang.o:00000000 T recognize_objc_keyword
c-decl.o:00000000 T print_lang_identifier
c-decl.o:00000000 T print_lang_type
...
GNU `nm' `--extern-only' `--defined-only' `-v' `--print-file-name'
может быть использована для создания MAP_FILE.
Простой профиль показывает общий итог времени, затраченного на исполнение каждой функции вашей программы. Если не указана опция `-z', то функции без явных затрат времени на их выполнение, без явных вызовов, не упоминаются. Заметим, что функция, не откомпилированная для профилирования и не выполнявшаяся достаточное для отображения на гистограмме время, неотличима от функции, которая никогда не вызывалась.
Здесь показан пример простого профиля небольшой программы:
Flat profile: (Простой профиль:)
Each sample counts as 0.01 seconds. (Каждый отсчет == 0.01 сек.)
% cumulative self self total
time seconds seconds calls ms/call ms/call name
33.34 0.02 0.02 7208 0.00 0.00 open
16.67 0.03 0.01 244 0.04 0.12 offtime
16.67 0.04 0.01 8 1.25 1.25 memccpy
16.67 0.05 0.01 7 1.43 1.43 write
16.67 0.06 0.01 mcount
0.00 0.06 0.00 236 0.00 0.00 tzset
0.00 0.06 0.00 192 0.00 0.00 tolower
0.00 0.06 0.00 47 0.00 0.00 strlen
0.00 0.06 0.00 45 0.00 0.00 strchr
0.00 0.06 0.00 1 0.00 50.00 main
0.00 0.06 0.00 1 0.00 0.00 memcpy
0.00 0.06 0.00 1 0.00 10.11 print
0.00 0.06 0.00 1 0.00 0.00 profil
0.00 0.06 0.00 1 0.00 50.00 report
...
Функции упорядочены по убыванию времени, затраченного на их выполнение.
Функции `mcount' и `profil' являются частью аппарата профилирования и
появляются в каждом простом профиле; их время несколько увеличивает
ожидаемое при профилировании время выполнения.
Период отсчета является оценкой границ возможной ошибки в каждом отсчете времени. Отсчеты времени, ненамного превышающие эту величину, ненадежны. В данном примере поле `собственных секунд' (`self seconds') для `mcount' может отлично получиться и `0.00', и `0.04' при других запусках. *См. Оценка ошибки:: для более полного обсуждения.
Что же означают поля в каждой строке:
Это процент от общего времени исполнения вашей программы, затраченный на выполнение этой функции. Сумма по всем строкам должна составлять 100%.
Это общее время в секундах, которое затратил компьютер на выполнение этой функции, плюс время, затраченное на выполнение всех функций, перечисленных выше в этой таблице.
Это количество секунд, подсчитанных только для этой функции. Листинг простого профиля сперва упорядочивается по этому количеству.
Это общее количество вызовов этой функции--сколько раз она была вызвана. Если функция ни разу не вызывалась или количество вызовов не может быть определено (возможно, из-за того, что функция не была откомпилирована для профилирования), то поле `calls' (`вызовов') остается пустым.
call' (`собственных миллисекунд на вызов') /
Это поле представляет собой среднее количество миллисекунд, затраченных этой функцией на вызов, если эта функция профилируется. Иначе это поле остается пустым для этой функции.
call' (`всего миллисекунд на вызов') /
Это поле представляет собой среднее количество миллисекунд, затраченных этой функцией и ее подпрограммами на вызов, если эта функция профилируется. Иначе это поле остается пустым для этой функции.
Это имя функции. Листинг простого профиля упорядочивается по этому полю в алфавитном порядке после упорядочения по полю `self seconds' (`собственных секунд').
Граф вызовов показывает, сколько времени было затрачено каждой функцией и функциями, вызванными из нее. По этой информации вы сможете судить о таких функциях, которые, хотя и не тратят много времени, однако вызывают другие функции, которые тратят необычно много времени.
Здесь показан пример графа вызовов небольшой программы. Этот пример получен при том же запуске `gprof', что и вышеприведенный пример простого профиля.
granularity: each sample hit covers 2 byte(s) for 20.00% of 0.05 seconds
index % time self children called name
<spontaneous>
[1] 100.0 0.00 0.05 start [1]
0.00 0.05 1/1 main [2]
0.00 0.00 1/2 on_exit [28]
0.00 0.00 1/1 exit [59]
-----------------------------------------------
0.00 0.05 1/1 start [1]
[2] 100.0 0.00 0.05 1 main [2]
0.00 0.05 1/1 report [3]
-----------------------------------------------
0.00 0.05 1/1 main [2]
[3] 100.0 0.00 0.05 1 report [3]
0.00 0.03 8/8 timelocal [6]
0.00 0.01 1/1 print [9]
0.00 0.01 9/9 fgets [12]
0.00 0.00 12/34 strncmp <cycle 1> [40]
0.00 0.00 8/8 lookup [20]
0.00 0.00 1/1 fopen [21]
0.00 0.00 8/8 chewtime [24]
0.00 0.00 8/16 skipspace [44]
-----------------------------------------------
[4] 59.8 0.01 0.02 8+472 <cycle 2 as a whole> [4]
0.01 0.02 244+260 offtime <cycle 2> [7]
0.00 0.00 236+1 tzset <cycle 2> [26]
-----------------------------------------------
Пунктирные линии делят эту таблицу на "записи" ("entries"), по
одной на каждую функцию. Каждая запись содержит одну или более строк.
Первичная строка каждой записи начинается с индекса в квадратных скобках. В конце первичной строки указано имя функции этой записи. В предшествующих строках записи описаны функции, вызывавшие данную, а в последующих строках--вызванные из нее подпрограммы.
Записи упорядочены по времени, затраченному на выполнение функций и их подпрограмм.
Внутренняя профилирующая функция `mcount' (*см. Простой профиль::) никогда не упоминается в графе вызовов.
* Первичная строка:: Описание содержимого первичной строки.
* Вызывающие:: Описание содержимого строк вызывающих функций.
* Подпрограммы:: Описание содержимого строк вызываемых функций.
* Циклы:: Описание взаимно-рекурсивных функций, таких, как
`a' вызывает `b', а `b' вызывает `a'.
"Первичная строка" каждой записи описывает функцию, к которой относится эта запись и представляет общую статистику для этой функции.
Для изучения мы повторим первичную строку записи для функции `report' из вышеприведенного примера, вместе со строками заголовков, содержащих имена полей:
index % time self children called name
...
[3] 100.0 0.00 0.05 1 report [3]
Что же означают поля в первичной строке:
Записи нумеруются последовательными целыми числами. Поэтому каждая функция имеет индексный номер, указываемый в начале первичной строки ее записи.
Любая перекрестная ссылка на функцию, будь то вызывающая или вызываемая, содержит индекс функции, так же, как и ее имя. Индекс поможет вам отыскать запись для этой функции.
Это процент от общего времени исполнения вашей программы, затраченный на выполнение этой функции и вызванных из нее подпрограмм.
Время, затраченное на эту функцию, также подсчитывается для функций, вызвавших данную. Следовательно, простое суммирование этих процентов лишено всякого смысла.
Это количество секунд выполнения, подсчитанных только для этой функции. Оно должно быть идентично числу, указанному в поле `собственных секунд' в простом профиле для этой функции.
Это количество секунд выполнения, подсчитанных только для вызванных этой функцией подпрограмм. Оно должно быть идентично сумме `собственных секунд' и `секунд в подпрограммах' для всех укзанных ниже вызываемых функций [в этой записи].
Это общее количество вызовов этой функции--сколько раз она была вызвана.
Если эта функция вызывает себя рекурсивно, то будут указаны два числа, разделенные `+'. Первое число показывает количество нерекурсивных вызовов, а второе--рекурсивных.
В вышеприведенном примере функция `report' была один раз вызвана из функции `main'.
Это имя текущей функции. Индексный номер повторяется после него.
Если функция является частью цикла взаимной рекурсии, то номер цикла выводится между именем функции и индексным номером (*См. Циклы::). Например, если функция `gnurr'--часть цикла номер один и имеет индекс `двенадцать', то первичная строка ее записи будет завершена так:
gnurr <cycle 1> [12]
Запись функции содержит строку для каждой функции, которая вызывала данную. Их поля соответствуют полям в первичной строке, но смысл их отличен из-за различий в содержании.
Для изучения мы повторим две строки из записи для функции `report'--первичную строку и одну из предшествующих строк вызывающей функции, вместе со строками заголовков, содержащих имена полей:
index % time self children called name
...
0.00 0.05 1/1 main [2]
[3] 100.0 0.00 0.05 1 report [3]
Что же означают поля в строке вызывающей функции (для `report',
вызванной из `main'):
Оценка времени, потраченного самой функцией `report', когда она была вызвана из функции `main'.
Оценка времени, потраченного подпрограммами функции `report', когда `report' была вызвана из функции `main'.
Сумма `собственных секунд' и `секунд в подпрограммах' является приблизительной оценкой времени выполнения `report', вызываемой из `main'.
Два числа: количество вызовов `report' из `main', за которым следует общее количество нерекурсивных вызовов `report' изо всех функций, которые ее вообще вызывали.
Имя функции, вызвавшей `report', к которой относится эта строка, и следом указан индекс этой функции.
Не все функции имеют записи в графе вызовов; некоторые из опций `gprof' требуют пропустить некоторые функции. Если вызывающая функция не имеет записи о себе, она, тем не менее, имеет строку вызывающей функции в записях тех функций, которые она вызывает.
Если вызывающая функция является частью рекурсивного цикла, то номер цикла выводится между именем и индексным номером.
Запись функции содержит по строке на каждую из ее подпрограмм - другими словами, по строке на каждую другую функцию, которую она вызывает. Их поля соответствуют полям в первичной строке, но смысл их отличен из-за различий в содержании.
Для изучения мы повторим две строки из записи для функции `main'-- первичную строку и одну из последующих строк вызванной ею функции, вместе со строками заголовков, содержащих имена полей:
index % time self children called name
...
[2] 100.0 0.00 0.05 1 main [2]
0.00 0.05 1/1 report [3]
Что же означают поля в строке вызванной функции (для `main',
вызывающей `report'):
Оценка времени, потраченного самой функцией `report', когда она была вызвана из функции `main'.
Оценка времени, потраченного подпрограммами функции `report', когда `report' была вызвана из функции `main'.
Сумма `собственных секунд' и `секунд в подпрограммах' является приблизительной оценкой времени выполнения `report', вызываемой из `main'.
Два числа: количество вызовов `report' из `main', за которым следует общее количество нерекурсивных вызовов `report'.
Имя функции, вызванной из `main', к которой относится эта строка, и следом указан индекс этой функции.
Если вызывающая функция является частью рекурсивного цикла, то номер цикла выводится между именем и индексным номером.
Картина может быть осложнена наличием "циклической рекурсии" в графе вызовов. Цикл возникает, когда некоторая функция вызывает другую функцию, которая (прямо или опосредованно) вызывает (или пытается это сделать) первую. Например, если `a' вызывает `b', а затем `b' вызывает `a', то `a' и `b' организуют циклическую рекурсию.
Когда бы вызовы ни прошли по обоим путям между двумя функциями, они принадлежат к одному и тому же циклу. Если `a' и `b' вызывают друг друга, и `b' и `c' вызывают друг друга, то все три функции находятся в одном и том же цикле. Однако следует заметить, что даже если только `b' вызывает `a', но при этом сама не была вызвана из `a', то `gprof' не способен распознать это, и, таким образом, `a' и `b' все же считаются в цикле.
Циклы нумеруются последовательными целыми числами. Если функция принадлежит циклу, всякий раз, когда ее имя встречается в графе вызовов, за ним следует `<cycle NUMBER>' (`<цикл НОМЕР>')
Циклы создают проблему, заключающуюся в том, что циклы делают парадоксальными значения времен в графе вызовов. Поле `время в подпрограммах' для `a' должно включать в себя время, затраченное на вызываемую `b' и все ее подпрограммы--но одной из подпрограмм `b' является `a'! А сколько времени выполнения `a' должно быть включено во `время в подпрограммах' функции `a', если `a' непосредственно рекурсивна?
Спсоб, которым `gprof' разрешает этот парадокс, заключается в создании простой записи для цикла как для единого целого. Первичная строка этой записи описывает общее время, затраченное на непосредственное выполнение функций цикла. "Подпрограммами" цикла являются отдельные его функции, а также все вызываемые из них функции. "Вызывающими" функциями для цикла являются такие функции, которые не входят в сам цикл, но вызывают функции цикла.
Вот пример части графа вызовов, в котором показан цикл, содержащий функции `a' и `b'. Цикл начинался вызовом `a' из `main'; обе, `a' и `b', вызывали `c'.
index % time self children called name
----------------------------------------
1.77 0 1/1 main [2]
[3] 91.71 1.77 0 1+5 <cycle 1 as a whole> [3]
1.02 0 3 b <cycle 1> [4]
0.75 0 2 a <cycle 1> [5]
----------------------------------------
3 a <cycle 1> [5]
[4] 52.85 1.02 0 0 b <cycle 1> [4]
2 a <cycle 1> [5]
0 0 3/6 c [6]
----------------------------------------
1.77 0 1/1 main [2]
2 b <cycle 1> [4]
[5] 38.86 0.75 0 1 a <cycle 1> [5]
3 b <cycle 1> [4]
0 0 3/6 c [6]
----------------------------------------
(Полный граф вызовов для этой программы содержит также запись для
`main', которая вызывает `a', и запись для `c', которую вызывают `a' и
`b').
index % time self children called name
<spontaneous>
[1] 100.00 0 1.93 0 start [1]
0.16 1.77 1/1 main [2]
----------------------------------------
0.16 1.77 1/1 start [1]
[2] 100.00 0.16 1.77 1 main [2]
1.77 0 1/1 a <cycle 1> [5]
----------------------------------------
1.77 0 1/1 main [2]
[3] 91.71 1.77 0 1+5 <cycle 1 as a whole> [3]
1.02 0 3 b <cycle 1> [4]
0.75 0 2 a <cycle 1> [5]
0 0 6/6 c [6]
----------------------------------------
3 a <cycle 1> [5]
[4] 52.85 1.02 0 0 b <cycle 1> [4]
2 a <cycle 1> [5]
0 0 3/6 c [6]
----------------------------------------
1.77 0 1/1 main [2]
2 b <cycle 1> [4]
[5] 38.86 0.75 0 1 a <cycle 1> [5]
3 b <cycle 1> [4]
0 0 3/6 c [6]
----------------------------------------
0 0 3/6 b <cycle 1> [4]
0 0 3/6 a <cycle 1> [5]
[6] 0.00 0 0 6 c [6]
----------------------------------------
Поле `self' в первичной строке цикла--общее время выполнения всех
функций цикла. Оно равно сумме полей `self' для каждой отдельной функции
цикла, взятых из записей вызываемых функций.
Поле `children' в первичной строке цикла и строки подпрограмм содержат времена только тех функций, которые не входят в цикл. Хотя `a' и вызывает `b', время таких вызовов `b' не подсчитывается для `a' в поле `children'. Таким образом, мы не натыкаемся на проблему: что делать, если время в этих вызовах `b' включает опосредованные рекурсивные вызовы `a'.
Поле `children' в строках вызывающих функций в записи цикла оценивают время, затрачиваемое *на весь цикл в целом*, и на другие его подпрограммы, в том случае, когда эта функция вызывает одну из функций цикла.
Поле `calls' в первичной строке цикла содержит два числа: во-первых, количество вызовов функций цикла функциями извне цикла; во-вторых, количество вызовов функций цикла функциями цикла (включая количество вызовов самой себя). Это обобщение обычного разделения вызовов на рекурсивные и нерекурсивные.
Поле `calls' в строке вызываемой подпрограммы, входящей в цикл, в записи цикла сообщает, сколько раз эта функция была вызвана из функций цикла. Общее же их количество показано вторым числом в поле `calls' в первичной строке.
В отдельных записях для каждой функции цикла могут встречаться другие функции, указанные и как вызывающие, и как вызываемые. Эти строки показывают, сколько раз каждая из функций цикла вызывала или была вызвана из других функций цикла. Поля `self' и `children' таких строк не заполняются, так как затруднительно определить их смысл (значение), когда начинается рекурсия.
Профилирование работает на изменениях, которые делает компилятор, когда компилирует вашу программу с опцией `-pg'. Каждая функция в вашей программе откомпилирована так, чтобы при своем вызове она порождала некоторую информацию о том, откуда она была вызвана. Отсюда профилятор может выяснить, какая функция ее вызвала, и сможет подсчитать, сколько раз она была вызвана.
Профилирование также подключает отслеживание того, как выполняется ваша программа, и снимает гистограмму, где (по какому адресу) находился программный счетчик. Обычно программный счетчик опрашивается около 100 раз в секунду, но точная частота может отличаться от системы к системе.
Специальная процедура запуска выделяет память под накопление гистограммы и устанавливает обработчик сигнала от часов для занесения записей в нее. Применение этой специальной процедуры запуска обусловлено использованием `gcc ... -pg' для сборки (линковки). Также в этом файле содержится функция `exit', ответственная за запись файла `gmon.out'.
Информация о количестве вызовов для библиотечных функций накапливается при использовании специальной версии Си-библиотеки. Функции в ней точно такие же, как и в обычной библиотеке, но откомпилированы с опцией `-pg'. Если вы собираете (линкуете) вашу программу через `gcc ... -pg', то автоматически будет использована профилирующая версия библиотеки.
Вывод `gprof' не отметит, какие части вашей программы ограничены пропускной способностью ввода/вывода или свопинга. Это потому, что отсчеты с программного счетчика снимаются через фиксированные интервалы времени исполнения программы. Следовательно, замеры времени в выводе `gprof' ничего не скажут про время, в течении которого ваша программа не выполнялась. Например, часть программы, создающая очень много данных, не может вместить их всех разом в физическую память, и будет исполнятся очень медленно, но `gprof' будет сообщать, что она занимает немного времени. С другой стороны, ведение отсчета по времени исполнения имеет то преимущество, что нагрузка, создаваемая другими пользователями, не должна оказывать непосредственного влияния на полученные при профилировании данные.
Цифры времени исполнения, которые вам выдает `gprof', основываются на процессе наблюдения, и это повод для возникновения статистических неточностей. Когда функция выполняется слишком короткий промежуток времени, наблюдающий процесс в среднем может поймать ее за работой только однажды, а это--очаровательная возможность считать, что эта функция не наблюдалась вообще или ее видели дважды.
В отличие от этого, цифры количества вызовов получаются подсчетом, а не наблюдением. Они точны и не меняются от запуска к запуску, если ваша программа детерминирована (ход ее исполнения строго предопределен).
Период наблюдения (отсчета), который выводится в начале простого профиля, говорит, как часто происходят наблюдения. Правило большого пальца утверждает, что цифры времени исполнения точны, если они значительно больше периода отсчета (наблюдения).
Обычно реальная ошибка превышает один период наблюдения. Фактически, если значение равно N периодам наблюдения, то *ожидаемая* ошибка не превышает корня квадратного из N. Если период наблюдения равен 0.01 сек., а время выполнения `foo' равно 1.00 сек., то ожидаемая ошибка в величине времени выполнения `foo' не превышает 0.10 сек. Весьма вероятно, что это время будет заметно изменяться *в среднем* от запуска к запуску для профилирования. (*Иногда* оно будет меняться гораздо сильнее).
Это не означает, что маленькие цифры содержат недостоверную информацию. Если *общее* время исполнения программы велико, то маленькое время выполнения для одной функции скажет вам, что эта функция использует незначительную долю от всего времени исполнения программы. Обычно это означает, что вам незачем беспокоится об оптимизации.
Есть один способ добиться большей точности--задать вашей программе побольше (но попроще) входных данных, чтобы она подольше поработала. Другой способ--собрать данные от разных запусков, используя опцию `-s' `gprof'. Вот так:
gprof -s EXECUTABLE-FILE gmon.out gmon.sum
gprof EXECUTABLE-FILE gmon.sum > OUTPUT-FILE
Некоторые из цифр в графе вызовов--приблизительные, например, `время в подпрограммах' и все времена в строках вызывающих и вызываемых функций.
Нет непосредственной информации об этих измерениях в самих данных о профиле. Однако, `gprof' может попытаться оценить их, делая некоторые предположения о вашей программе, которые могут быть, а могут и не быть истинными.
Предположения (допущения) приводят к тому, что среднее время на каждый вызов какой-либо функции `foo' не соответствует времени, указанному для функции, которая ее вызвала. Если `foo' всего затратила 5 секунд и 2/5 вызовов `foo' были сделаны из функции `a', то для `foo' будет сделано предположение, что она потребовала 2 секунды `времени в подпрограммах' функции `a'.
Обычно это допущение в достаточной степени истинно, но для некоторых программ оно очень далеко от истины. Допустим, что `foo' возвращается очень быстро, если ее аргумент равен нулю; допустим также, что `a' всегда передает нуль в качестве аргумента, тогда как другие функции вызывают `foo' с другими значениями аргумента. В такой программе все время, затраченное на `foo', будет приходиться на другие функции. Но `gprof' не имеет возможности узнать об этом; он слепо и тупо укажет 2 секунды времени для `foo', вызываемой из `a'.
Мы надеемся, что несколько дней для получения более точных данных в `gmon.out' сделают это допущение более не нужным, если мы сможем этого добиться. И вообще, приблизительные цифры, как правило, более полезны, чем неверные.
GNU `gprof' и Berkeley Unix `gprof' используют один и тот же файл данных `gmon.out' и обеспечивают почти одинаковую информацию. Но они имеют ряд различий.