Способы отладки приложений: Протоколирование

Страница 1 из 2
Дмитрий Долгов
Родился в 1973 году. Окончил Санкт-Петербургский Государственный Технический Университет (бывший Политехнический Институт) по специальности "Прикладная математика". Более 8 лет проработал в CREAT Studio, где до недавнего времени занимал пост главного программиста и начальника отдела программирования. Участвовал в выпуске игр для PC, Playstation 2, Xbox и Dreamcast. В настоящее время работает в отделе игровых и мультимедийных продуктов фирмы "1С".

Способы отладки приложений: вводная часть >>

Эта статья продолжает цикл, посвященный способам отладки приложений. Кратко все основные методы были рассмотрены в предыдущей статье, здесь же мы подробно остановимся на одном способе - отладке при помощи протоколирования.

Этот способ является одним из основных для выявления ошибок в том случае, если ваше приложение (или разработанная вами библиотека) запускается на удаленном компьютере. Например, у конечного пользователя или у программистов компании-заказчика. К сожалению, не все программисты относятся к протоколированию работы системы с должным вниманием, что зачастую приводит к трудноразрешимым проблемам после сдачи работ.

Разрабатываем систему протоколирования

В простейшем варианте протоколирование приложения может выглядеть следующим образом:


FILE *log_stream = fopen("mylog.txt", "wt");
...
fprintf(log_stream, "Resource file %s loaded", res_name);
...
fprintf(log_stream, "Loading level %s", map_name);
...

Но это - как самый простой, так и самый неудобный вариант. Давайте рассмотрим, как следует организовывать ведение протокола, и какую информацию необходимо в нем сохранять?

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


FILE *log_stream = fopen("D:\\texture.log", "wt");

for (int i=0; i< texture_list.size(); i++) 
    fprintf(log_stream, "Texture loaded: %s\n", texture_list[i].name());

За организацию такого, с позволения сказать, "протокола" должен устраиваться показательно-массовый расстрел. Во-первых, нет никакой гарантии, что диск D: существует, и что нужный файл может быть открыт для записи. Во-вторых, приложение создает (в том числе и в финальной конфигурации!) файл в совершенно левом месте с кучей ненужной отладочной информации.

Чтобы такого не происходило, протоколирование должно вестись по жестким законам, общим для всех частей приложения. Каждая библиотека имеет право создавать диагностические сообщения, но работа с сообщениями должна проводиться централизованно и организованно, чтобы исключить появление "левых" файлов в произвольных подкаталогах, различных отладочных messagebox и неокаймленных в релиз конфигурации директив asm int 3.

Какие данные потребуются для централизованной обработки сообщений:

  • Текстовое сообщение о произошедшем событии. Очевидно.
  • Приоритет сообщения ("ошибка", "предупреждение" или что-то еще). Крайне желательно. Подробнее - см. ниже.
  • Имя файла и номер строки. Желательно. Теоретически, необходимую строчку можно найти в программе, но нет никакой гарантии, что a) из-за подстановок дополнительных аргументов строчка выглядит именно так, как мы ее ищем; b) строчка с таким текстом только одна на весь проект.
  • Время наступления события. Желательно. В интерактивных приложениях анализ содержимого протокола может дать много ценной информации, если проанализировать время наступления того или иного события. Формат задания времени - на ваш выбор (это может быть как текущее системное время, так и время с момента запуска приложения), но рекомендуемая гранулярность - не менее 1 миллисекунды.
  • Идентификатор библиотеки, которая инициировала сообщение или идентификатор программиста, написавшего это сообщение. Желательно. Подробности будут рассмотрены ниже.
  • Порядковый номер сообщения. Иногда оказывается полезным.

Теперь более подробно рассмотрим некоторые пункты.

Приоритет сообщения или уровень протоколирования

При разработке своей системы протокола можно ориентироваться на уже существующие примеры. Как вариант, проанализируем сообщения, которые выводятся при компиляции исходных файлов в Microsoft Visual Studio - тут можно выделить 3 уровня сообщений:

  1. Информационные сообщения о ходе работы компилятора ("compiling file xxx.cpp", "Done, 0 errors, 0 warnings", …).
  2. Сообщения-предупреждения (Warnings). Не являются критичными для компиляции приложения, но на них стоит обратить внимание.
  3. Сообщения об ошибках (Errors). Обязательны к исправлению перед продолжением компиляции проекта.

Таким образом, в системе протоколирования можно выделить как минимум 3 основных типа сообщений: Notice, Warning, Error. Такая система используется во многих компаниях, но, как правило, оказывается не совсем удобной. Чем больше программистов в компании и чем более часто используется протоколирование, тем больше сообщений попадает в протокол, и в итоге нужные сообщения оказываются "забиты" шумом. Отключите в Visual Studio режимы "Suppress Startup Banner", "Show all progress", установите "Warning Level: 4" и попробуйте найти среди кучи мусора информативные сообщения об ошибке.

Чтобы правильно оценить требуемое количество уровней протоколирования, обратимся к описанию механизма syslogd операционной системы UNIX. В руководстве описываются следующие приоритеты сообщений (syslog (3) man page):

 Priority   Description 
 Debug   Normally used for debugging 
 Info   Informational messages 
 Notice   Conditions that may require attention 
 Warning   Any warnings 
 Err   Any errors 
 Crit   Critical conditions like hardware problems 
 Alert   Any condition that demand immediate attention 
 Emerg   Any emergency condition 

