Протоколирование: рекомендации по трассировке

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

Введение

Очень часто возникает проблема диагностики дефектов в тестовой или рабочей среде, где нет инструментов разработки и отладки. И единственным способом понять, в чем ошибка – добавление строк кода с отладочной информацией и повторная установка приложения, если такие строки не были добавлены ранее. А можно ли сразу писать код так, чтобы информации, которую протоколирует приложение, было бы достаточно для диагностики проблемы?
В статье я совсем не буду касаться таких вопросов как инструменты для протоколирования. Но в любом случае, нужно понимать, что такие инструменты существуют и позволяют фильтровать записываемые в протокол данные и настраивать запись протокола в различные источники.
Основная задача статьи – дать представление разработчикам, какими способами проводится протоколирование, и дать рекомендации о том, где в программе вставлять строчки кода для протоколирования. В этой статье, в основном, будем говорить о трассировке.

Протоколирование

Я рассматриваю протоколирование намного шире, чем просто запись в лог-файл. Для меня протоколирование — это набор средств и методов, которые решают такие задачи:

• Быть уверенным, что система работает и работает правильно
• Понимать, почему система и ее данные находятся в текущем состоянии
• Иметь возможность быстро найти неисправность
• Узнать, как систему можно усовершенствовать

Подходы к протоколированию

Вышеуказанные цели можно конкретизировать, выделив «пользователей» результатов протоколирования, и задачи этих «пользователей». Далее можно выделить средства и методы, с помощью которых эти задачи можно реализовать. Итак, я вижу 4 основных категории «пользователей»:

• Разработчик — специалист, который разрабатывает и улучшает приложение
• Тест инженер — специалист, который отвечает за качество приложения, обнаружение и локализацию дефектов в период разработки
• Системный администратор — специалист службы сопровождения, который отвечает за бесперебойную работу приложения в рабочей среде и своевременное обнаружение ошибок.
• Владелец приложения — бизнес-пользователь, который знает и понимает функционал приложения в целом и, по сути, является владельцем данных приложения; сотрудник для которого разрабатывалось это приложение

В таблице ниже для типов пользователей приведены наиболее часто используемые ими в работе методы и средства для решения своих задач.

Указанные в таблице средства и методы кратко описаны ниже.

• Трассировка — инструмент, который обычно называют «логом», по сути, хранилище, куда пишется подробная информация о ходе выполнения программы (последовательно, в порядке возникновения событий). Это обычно текстовый файл или таблица базы данных. Данный инструмент нужен разработчику, тест-инженеру или специалист службы сопровождения для детального анализа того, что происходит в приложении.
• Журнал событий — инструмент, который показывает события в приложении с точки зрения администратора. Т.е. события, по которым системный администратор может сказать в рабочем ли состоянии приложение или нет. Если говорить о разработке ПО для Windows ­—то это чаще всего Windows Event Log или собственные журналы приложений. Я сторонник того, чтобы не смешивать хранилища для трассировки и журнал событий.
• Журнал аудита — инструмент, который позволяет пользователю приложения понять, кто и какие действия выполнял (или пытался выполнять) в системе
• Счетчики производительности— инструмент системного администратора, который помогает обнаружить узкое место в производительности системы. Примером такого инструмента может быть Performance Monitor, встроенный в операционную систему Windows. Для других ОС существуют аналогичные инструменты
• Состояние объектов/процессов — инструмент, который помогает понять, в каком состоянии (или в какой стадии) находятся в текущий момент объекты или процессы в приложении, и как они в это состояние или стадию обработки они попали.
  Например: представим себе приложение, которое обрабатывает входящие почтовые электронные сообщения. Для каждого такого сообщения можно выделить состояния: получено, обработано, удалено. В «журнал состояний объектов/процессов» в таком случае следует записать ключевую информацию по письму, историю смены состояний письма и сообщения при его обработке. Таким образом, полностью отделяется важная информация по процессу обработки письма от «мусора»

Выбор и реализация методов протоколирования — очень важная задача, от реализации которой зависит скорость и качество обнаружения и исправления дефектов и качества сопровождения. Поэтому на стадии планирования и разработки этой задаче нужно уделить досрочно внимания и подобрать достаточный набор методов протоколирования.

Трассировка

* картинка взята из статьи Lazy logger levels ^[1]

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

• обо всех ошибках – обработанных и не обработанных
• параметры запуска и загруженную конфигурацию
• а также события, описанные ниже.

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

