Марк Митчелл - Программирование для Linux. Профессиональный подход

Калькулятор принимает однострочные постфиксные выражения [40] В постфиксной записи бинарный оператор ставится после операндов, а не между ними. Например, чтобы умножить 6 на 8, нужно записать 6 8 *. Чтобы умножить 6 на 8, а затем добавить 5, следует записать 6 8 * 5 +. и отображает значение каждого выражения:

% ./calculator

Please enter a postfix expression:

2 3 +

5

Please enter a postfix expression:

2 3 + 4 -

1

Калькулятор, реализованный в файле calculator.c, читает каждое выражение и сохраняет промежуточные результаты в стеке унарных чисел, реализованном в файле stack.c. Унарные числа представляются в стеке в виде связных списков.

Первый этап профилирования заключается в настройке исполняемого файла на сбор профильной информации. Для этого при компиляции и компоновке объектных файлов необходимо указывать флаг -pg. Рассмотрим, к примеру, такую последовательность команд:

% gcc -pg -c -o calculator.o calculator.c

% gcc -pg -c -o stack.o stack.c

% gcc -pg -c -o number.o number.c

% gcc -pg calculator.o stack.o number.o -o calculator

Здесь разрешается сбор информации о вызовах функций и времени их выполнения. Чтобы получать сведения о каждой выполняемой строке программы, укажите флаг -g. При наличии флага -aбудет подсчитываться количество итераций циклов.

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

Получив имя исполняемого файла, утилита gprofпроверяет файл gmon.outи отображает информацию о том, сколько времени заняло выполнение каждой функции. Давайте проанализируем ход выполнения операции 1787 × 13 - 1918 в нашей программе-калькуляторе, создав простой профиль .

Flat profile:

Each sample counts as 0.01 seconds.

% cumulative self self total

time seconds seconds calls ms/call ms/call name

26.07 1.76 1.76 20795463 0.00 0.00 decrement_number

24.44 3.41 1.65 1787 0.92 1.72 add

19.85 4.75 1.34 62413059 0.00 0.00 zerop

15.11 5.77 1.02 1792 0.57 2.05 destroy_number

14.37 6.74 0.97 20795463 0.00 0.00 add_one

0.15 6.75 0.01 1788 0.01 0.01 copy_number

0.00 6.75 0.00 1792 0.00 0.00 make_zero

0.00 6.75 0.00 11 0.00 0.00 empty_stack

Вычисление функции decrement_number()и всех вызываемых в ней функций заняло 26,07% общего времени выполнения программы. Эта функция вызывалась 20795463 раза. Каждый вызов выполнялся 0,00 с, т.е. столь малое время, что его не удалось замерить. Функция add()вызывалась 1787 раз, очевидно для вычисления произведения. Каждый проход по функции занимал 0,92 секунды. Функция copy_number()вызывалась почти столько же раз — 1788, но на ее выполнение ушло всего 0.15% общего времени работы программы. Иногда в отчете присутствуют функции mcount()и profil(), используемые профайлером.

В простом профиле отражается время, затраченное на выполнение каждой функции. Утилита gprofумеет также создавать схему вызовов, где показывается время, проведенное не только в каждой функции, но и во всех вызываемых в ее контексте дочерних функциях.

index % time self children called name

[1] 100.0 0.00 6.75 main [1]

0.00 6.75 2/2 apply_binary_function [2]

0.00 0.00 1/1792 destroy_number [4]

0.00 0.00 1/1 number_to_unsigned_int [10]

0.00 0.00 3/3 string_to_number [12]

0.00 0.00 3/5 push_stack [16]

0.00 0.00 1/1 create_stack [16]

0.00 0.00 1/11 empty_stack [14]

0.00 0.00 1/5 pop_stack [15]

0.00 0.00 1/1 clear_stack [17]

--------------------------------------

0.00 6.75 2/2 main [1]

[2] 100.0 0.00 6.75 2 apply_binary_function [2]

0.00 6.74 1/1 product [3)

0.00 0.01 4/1792 destroy_number [4]

0.00 0.00 1/1 subtract [11]

0.00 0.00 4/11 empty_stack [14]

0.00 0.00 4/5 pop_stack [15]

0.00 0.00 2/5 push_stack [16]

--------------------------------------

0.00 6.74 1/1 apply_binary_function [2]

[3] 99.6 0.00 6.74 1 product [3]

1.02 2.65 1767/1792 destroy_number [4]

1.65 1.43 1767/1767 add [5]

0.00 0.00 1760/62413059 zerop [7]

0.00 0.00 1/1792 make_zero [13]

В первой секции сообщается о том, что на выполнение функции main()и всех ее дочерних функций ушло 100% времени (6.75 секунд). Функцию main()вызвал некто : это означает, что профайлер не смог определить, как был осуществлен вызов. В функции main()дважды вызывалась функция apply_binary_function()(всего таких вызовов в программе было тоже два). В третьей секции сообщается о том, что выполнение функции product()и ее дочерних функций заняло 98% времени. Эта функция вызывалась только один раз из функции apply_binary_function().

По схеме вызовов несложно определить время работы той или иной функции. Однако рекурсивные функции требуют особого подхода. Например, функция even()вызывает функцию odd(), а та — снова функцию even(). Самому длинному из таких циклов присваивается номер и выделяется отдельная секция отчета. Следующий фрагмент профильных данных получен в результате проверки того, является ли результат операции 1787 × 13 × 3 четным:

--------------------------------------

0.00 0.02 1/1 main [1]

[9] 0.1 0.00 0.02 1 apply_unary_function [9]

0.01 0.00 1/1 even [13]

0.00 0.00 1/1806 destroy_number [5]

0.00 0.00 1/13 empty_stack [17]

0.00 0.00 1/6 pop_stack [16]

0.00 0.00 1/6 push_stack [19]

--------------------------------------

[10] 0.1 0.01 0.00 1+69993 [10]

0.00 0.00 34647 even [13]

--------------------------------------

34847 even [13]

[11] 0.1 0.01 0.00 34847 odd [11]

0.00 0.00 34847/186997954 zerop [7]

0.00 0.00 1/1806 make_zero [16]

34846 even [13]

Выражение 1+69693в секции 10 сообщает о том что цикл 1 выполнялся один раз и в нем насчитывается 69693 обращений к функциям. Первой в цикле вызывалась функция even(), а из нее — функция odd. Обе функции вызывались по 34847 раз.

Утилита gprofрасполагает рядом полезных опций.

■ При задании опции -sбудут суммироваться результаты нескольких запусков программы.

■ С помощью опции -cможно узнать, какие дочерние функции могли быть, но так и не были вызваны

■ При задании опции -lотображается построчная профильная информация.

■ При задании опции -Aбудет отображен исходный текст программы, сопровождаемый процентными показателями времени выполнения.

Схема работы утилиты gprofвыглядит следующим образом. Когда в ходе выполнения программы происходит вызов функции, счётчик обращений к функции увеличивается на единицу. Утилита периодически прерывает программу, чтобы выяснить, какая функция выполняется в данный момент. На основании этих '"выборок" и определяется время выполнения. В Linux тактовые импульсы генерируются с интервалом 0,01 с, следовательно, это наименьший промежуток между прерываниями. Таким образом, профильные данные о слишком быстро выполняющихся функциях могут оказаться неточными. Во избежание погрешностей рекомендуется запускать программу на длительные периоды времени или суммировать профильные данные по результатам нескольких запусков (это делается с помощью опции -s).