Загальна година виконання

Відомості про годину, що додаток витрачає на виконання кожної крапки програми, дозволяють виявити його найбільше "гарячі" ділянки. Правда, отут необхідно зробити одне уточнення. Безпосередній вимір покаже, що, принаймні, 99,99% усього години виконання програма проводити усередині функції main, алі адже очевидно, що "гарячої" є аж ніяк не сама main, а викликувані нею функції! Щоб не викликати в програмістів здивування, профіліровщики звичайно віднімають година, витрачений на виконання дочірніх функцій, із загального години виконання кожної функції програми.

Розглянемо, наприклад, результат профілювання деякого додатка профіліровщиком profile.exe, що входити в комплект поставки компілятора Microsoft Visual C++.

Лістинг 1.1. Приклад профілювання додатка програмою profile.exe

Func Func+Child Hit

Time % Time % Count Function

350,192 95,9 360,982 98,9 10000 _do_pswd (pswd_x.obj)

5,700 1,6 5,700 1,6 10000 _CalculateCRC (pswd_x.obj)

5,090 1,4 10,790 3,0 10000 _CheckCRC (pswd_x.obj)

2,841 0,8 363,824 99,6 1 _gen_pswd (pswd_x.obj)

1,226 0,3 365,148 100,0 1 _main (pswd_x.obj)

0,098 0,0 0,098 0,0 1 _print_dot (pswd_x.obj)

У середньому стовпчику (Func+Child Time) приводитися повний година виконання кожної функції, левова частина якого належить функції main (ну цього й випливало очікувати), за нею з мінімальним відривом треба gen_pswd зі своїми 99,6%, далі йде do_pswd — 98,9% і, сильно відстаючи від її, десь там на відшибі плететься CheckCRC, відтягаючи на собі всього лише 3,0%. А функцією CalculateCRC, з її боязким показником 1,6%, на перший погляд можна й зовсім зневажити! Отже, зважаючи на всі, мі маємо три "гарячих" крапки: main, gen_pswd і do_pswd.

Діаграма, що ілюструє загальний година виконання кожної з функцій. На перший погляд, отут три "гарячих" крапки, але насправді це не так

Втім, функцію main можна відкинути відразу. Вона, зрозуміла праворуч, ні в чому не "винувата". Залишаються функції gen_pswd і do_pswd. Якби це були абсолютно незалежні функції, те "гарячих" крапок було б і впрямь дві, алі в нашім випадку це не так. І, якщо з повного години виконання функції gen_pswd, відняти година виконання її дочірньої функції do_pswd в "матері" завтратитися всього лише…0,7%..... Так! Менше відсотка години виконання!

Звернемося до крайнього лівого стовпчика (лістинг 1.1) таблиці профилировщика (Funct Time), щоб підтвердити наші припущення. Дійсно, у програмі присутня всього лише одна "гаряча" крапка — do_pswd, і тільки її оптимізація здатна істотно збільшити швидкодію додатка.

Діаграма, що ілюструє чистий година роботи кожної з функцій (тобто з відрахуванням години дочірніх функцій). Як видно, у програмі є одна, алі надзвичайно "гаряча" крапка

Добрі, будемо вважати, що найбільше "гаряча" функція визначена й тепер мі палко бажаємо її оптимізувати. А для цього варто б довідатися картину розподілу "температури" усередині самої функції. На жаль, профіліровщик profile.exe (і інші подібні йому) не зможе нічим нам допомогти, оскільки його розв'язна здатність обмежується саме функціями.

Але, на наше щастя існують і більше розвинуті профіліровщики, що впевнено розрізняють окремі рядки й навіть машинні команди! До таким профилировщикам зокрема ставитися VTune від Intel. Давайте завантажимо його й заглянемо усередину функції do_pswd

Лістинг 1.2. Карта розподілу "температури" усередині функції do_pswd, отримана за допомогою профіліровщика VTune

Від тепер зовсім інша праворуч — відразу видно, що доцільно оптимізувати, а що й без того працює відмінно. "Гарячі" крапки головним чином зосереджені навколо конструкції pswd[p], — вона дуже повільно виконується. Чому? Вихідний текст не дає безпосередньої відповіді на поставлене питання й тому зовсім не ясно: що конкретно варто зробити для зниження "температури" "гарячих" крапок.

Доводити спускатися на рівень "голих" машинних команд (благо профіліровщик VTune це дозволяє). Від, наприклад, у що компілятор перетворив необразливий на вид оператор присвоєння pswd[p] = '!'

Лістинг 1.3. Дослідження температури машинних команд усередині конструкції pswd[p] = '!'

В одному рядку вихідного тексту відбувається цілих три звертання до пам'яті! Спочатку покажчик pswd завантажується в регістр EDX, потім він підсумується зі змінної p, що так саме розташована в пам'яті, і лише потім по розрахованому зсуві на згадку благополучно записується константа '!' (021h).

Проте, однаково залишається не ясно, чому завантаження покажчика pswd займає стільки години? Може бути, хтось постійно витісняє покажчик pswd з кэша, змушуючи процесор звертатися до повільної оперативної пам'яті? Так і є! Програма працює з великою кількістю змінних, що свідомо не вміщаються в кеш іншого рівня.