3. Отладка и профилирование


3.1 Отладка

Отладка программ в Euphoria значительно проще, чем в большинстве других языков программирования. Широкие проверки правильности работы программы, обеспечиваемые интерпретатором Euphoria, отлавливают множество таких ошибок, которые могли бы в других языках занять у вас часы на их выявление и исправление. Когда интерпретатор останавливает вашу программу из-за возникшей ошибки, вы всегда получаете на экране краткое сообщение о причине остановки и детальный отчёт в файле, который называется ex.err. В совокупности это сообщение и файл дают полное описание того, что случилось, плюс всю цепочку вызовов подпрограмм, приведшую к аварии. В файле ex.err будет также распечатка величин всех переменных вашей программы и, при необходимости, перечень последних выполненных команд. Слишком длинные ряды распечатываются частично. Если файл ex.err вам почему-то не очень удобен, вы можете выбрать другое имя файла, расположив его в любом месте на вашей системе, но для этого придётся вызвать процедуру crash_file().

В дополнение вы можете также создать систему своих типов, которые точно определят набор законных величин для каждой из ваших переменных. И отчёт об ошибке будет выпущен интерпретатором как раз в тот момент, когда одной из ваших типизированных переменных будет присвоена незаконная величина.

Иногда программа будет вести себя неправильно, но все проверки, выполняемые интерпретатором во время её работы, будут проходить нормально, не вызывая аварийных остановок. В любом языке программирования в таких случаях может быть хорошей идеей просто ещё раз изучить исходный код и ещё раз продумать алгоритм, который вы запрограммировали. Может оказаться полезной простая вставка команд печати в стратегических точках, чтобы проследить в них внутреннюю логику программы. Этот подход особенно удобен в интерпретируемых языках, подобных Euphoria, так как вы можете просто отредактировать код и перезапустить программу без необходимости каждый раз ожидать перекомпиляции/перекомпоновки.

Интерпретатор обеспечивает вас дополнительными мощными инструментами для отладки. Используя команду trace(1), вы можете наблюдать трассу исполнения вашей программы на одном экране, а на другом - следить за выводимыми ею численными, текстовыми или графическими данными. Команда trace(2) даёт тот же эффект, что и trace(1), но экран трассировки будет монохромным. Наконец, trace(3) выводит все выполненные команды в файл журнала, который называется ctrace.out.

Специальные команды with trace / without trace задают те части вашей программы, которые вы решили трассировать. Часто вы будете просто вставлять команду with trace в самом начале своего исходного кода, чтобы предусмотреть сквозную трассировку всей программы. Но иногда будет лучше, если вы поставите первую with trace после всех ваших собственных типов, так, чтобы не попадать при трассировке внутрь тела типов после каждого присваивания новой величины каждой из ваших переменных. В некоторых других случаях вы будете точно знать, какую подпрограмму или подпрограммы желательно было бы трассировать, и вам будет необходимо отобрать для трассировки только именно их. Конечно, находясь в окне трассировки (на экране трассировки), вы можете пропустить просмотр исполнения любой подпрограммы, нажав на клавиатуре клавишу со стрелкой вниз вместо Enter.

В файле ctrace.out или в файле ex.err для трассируемых строк кода предусмотрен вывод сообщения "Traced lines leading up to the failure" - "Трассируемые строки, предшествовавшие отказу", если во время работы программы произойдёт аварийная остановка из-за обнаруженной ошибки. Если вам необходима эта информация, но вы не получаете её, необходимо вставить в код команду with trace, а затем перезапустить программу. Работа программы замедляется на тех участках кода, которые откомпилированы с метакомандой with trace, особенно, когда для включения (активации) трассировки используется команда trace(3).

После того, как участок кода, подлежащий трассировке, выделен метакомандами, ваша программа должна затем динамически активировать (включать) процесс трассировки командой trace(). Вы можете просто написать:

        with trace
        trace(1)
в самом начале вашей программы, что обеспечит старт трассировки с момента запуска программы на исполнение. Но более вероятно, что вы захотите включать трассировку при входе в какую-то вполне конкретную подпрограмму, или при наступлении в вашей программе некоторого события или условия, то есть,
        if x < 0 then
            trace(1)
        end if

Аналогично, вы можете выключить (деактивировать) трассировку командой trace(0). Вы можете также выключить трассировку интерактивно, с клавиатуры, нажав клавишу 'q'. Не забывайте, что метакоманда with trace должна быть записана вне тела подпрограммы, т.е. на высшем уровне кода, в то время как команды активации trace() можно писать и внутри подпрограмм, и вне их.

