Информация о пенальти
Уже сам факт существования "горячей" точки говорит о том, что в программе что-то неправильно. Хорошо, если это чисто алгоритмическая ошибка, которую видно невооруженным глазом (например, наиболее узким местом приложения оказалась пузырьковая сортировка). Хуже, если процессорное время исчезает буквально на пустом месте без всяких видимых на то причин. Еще хуже, если "хищения" таков происходят не систематически, а совершаются при строго определенном стечении каких-то неизвестных нам обстоятельств.
Возвращаясь к предыдущему вопросу: почему указатель pswd загружается так долго? И при каких именно обстоятельствах загрузка y "подскакивает" со своих обычных семи до восьмидесяти тактов? Судя по всему, процессору что-то не понравилось и он обложил эти две машинные команды штрафом (penalty), на время притормозив их исполнение. Можем ли мы узнать когда и за какой проступок это произошло? Не прибегая к полной эмуляции процессора– навряд ли (хотя современные x86 с некоторыми ограничениями позволяют получить эту информацию и так).
Гранды компьютерной индустрии – Intel и AMD уже давно выпустили свои профилировщики, содержащие полноценные эмуляторы выпускаемых ими процессоров, позволяющие визуализировать нюансы выполнения каждой машинной инструкции.
Просто щелкните по строке "mov ecx, DWORD PTR [ebp-28]" и VTune выдаст всю, имеющуюся у него информацию:
Decoder Minimum Clocks
= 1 ; Минимальное время декодирования – 1 такт
Decoder Average Clocks
= 8.7 ; Эффективное время декодирования – 8,7 тактов
Decoder Maximum Clocks
= 86 ; Максимальное время декодирования – 86 тактов
Retirement Minimum Clocks
= 0, ; Минимальное время завершения – 0 тактов
Retirement Average Clocks
= 7.3 ; Эффективное время завершения – 7,3 такта
Retirement Maximum Clocks
= 80 ; Максимальное время завершения – 80 тактов
Total Cycles
= 80 (00,65%) ; Всего времени исполнения – 80 тактов
Micro-Ops for this instruction = 1 ; Кол-во микроопераций в инструкции – 1
The instruction had to wait 0 cycles for it's sources to be ready
("Инструкция ждала 0 тактов пока подготавливались ее операнды, т.е. попросту она их не ждала совсем")
Dynamic Penalty: IC_miss
The instruction was not in the instruction cache, so the processor loads the instruction from the L2 cache or main memory.
("Инструкция отсутствовала в кодовом кэше, и процессор был вынужден загружать ее из кэша второго уровня или основной оперативной памяти")
Occurances
= 1 ; Такое случалось 1 раз
Dynamic Penalty: L2instr_miss
The instruction was not in the L2 cache, so the processor loads the instruction from main memory.
("Инструкция отсутствовала в кэше второго уровня и процессор был вынужден загружать ее из основной оперативной памяти")
Occurances
= 1 ; Такое случалось 1 раз
Dynamic Penalty: Store_addr_unknown
The load instruction stalls due to the address calculation of the previous store instruction.
("Загружающая инструкция простаивала по той причине, что адрес источника рассчитывался предыдущей инструкцией записи")
Occurances
= 10 ; Такое случалось 10 раз
Так, кажется, наше расследование превращается в самый настоящий детектив, еще более запутанный, чем у Агаты Кристи. Если приложить к полученному результату даже самый скромный арифметических аппарат, получится полная чепуха и полная расхождение дебита с кредитом. Судите сами. Полное время выполнения инструкции – 80 тактов, причем, известно, что она выполнялась 11 раз (см. колонку count в листинге 1). А наихудшее время выполнения инструкции составило… 80 тактов! А наихудшее время декодирования и вовсе – 86! То есть, худшее время декодирования инструкции превышает общее время ее исполнения и при этом в десяти итерациях она еще ухитряется простаивать как минимум один такт за каждую итерацию по причине занятости блока расчета адресов.
Да… тут есть от чего поехать крышей!
Причина такого несоответствия заключается в относительности самого понятия времени. Вы думаете время относительно только у Эйнштейна? Отнюдь! В конвейерных процессорах (в частности процессорах Pentium и AMD K6/Athlon) понятие "времени выполнения инструкции" вообще не существует в принципе (см. "Фундаментальные проблемы профилировки в малом. Конвейеризация или пропускная способность vs латентность"). В силу того, что несколько инструкций могут выполняться параллельно, простое алгебраическое суммирование времени их исполнения даст значительно больший результат, нежели исполнение занимает в действительности.
Ладно, оставим разборки с относительностью до более поздних времен, а пока обратим внимание на тот факт, что в силу отсутствия нашей инструкции в кэше (она как раз находится на границе двух кэш линеек) и вытекающей отсюда необходимости загружать ее из основной памяти, в первой итерации цикла она выполняется значительно медленнее, чем во всех последующих. Отсюда, собственно, и берутся эти пресловутые восемьдесят тактов. При большом количестве итераций (а при "живом" исполнении программы оно и впрямь велико) временем начальной загрузки можно и пренебречь, но… Стоп! Ведь профилировщик исполнил тело данного цикла всего 11 раз, в результате чего среднее время выполнения этой инструкции составило 7,6 тактов, что совершенно не соответствует реальной действительности! Ой! Оказывается, это вовсе не горячая точка! И тут совершенного нечего оптимизировать. Если мы увеличим количество прогонов профилировщика хотя бы в четыре раза, среднее время выполнения нашей инструкции понизится до 1,8 тактов и она окажется одним из самых холодных мест программы! Точнее – это вообще абсолютный ноль, поскольку эффективное время исполнения данной инструкции – ноль тактов (т.е. она завершается одновременно с предыдущей машинной командой). Словом, мы навернулись по полной программе.
Отсюда правило: прежде чем приступать к оптимизации, убедитесь, что количество прогонов программы достаточно велико для маскировки накладных расходов первоначальной загрузки.
Короткое лирическое отступление на тему: почему же все так произошло. По умолчанию VTune прогоняет профилируемый фрагмент 1.000 раз. Много? Не спешите с ответом. Наш хитрый цикл устроен так, что его тело получает управление лишь каждые 'z' ? '!' == 0x59 итераций. Таким образом, за все время анализа тело цикла будет исполнено всего лишь 1.000/89 == 11 раз!!! Причем, ни в коем случае нельзя сказать, что это надуманный пример. Напротив! В программном коде такое встречается сплошь и рядом.
while((++pswd[p])>'z') // ß
данный цикл прогоняется профилировщиком 1.000 раз
{
pswd[p] = '!'; // ß
данная инструкция прогоняется всего 11 раз
…
}
Листинг 4 Демонстрация кода, некоторые участки которого прогоняются профилировщиком относительно небольшое количество раз, что искажает результат профилировки.
Поэтому, обнаружив горячу точку в первую очередь убедитесь, что количество ее прогонов достаточно велико. В противном случае полученный результат с большой степенью вероятности окажется недостоверным. И тут мы плавно переходим к обсуждению подсчета числа вызовов каждой точки программы.
Впрочем нет, постойте. Нам еще предстоит разобраться со второй "горячей" точкой и на удивление тормозной скоростью загрузки указателя pswd. Опытные программисты, вероятно, уже догадались в чем тут дело. Действительно, – строка pswd[p] = '!'
– это первая строка тела цикла, получающая управление каждые 0x59 итераций, что намного превосходит "проницательность" динамического алгоритма предсказания ветвлений, используемого процессором для предотвращения остановки вычислительного конвейера. Следовательно, данное ветвление всегда предсказывается ошибочно и выполнение это инструкции процессору приходится начинать с нуля. А процессорный конвейер – длинный. Пока он заполниться… Собственно, тут виновата вовсе не команда "mov edx, DWORD PTR [ebp+0ch]"
– любая другая команда на ее месте исполнялась бы столь же непроизводительно! "Паяльная грелка", до красна нагревающая эту точку программы, находится совсем в другом месте!
Поднимем курсор чуть выше, на инструкцию условного перехода предшествующую этой команде, и дважды щелкнем мышкой. Профилировщик VTune выдаст следующую информацию:
Decoder Minimum Clocks
= 0 ; Минимальное время декодирования – 0 тактов
Decoder Average Clocks
= 0 ; Эффективное время декодирования – 0 тактов
Decoder Maximum Clocks
= 4 ; Максимальное время декодирования – 4 такта
Retirement Average Clocks
= 1 ; Эффективное время завершения – 1 такт
Total Cycles
= 1011 (08,20%) ; Всего времени исполнения – 1010 тактов (8,2%)
Micro-Ops for this instruction = 1 ; Кол-во микроопераций в инструкции – 1
The instruction had to wait (8,11.1,113) cycles for it's sources to be ready
("Эта инструкция ждала минимально 8, максимально 113, а в основном 11,1 тактов пока ее операнды не были готовы")
Dynamic Penalty: BTB_Miss_Penalty ; Штраф типа BTB_Miss_Penalty
This instruction stalls because the branch was mispredicted.
("Эта инструкция простаивала потому что ветвление не было предсказано")
Occurances = 13 ; Такое случалось 13 раз
Наша гипотеза полностью подтверждается. Это ветвление тринадцать
раз предсказывалась неправильно, о чем VTune и свидетельствует! Постой, как тринадцать?! Ведь тело цикла исполняется только одиннадцать! Да, правильно, одиннадцать. Но ведь процессор наперед этого не знал, и дважды пытался передать на него управление, и лишь затем, увидев, что ни одно из двух предсказаний не сбылось, плюнул и поклялся, что никогда – никогда не поставит свои фишки на эту ветку.
ОК. Когда загадки разрешаются – это приятно. Но главный вопрос несколько в другом: как именно их разрешать? Хорошо, что в нашем случае непредсказуемый условный переход находился так близко к "горячей" точке, но ведь в некоторых (и не таких уж редких) случаях "виновник" бывает расположен даже в других модулях программы! Ну что на это сказать… Подходите к профилировке комплексно и всегда думайте головой.Пожалуй, ничего более действенного я не смогу посоветовать…