Попробуем перевести эти приоритеты в систему сообщений для игрового приложения. Рассмотренные выше информационные сообщения, предупреждения и ошибки попадают в классификацию Notice, Warning, Err. Остальные приоритеты могут использоваться в следующих целях:

 Priority   Description 
 Debug   Отладочные сообщения. Могут использоваться для глубокой отладки приложения или его отдельных компонент.
Debug: Player position changed to 34.23; 0.08; 18.96 
 Info   Отладочные сообщения. Также используются для отладки приложения или его отдельных компонент.
Info: Player CDT with mesh "Object1" 
 Notice   Информационные сообщения. Информируют о серьезных событиях в ходе игры (завершена инициализация подсистем, начата загрузка уровня, игрок убит и т.д.).
Notice: Loading level "Level1.map"... 
 Warning   Предупреждение. Может использоваться в том случае, если обнаружено некое несоответствие ожидаемому поведению игры.
Warning: Player position outside scene bounding box 
 Err   Сообщение об ошибке. Текущая функция не может быть выполнена правильно, хотя общий процесс игры не прерывается (восстановимая ошибка).
Err: Can't load sound file "attack.wav". Windows error 2. 
 Crit   Сообщение о критической ошибке. Какие-то компоненты приложения могут перестать функционировать.
Crit: Can't detect compatible sound card. All sounds will be disabled. 
 Alert   Сообщение о невосстановимой ошибке. Приложение детектировало некорректную ситуацию, которая c большой долей вероятности может привести к фатальной остановке программы.
Alert: Allocation failed. Not enough memory. 
 Emerg   Фатальное сообщение об ошибке. Как правило, используется в обработчиках Unhandled exceptions и в других случаях, когда приложение оказывается "за гранью" фатальной остановки.
Emerg: Unhanded Exception. Code 0xC0000005 (access violation). Address: 

Приведенная схема не является единственно возможной. Например, уровни Debug и Info, а также Alert и Emerg можно объединить вместе. Можно, наоборот, более подробно расписать условия для каждого из приоритетов и разбить предложенную схему еще на несколько уровней.

В протоколе также рекомендуется сохранять (если это возможно), сообщения assert и сообщения от менеджера памяти о найденных ошибках. В зависимости от идеологии использования assert в той или иной компании, событие assert может создавать сообщение для протокола с приоритетом от Warning до Alert. Сообщения от менеджера памяти (порча памяти, нехватка памяти и т.п.) могут идти с приоритетом Crit или Alert.

В штатном режиме работы сообщения приоритета Warning и более серьезные не должны происходить вообще. Сообщения класса Notice рекомендуется создавать таким образом, чтобы они происходили не чаще, чем 1 раз в несколько секунд. Сообщения приоритета Info и Debug должны отсекаться и не сохраняться в файл.

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

 Type   Time (ms)   Message 
 Notice:   23   Game started, build version 1.01.0562 
 Warn:   167   Windows sound options set to 'Mute'. 
 Notice:   1983   Main resource file loaded, file version: 1.01.0554 
 Notice:   2351   Initialization complete. 
 Notice:   2352   Loading main menu. 
 Notice:   8092   Player selected: "Dima". 
 Warn:   8095   Can't load sound file 'res\sounds\NextMenuItem.wav' 
 Notice:   12361   Loading level "Tutorial.map". 
 Err:   14388   Can't find file "tutorial.mpg" 
 Notice:   14400   "Tutorial.map": loading complete. 
 Notice:   21082   Game paused by player 
 Alert:   22014   heapchk() return code: _HEAPBAD (-4) 
 Emerg:   22015   Unhandled exception. Access violation. 

Идентификатор библиотеки

В состав игрового приложения входит несколько десятков библиотек (или компонент). Чтобы в файле протокола можно было быстро локализовать информацию, относящуюся к той или иной библиотеке, рекомендуется снабжать каждое сообщение некоторым идентификатором. В качестве такого идентификатора могут выступать:

  • Имя файла, в котором записано сообщение (__FILE__). Не всегда удобно - многие библиотеки состоят из нескольких cpp и header файлов. Кроме этого, если в различных частях проекта присутствуют файлы с одинаковыми именами, могут возникнуть конфликты.
  • Имя (ник) программиста, который отвечает за эту библиотеку. Очень удобно делать фильтр и просматривать только свои собственные сообщения, но когда количество программистов приближается к десяти, наступает коллапс. Он может возникнуть и раньше, если над одной частью программы будут работать одновременно двое программистов (или если один из них передал свои дела другому).
  • Идентификатор библиотеки. Наиболее универсальный и удобный способ идентификации. В качестве идентификатора может использоваться простая текстовая строчка или что-либо еще.
 
  стр. 1 из 2  

Copyright © 2016 ООО "ДТФ.РУ". Все права защищены.

Воспроизведение материалов или их частей в любом виде и форме без письменного согласия запрещено.

Замечания и предложения отправляйте через форму обратной связи.

Пользовательское соглашение