Иногда вам будет необходимо активировать трассировку изнутри типа. Предположим, что вы запускаете программу, а она останавливается с файлом ex.err, из которого следует, что одна из ваших переменных приняла некоторое странное значение, величина которого хотя и законна, но вас удивляет, как это вообще могло произойти. Просто создайте тип для этой переменной, в котором команда trace(1) выполняется, если присваиваемая переменной величина принимает то странное значение, которое так вас заинтересовало, то есть,

        type positive_int(integer x)
            if x = 99 then
                trace(1) -- как это может быть???
                return 1 -- продолжать
            else
                return x > 0
            end if
        end type

Когда positive_int() завершится, вы увидите именно ту команду, которая присвоила вашей переменной странное значение, и тогда сможете проверить величины других переменных, вовлечённых в это действо. Вы сможете также проверить выходной экран вашей программы, чтобы увидеть, что происходит именно в этот момент. Если вы определите positive_int() так, чтобы для странной величины (99) выдавался 0 вместо 1, это вызовет остановку программы с распечаткой диагностической информации в файл ex.err.


3.1.1 Экран трассировки

Когда команды trace(1) или trace(2) исполняются интерпретатором, главный экран вашей программы сохраняется в памяти и на отображение выводится экран трассировки. На нём показан текст вашей программы; команда, которая подлежит исполнению на следующем шаге, выделена в тексте; одновременно в обычном цвете показаны несколько предшествующих и последующих команд. Несколько строк внизу экрана оставлены для отображения имён переменных и их значений. В самой верхней строке (меню) показаны команды, которые вы можете в данной точке ввести с клавиатуры:

F1 - отобразить главный экран программы - для просмотра той информации, которую выводит ваша программа
F2 - вернуться на экран трассировки. Нажмите эту клавишу, если после просмотра главного экрана программы вам необходимо снова вывести экран трассировки.
Enter - исполнить только выделенную в тексте программы команду
стрелка-вниз - продолжить исполнение и прервать его, когда придёт время исполнить команду, следующую в листинге исходного кода высшего уровня за данной командой. Этот пункт меню позволяет вам пропускать трассировку внутренних команд подпрограмм, а также останавливаться на первой команде, следующей за окончанием циклов for и while, если нет необходимости смотреть на все подряд шаги циклов.
? - отобразить величину переменной. После нажатия на клавишу ? вы будете приглашены ко вводу имени переменной. Многие переменные отображаются для вас автоматически по мере присваивания им очередных величин. Если переменная в данный момент не видна, или видна только частично, вы можете вызвать её на отображение отдельно. Длинные ряды ограничиваются одной строкой экрана, но когда вы вызываете ряд на отображение, экран очистится и вы сможете прокрутить ряд, выведенный на отображение с помощью pretty_print(). Затем отображение вернётся в обычный режим с одной строкой под переменную. Переменные, ещё не объявленные в данной точке программы, не могут быть показаны. Переменные, которые ещё не инициализированы, после имени обозначаются как "< NO VALUE >". Отображаются только переменные, но не общие выражения. По мере вашего продвижения по программе, система обновляет все величины, выведенные на экран. Периодически она будет удалять с экрана переменные, сцена которых закончилась или которые довольно долго (в сравнении с быстроменяющимися) не изменяли своего значения.
q - прервать трассировку и возобновить обычное исполнение. Трассировка восстановится, когда интерпретатор встретит очередную команду trace(1) и исполнит её.
Q - прервать трассировку и позволить программе исполняться в обычном порядке до самого завершения. Команды trace() интерпретатором будут игнорироваться.
! - команда немедленно прерывает вашу программу. Трасса недавних последних команд программы и распечатка величин переменных выводятся в файл ex.err.

По мере трассировки вашей программы, имена переменных и их величины будут автоматически появляться в нижней части экрана. Когда переменной присвоено новое значение, вы увидите её имя и новую величину в нижней строке. Отображаемая величина переменной всегда соответствует её текущему значению. Частные переменные автоматически стираются с экрана, как только подпрограмма закончилась. Когда область, выделенная для показа переменных, заполняется, наиболее давние переменные удаляются с экрана, чтобы освободить место для новых. Величины элементов в длинных рядах не отображаются, если уходили бы на экране за пределы 80-ой колонки.

Для вашего удобства, числа, которые находятся в диапазоне кодов символов (32-127) таблицы ASCII, отображаются вместе с собственно символом ASCII. Символ ASCII подсвечивается другим цветом (или забирается в кавычки на монохромном дисплее). Такое преобразование делается для всех переменных, так как Euphoria "не знает", о чём вы на самом деле думаете, о числах или о символах ASCII. Символы ASCII (в кавычках) также выводятся и в файл ex.err. Это дублирование несколько переполняет экран, но информация ASCII часто бывает очень полезной.

