Замеры времени и профилирование Автоматизируйте замеры времени. В большинстве систем существуют команды, позволяющие выяснить, сколько времени работала программа. В Unix такая команда называется time: Эта команда запускает программу и возвращает три числа, означающих время в секундах: время real — физическое время, израсходованное до завершения работы программы; время user — время процессора, потраченное на исполнение самой программы; время sys — время, потраченное на программу операционной системой. Если в вашей системе есть аналогичная команда, используйте ее — числа будут более информативными и надежными, и делать отсчеты будет проще, чем при использовании секундомера. Ведите подробные записи. При работе над программой — внесении модификаций и/или проведении измерений -т у вас накопится огромное количество данных, в которых вам будет трудно разобраться по памяти уже через день-два. (Какая именно версия работает на 20 % быстрее?) Многие технологии, которые мы обсуждали в главе о тестировании, могут быть адаптированы и к измерениям времени и улучшению производительности. Используйте компьютер для запуска набора тестов и измерения времени их работы, а самое главное — используйте регрессивное тестирование, чтобы удостовериться в том, что "улучшения" производительности не нарушили корректности программы. Если в вашей системе нет команды time или вы хотите замерить время работы отдельно взятой функции, не так трудно создать себе оснастку для таких замеров — по аналогии с тестовой оснасткой. В С и C++ существует стандартная функция clock, которая сообщает, сколько процессорного времени программа использовала до текущего момента. Ее можно вызвать перед интересующей вас функцией и после нее и таким образом вычислить время ее исполнения процессором: Масштабирующий коэффициент CLOCKS_PEfi_SEC характеризует разрешение таймера, возвращаемое clock. Если функция выполняется за доли секунды, запустите ее в цикле, но (если измерения должны быть особо точными) не забудьте компенсировать затраты времени на сам цикл: В Java функции класса Date выдают текущее системное время, которое приблизительно равно времени, использованному процессором: Значение, возвращаемое getTime, измеряется в миллисекундах. Используйте профилировщик. Не считая такого надежного и достоверного способа, как замер времени исполнения программы, самым важным инструментом для анализа производительности является система для генерации профилей. Профиль (profile) -- это измерение того,,где именно программа "тратит время". Некоторые профили предоставляют список всех функций, количество вызовов каждой из них и долю потребляемого каждой функцией времени от общего времени исполнения программы. Другие показывают, сколько раз было выполнено каждое выражение. Выражения, которые выполняются часто, сильнее влияют на время исполнения, а те, которые не выполняются никогда, скорее всего, являются бесполезным или неадекватно оттестированным кодом. Профилирование — эффективный способ поиска горячих точек (hot spots), или критических мест программы, то есть функций ши^фрагмен-тов кода, которые расходуют львиную долю всего времени исполнения программы. Однако же интерпретировать результаты профилирования надо с достаточной степенью осторожности. Из-за изощренности компиляторов, сложности организации кэширования и работы с памятью, а также из-за того, что сам процесс профилирования влияет на производительность, статистические показатели в профилях могут быть только приблизительными. В 1971 году в работе, где впервые был представлен термин "профилирование", Дон Кнут написал, что, "как правило,-менее 4 % программы поглощают более половины от всего времени исполнения". Принимая во внимание это замечание, можно сделать вывод о способах применения профилирования: с его помощью определяются участки программы, поглощающие большую часть времени работы, в них вносятся улучшения, и процесс повторяется еще раз для поиска новых критических мест. Выясняется, что после одной-двух подобных итераций характерных "горячих точек" не остается. Профилирование обычно включается специальным флагом или опцией компилятора. Программа выполняется, и после этого показываются результаты работы профилировщика. В Unix таким флагом является, как правило, -р, а профилировщик называется prof: В приводимой далее таблице показан профиль, сгенерированный рабочей версией спам-фильтра, которую мы создали специально для того, чтобы разобраться в его поведении. В ней используется фиксированное сообщение и фиксированный набор из 217 фраз, который сравнивается с сообщением 10 000 раз. Запуск производился на машине MIPS R10000 250 MHz; использовалась изначальная версия st rst r — с вызовами других стандартных функций. Результаты были переформатированы для более удачного размещения на странице. Обратите внимание на то, что размер ввода (217 фраз) и количество запусков (10 000) можно использовать для проверки правильности работы — эти числа появляются в колонке "calls" (вызовы), в которой показано количество вызовов каждой функции. 12234768552: Total number of instructions executed 13961810001: Total computed cycles 55.847: Total computed execution time (sees.) 1.141: Average cycles / instruction secs % cum% cycles instructions calls function 45.260 81.0 81.0 11314990000 9440110000 48350000 strchr 6.081 10.9 91.9 1520280000 1566460000 46180000 strncmp 2.592 4.6 96.6 648080000 854500000 2170000 strstr 1.825 3.3 99.8 456225559 344882213 2170435 strlen 0.088 0.2 100.0 21950000 28510000 10000 isspam 0.000 0.0 100.0 100025 100028 1 main 0.000 0.0 100.0 53677 70268 219 memccpy 0.000 0.0 100.0 48888 46403 217 memcmp 0.000 0.0 100.0 17989 19894 219 isspam 0.000 0.0 100.0 16798 17547 230 strlen 0.000 0.0 100.0 10305 10900 204 realfree 0.000 0.0 100.0 6293 7161 217 estrdup 0.000 0.0 100.0 6032 8575 231 cleanfree 0.000 0.0 100.0 5932 5729 1 readpat 0.000 0.0 100.0 5899 6339 219 getline 0.000 0.0 100.0 5500 5720 220 malloc Очевидно, что в затратах времени доминируют две функции: strchr и strncmp, причем обе вызываются из strstr. Итак, Кнут ориентирует нас правильно: небольшая часть программы поглощает большую часть времени ее исполнения. При первом профилировании программы очень часто выясняется, что лидирующие в профиле две-три функции поглощают половину времени и более, как в приведенном случае, и, соответственно, становится сразу же ясно, на чем сконцентрировать внимание. Концентрируйтесь на критических местах. Переписав st rst r, мы еще раз выполнили профилирование для spamtest и выяснили, что теперь 99.8 % времени тратит собственно strstr, хотя в целом программа и стала работать быстрее. Когда одна функция является таким явным узким местом программы, существует только два способа исправить положение: улучшить саму функцию, применив более эффективный алгоритм, или/ке избавиться от этой функции вообще, переписав всю программу. Мы выбрали второй способ — переписали программу. Ниже приведены первые несколько строк профиля работы программы sparest, использующей последнюю, наиболее быструю реализацию isspam. При этом общее время работы программы существенно уменьшилось, критической точкой стала функция memcmp, a isspam стала заш'мать более существенную долю от общего времени. Эта версия гораздо сложнее предыдущей, однако эта сложность окупается с лихвой благодаря отказу от использования strlen и strchr в isspam и замене sees % cum% cycles instructions calls function strncmp на memcmp, которая тратит меньше усилий и» обработку каждого байта. secs % cum% cycles instructions calls function 3.524 56.9 56.9 880890000 1027590000 46180000 memcmp 2.662 43.0 100.0 665550000 902920000 10000 isspam 0.001 0.0 100.0 140304 106043 652 strlen 0.000 0.0 100.0 100025 100028 1 main Весьма поучительно будет потратить некоторое время на сравнение счетчиков циклов и количества вызовов различных функций в двух профилях. Отметьте, что количество" вызовов strlen упало от нескольких миллионов до 652, a strncmp и memcmp вызываются одинаковое количество раз. Обратите внимание и на то, что isspam, которая сейчас взяла на себя и функцию st rch r, умудряется обойтись гораздо меньшим количеством циклов благодаря тому, что она проверяет на каждом шаге только нужные образцы. Изучение чисел может раскрыть и многие другие детали хода выполнения программы. "Горячая точка" нередко может быть уничтожена или, по крайней мере, существенно "охлаждена" гораздо более простыми способами, чем мы применили для спам-фильтра. Когда-то давным-давно профилирование Awk показало, что одна функция вызывается примерно миллион раз — в таком цикле: ? for (j ='i; j < MAXFLD; j++) ? clear(j); Выполнение этого цикла, в котором поля очищались перед считыванИем каждой новой строки ввода, занимало почти 50 % от всего времени исполнения. Константа MAXFLD — максимальное количество полей в строке ввода — была равна 200. Однако в большинстве случаев использования Awk реальное количество полей не превышало двух-трех. Таким образом, огромное количество времени тратилось на очистку полей, которые никогда и не устанавливались. Замена константы на предыдущее значение максимального количества полей дало выигрыш в скорости 25 %. Все исправления свелись к изменению верхней границы цикла: for (j = i; j < rnaxfld; j++) clear(j); maxfld = i; Постройте график. Особенно удачным получается представление замеров производительности в виде графиков. Графики помогут более наглядно представить информацию о влиянии изменения параметров, сравнить алгоритмы и структуры данных, а иногда и указать на неожиданное поведение программы. Графики длин цепочек для нескольких хэш-мультипликаторов в главе 5 явно продемонстрировали преимущества одних мультипликаторов перед другими. На представленном ниже графике показано влияние размера массива хэш-таблицы на время исполнения С-версии программы ma rkov; в качестве вводимого текста использовались Псалмы (42 685 слов, 22 482 префикса)., Мы поставили два эксперимента. В первой серии запусков программа использовала размеры массивов, которые являлись степенями двойки — от 2 до 16 384; в другой версии использовались размеры, которые являлись максимальным простым числом, меньшим каждой степени двойки. Мы хотели посмотреть, приведет ли использование простых чисел в качестве размеров массивов к ощутимой разнице в производительности. На графике ясно видно, что время исполнения для такого ввода не зависит от размера таблицы при размерах, больших 10 000 элементов; также нет и существенной разницы между использованием в качестве размеров таблицы степеней двойки или простых чисел. Упражнение 7-2 Вне зависимости от того, есть на вашей машине команда time или нет, используйте clock или getTime для создания собственного измерителя времени. Сравните его результаты с системным временем. Как влияет на результаты другая активность на машине? Упражнение 7-3 В первом профиле st rch г вызывалась 48 350 000 раз, a st rncmp — только 46 180 000 раз. Объясните это различие.