• Какие события нужно писать в трассировочный лог
• Как правильно выбрать уровень для события
• Как правильно выбрать категории событий
• Какую информацию нужно записывать при возникновении того или иного события

Это и будет рассмотрено далее в статье.

Какие события нужно вносить в трассировочный лог

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

• Используется ли модульные тесты при разработке.
  Использование модульных тестов позволяет значительно снизить количество ошибок в бизнес логике методов, не взаимодействующих с внешними системами (внешними по отношению к данному слою приложения). Однако при взаимодействии кода с внешней системой (взаимодействие кода бизнес слоя с базой данных, взаимодействие слоев бизнес логики, расположенных на разных компьютерах и прочее) модульные тесты не эффективны потому, что конфигурация разных слоев может быть разной в разных средах. Исходя из этого, можно сделать вывод, что при использовании модульных тестов логично выполнять только трассировку взаимодействий между слоями и трассировку ошибок (т.к. считаем, что логика каждого слоя в отдельности очень хорошо протестирована). Если же модульных тестов нет — трассировать нужно каждую ветку логики программы (вход в метод, выход, возникновение в методе ошибки, каждую ветку условного оператора)
• Тип приложения.
  В таблице представлены некоторые типы приложений и события для протоколирования в трассировочный лог (понятно, что есть и другие типы приложений).

Какие данные нужно вносить в трассировочный лог

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

Уровни трассировки

Уровни в основном используются для фильтрации событий при записи в журнал. Это нужно для предотвращения записи в журнал данных, которые в данный период времени не нужны.
Например, такой инструмент как NLog, предоставляет по умолчанию 6 уровней событий (от более детального до менее детального): trace, debug, info, warn, error, fatal (более детально см. в документации к NLog ^[2])
Далее, в конфигурации можно указать, что, например, в рабочей среде, в журнал трассировки писать события уровня Error и Fatal (а все остальные игнорировать), а при возникновении проблемы изменить конфигурацию так, чтобы записывать все события.
Следующая таблица показывает мои рекомендации по выбору уровней событий при трассировке

Выбор категорий событий

Второй важный параметр, по которому можно настроить фильтрацию записи событий в журнал — это категории событий. Эти категории разработчик должен выбирать сам (т.е. инструменты не предоставляют категории по умолчанию)
Я рекомендую придерживаться таких рекомендаций — для каждого отдельного логического уровня сделать отдельную категорию. Например: уровень интерфейса (UIControls), уровень бизнес-логики (BusinessLogic), уровень доступа к данным (DAL), модуль поиска (Search), программа настройки конфигурации (ConfigManager) и так далее.
Далее, если у вас есть отдельные компоненты внутри слоя, то можно для их трассировки выбрать отдельные подкатегории, отделяя от основной категории точкой.
Например, визуальный компонент для отображения облака тегов (который располагается в уровне интерфейса)— UIControls.TagsControl.
Таким образом, при возникновении проблемы с компонентом, с одной стороны вы всегда сможете по журналу определить, какой компонент создал то или иное событие, с другой — более гибко настроить фильтрацию записи в журнал событий только по выбранному компоненту.

Заключение

Протоколирование — важная функция в любом приложении и требует внимательного анализа и проектирования. Несмотря на то, что трассировка обычно не описывается в требованиях, правильное ее использование может в значительной степени ускорить процесс обнаружения и исправление дефектов на тестовой и рабочей среде.
Данные выкладки — это мои практика и наблюдения, и, соответственно, у вас могут быть свой опыт и своя методика по использованию протоколирования (и трассировки в частности). С удовольствием выслушаю критические отзывы и замечания для улучшения рекомендаций.

Что еще почитать по трассировке

• Способы отладки приложений: Протоколирование http://dtf.ru/articles/read.php?id=36547 ^[3]
• Каким должен быть правильный лог-файл — http://www.codeart.ru/2011/02/23/kakim-dolzhen-byt-pravilnyj-log-fajl/ ^[4]
• What Goes Into A Trace Log? — http://www.informit.com/guides/content.aspx?g=dotnet&seqNum=228 ^[5]
• Tracing (software) — http://en.wikipedia.org/wiki/Tracing_(software) ^[6]
• The Art of Logging — http://www.codeproject.com/Articles/42354/The-Art-of-Logging ^[7]
• Правильное логгирование в Microsoft .NET Framework http://habrahabr.ru/post/98638/ ^[8]

Автор: PavelN