Экран трассировки адаптируется к тому графическому режиму, который действует для главного экрана программы. Адаптация делает переключение между экранами более быстрым и лёгким.

Когда по ходу дела в трассируемой программе требуется ввод данных с клавиатуры, открывается главный экран, чтобы дать вам возможность произвести ввод данных так, как вы это обычно делаете. Этот приём хорошо работает с подпрограммой gets(), обеспечивающей ввод (чтение одной строки). А когда задействована подпрограмма get_key() (быстрый опрос клавиатуры), вам даётся 8 секунд, чтобы нажать необходимую клавишу, и если клавиша не нажата, считается, что по данному вызову get_key() ввода не последовало. Этот приём даёт вам возможность проверить случай, когда ввод был, и случай, когда ввода по get_key() не было.


3.1.2 Файл трассировки

Когда ваша программа вызывает trace(3), активируется трассировка в файл. В текущем каталоге открывается файл ctrace.out. В нём записываются последние 500 команд Euphoria, которые выполнены по вашей программе. Здесь работает круговой буфер, в котором содержится максимум 500 команд. Когда достигнут конец ctrace.out, следующая исполненная команда записывается в начале файла. Самая последняя исполненная команда всегда сопровождается строкой "=== THE END ===". Поскольку буфер круговой, запись о последней исполненной команде может появиться в любом месте файла ctrace.out. Команда, записанная перед строкой "=== THE END ===" в уже очень длинном файле, является 500-ой в буфере, последней.

Данная форма трассировки поддержана и интерпретатором, и транслятором с Euphoria на Си. Она бывает особенно полезна, когда случается аврийная остановка на машинном уровне, препятствующая Euphoria в записи обычного диагностического файла ex.err. Взглянув на последнюю перед аварией выполненную команду, вы можете составить обоснованное предположение о причине аварии. Возможно, этой последней командой был вызов poke() по незаконному адресу в памяти. Возможно, это был вызов подпрограммы Си. В некоторых случаях это может быть сигналом о наличии ошибки в собственно интерпретаторе или трансляторе.

Исходный код каждой следующей команды непосредственно перед её исполнением выталкивается для записи в файл ctrace.out, следовательно, наиболее вероятно, что авария произошла именно во время исполнения последней записанной команды, которую вы видите в файле ctrace.out.



3.2 Профилирование

Профилирование включается командой with profile (DOS32, WIN32, Linux, FreeBSD) или командой with profile_time (только DOS32). В результате профилирования вашей программы вы получите специальную её распечатку, которая называется профиль и которая по окончании работы программы вырабатывается интерпретатором и записывается в специальном файле листинга ex.pro. Файл листинга располагается в текущем каталоге.

Имеется два режима профилирования: по счётчику, и по времени. Первый режим, по счётчику, работает, когда вы пишете with profile. Второй режим, по времени, работает, когда вы пишете with profile_time. Вы не можете смешивать эти два режима в единственном прогоне своей программы. Чтобы получить оба профиля, вам потребуется два отдельных её прогона.

Мы осуществили прогон нашей программы sieve8k.ex (программа проверки производительности из каталога demo\bench) и в том, и в другом режиме профилирования. Результаты можно видеть в файлах sieve8k.pro (по счётчику) и sieve8k.pro2 (по времени).

Профилирование по счётчику показывает совершенно точно, сколько раз за время работы вашей программы была выполнена каждая из заданных в ней команд. Если команда не была ни разу выполнена, поле показаний счётчика остаётся пустым.

Профилирование по времени (только для DOS32) показывет приближённую оценку процента общего времени, израсходованного программой на выполнение каждой команды. Если команда ни разу не попала в выборку, поле для записи процента времени останется пустым. Если вы видите в этом поле 0.00, это означает, что команда в выборку попадала, но процент времени, затраченный на её выполнение, не достигает 0.01.

В файл листинга попадут только те команды, которые откомпилированы после записи with profile или with profile_time. Обычно вы будете указывать with profile или with profile_time в самом начале вашего главного файла .ex, чтобы получить в листинге полный отчёт по всем командам. В редакторе Euphoria этот файл имеет раскрашенный синтаксис.

Профилирование может во многом помочь вам отполировать вашу программу до блеска:

  • позволяет вам ясно видеть команды, которые исполняются наиболее напряжённо и требуют к себе особого внимания с точки зрения оптимизации и ускорения кода
  • даёт вам возможность убедиться, что ваша программа на самом деле работает именно так, как вы это задумали
  • может снабдить вас статистикой по входным данным
  • покажет вам, какие участки кода никогда не были даже проверены - не пускайте ваших пользователей впереди себя в очереди за такой пикантной новостью!

