Замеры времени и профилирование
Очевидно, что в затратах времени доминируют две функции: strchr и strncmp, причем обе вызываются из strstr. Итак, Кнут ориентирует нас правильно: небольшая часть программы поглощает большую часть времени ее исполнения. При первом профилировании программы очень часто выясняется, что лидирующие в профиле две-три функции поглощают половину времени и более, как в приведенном случае, и, соответственно, становится сразу же ясно, на чем сконцентрировать внимание.
Концентрируйтесь на критических местах.
Переписав strstr, мы еще раз выполнили профилирование для spamtest и выяснили, что теперь 99.8% времени тратит собственно strstr, хотя в целом программа и стала работать быстрее. Когда одна функция является таким явным узким местом программы, существует только два способа исправить положение: улучшить саму функцию, применив более эффективный алгоритм, или избавиться от этой функции вообще, переписав всю программу.
Мы выбрали второй способ – переписали программу. Ниже приведены первые несколько строк профиля работы программы sparest, использующей последнюю, наиболее быструю реализацию isspam. При этом общее время работы программы существенно уменьшилось, критической точкой стала функция memcmp, а 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, а strncmp и memcmp вызываются одинаковое количество раз. Обратите внимание и на то, что isspam, которая сейчас взяла на себя и функцию strchr, умудряется обойтись гораздо меньшим количеством циклов благодаря тому, что она проверяет на каждом шаге только нужные образцы. Изучение чисел может раскрыть и многие другие детали хода выполнения программы.
"Горячая точка" нередко может быть уничтожена или, по крайней мере, существенно "охлаждена" гораздо более простыми способами, чем мы применили для спам-фильтра. Когда-то давным-давно профилирование Awk показало, что одна функция вызывается примерно миллион раз – в таком цикле:
? for (j ='i; j < MAXFLD; j++) ? clear(j);
Выполнение этого цикла, в котором поля очищались перед считыванием каждой новой строки ввода, занимало почти 50% от всего времени исполнения. Константа MAXFLD – максимальное количество полей в строке ввода – была равна 200. Однако в большинстве случаев использования Awk реальное количество полей не превышало двух-трех.