В приводимой далее таблице показан профиль, сгенерированный рабочей версией спам-фильтра, которую мы создали специально для того, чтобы разобраться в его поведении. В ней используется фиксированное сообщение и фиксированный набор из 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. Итак, Кнут ориентирует нас правильно: небольшая часть программы поглощает большую часть времени ее исполнения.