Иногда вы захотите сосредоточить своё внимание на детальном разборе определённого действия, выполняемого вашей программой. Например, в игре Language War мы обнаружили, что игра, в общем-то достаточно быстрая, сильно тормозится во время отображения взрыва планеты, разбрасывая 2500 пикселов по всем возможным направлениям. Мы решили, что неплохо было бы разогнать подпрограмму взрыва. Нас не заботил остальной код, так как там скорость была вполне сносной. Мы дали команду profile(0) в самом начале игры, сразу после метакоманды with profile_time, чтобы остановить профилирование, а затем мы вставили команду profile(1) в начале подпрограммы взрыва и команду profile(0) в конце этой подпрограммы. Таким образом, мы могли исполнять игру, создавая многочисленные взрывы и журналируя множество выборок исключительно по эффекту взрыва. Если выборки изменялись и по другим подпрограммам более низкого уровня, мы знали, что те выборки были взяты во время взрыва. Если бы мы просто отслеживали профиль для целой программы, картина не была бы слишком ясной, так как подпрограммы более низкого уровня также использовались для передвижения кораблей, рисования трасс фазоров и т.д. Команда profile() может помочь точно таким же манером, когда вы производите и профилирование по счётчику.


3.2.1 Примечания о профилировании по времени

С каждым тиком и таком системных часов генерируется так называемое прерывание от таймера. Когда вы пишете with profile_time, Euphoria будет брать выборки из вашей программы и смотреть, какая команда выполнялась на момент каждого прерывания от таймера.

Эти прерывания обычно поступают с частотой 18.2 раза в секунду, но если вы вызвали подпрограмму tick_rate(), вы можете выбрать намного более высокую частоту прерываний и, таким образом, получить более точный профиль по времени, так как он будет базироваться на большем числе выборок. По умолчанию, если вы не вызвали tick_rate(), автоматически будет вызвано tick_rate(100), как только вы начали профилирование. Вы можете установить частоту ещё более высокой (скажем, до 1000), но тогда не исключено, что производительность вашей программы снизится.

Каждая выборка требует 4-х байтов в памяти и буфер организуется обычно под 25000 выборок. Если вам необходимо больше, чем 25000 выборок, вы можете затребовать необходимый объём буфера:

        with profile_time 100000
В этом случае зарезервируется пространство под 100000 выборок (к примеру). Если буфер переполняется, выдаётся предупреждение (в начале файла ex.pro). На частоте 100 выборок в секунду ваша программа может исполняться 250 секунд, пока не будет израсходован стандартный буфер на 25000 выборок. В Euphoria нет возможности динамического увеличения объёма буфера во время обработки прерывания. Именно поэтому вы должны задавать увеличение буфера сверх стандартного объёма в своей программе. Но после завершения каждой исполняемой команды высшего уровня Euphoria будет обрабатывать накопленные выборки, освобождая буфер для других выборок. Таким образом, профиль может базироваться на большем числе выборок, чем то, под которое вы фактически зарезервировали пространство.

Процент, показанный на левом поле в файле ex.pro, расчитывается путём отнесения числа выборок, пришедшихся на каждую данную команду, к общему числу взятых выборок, следовательно, если на команду пришлось 50 выборок из общего числа 500 выборок, то в поле, относящемся к этой команде, появится величина 10.0 (10 процентов). Когда профилирование остановлено командой profile(0), прерывания игнорируются, выборки не берутся, и общее число выборок не нарастает.

Увеличивая число выборок, вы можете повысить точность результатов. Тем не менее, необходимо отслеживать отсутствие ситуации, когда программа синхронизирует сама себя с прерываниями от таймера, ожидая отсчёта time(), чтобы продолжить исполнение. Команды, выполняемые сразу после точки, где проверяются часы, могут никогда не дать ни одной выборки, что могло бы дать вам весьма искажённую общую картину, то есть,

        while time() < LIMIT do
        end while
        x += 1 -- эта команда не будет давать выборок

Иногда вы можете встретить значительный процент времени, уходящий на команду return. Такое обычно случается из-за освобождения большого объёма памяти, выделенного под временные и частные переменные, используемые внутри подпрограммы. Значительное время может занимать также процесс высвобождения памяти, когда присваивается новая величина большому ряду.

Если в процесс вовлечена перекачка данных в файл памяти, вы можете увидеть большие траты времени на те команды, которым требуется доступ к дисковой памяти, таким как команды обращения к элементам большого ряда, выгруженного на диск.

 

... продолжение
Часть II - Библиотека подпрограмм