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

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

    Введение


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

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



    Я рассматриваю протоколирование намного шире, чем просто запись в лог-файл. Для меня протоколирование — это набор средств и методов, которые решают такие задачи:
    • Быть уверенным, что система работает и работает правильно
    • Понимать, почему система и ее данные находятся в текущем состоянии
    • Иметь возможность быстро найти неисправность
    • Узнать, как систему можно усовершенствовать


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


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

    В таблице ниже для типов пользователей приведены наиболее часто используемые ими в работе методы и средства для решения своих задач.
    Аудитория Задача Средства и методы
    Разработчик
    • Найти место возникновения проблем и исправить их
    • Выполнить оптимизацию
    • Трассировка
    • Счетчики производительности
    • Состояние объектов/процессов
    Тест инженер
    • Быть уверенным, что система работает корректно
    • Обнаружение дефектов
    • Максимально точно определить место и причину возникновения найденных дефектов
    • Журнал событий
    • Журнал аудита
    • Состояние объектов/процессов
    Системный администратор
    • Быть уверенным, что система работает
    • Если есть ошибки понять почему (по чьей вине, где исправлять)
    • Если работает медленно – понять почему
    • Журнал событий
    • Счетчики производительности
    • Состояние объектов/процессов
    Владелец приложения
    • Быть уверенным, что система работает именно так, как нужно
    • Журнал аудита
    • Состояние объектов/процессов

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

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

    Трассировка



    * картинка взята из статьи Lazy logger levels

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

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

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

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

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

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

    Кроме простого названия (описания) события, для анализа работы часто нужна еще дополнительная информация. Следующая таблица показывает данные, которые полезно было бы записывать. Понятно, что далеко не всегда нужно писать события настолько подробно. Кроме того, обычно инструменты трассировки позволяют некоторую из указанной ниже информации записывать автоматически.
    Данные Описание
    Дата и время Дата и время возникновения события
    Сервер Сервер, на котором событие возникло (полезно при анализе журналов, собранных с различных серверов)
    Процесс Название процесса, где возникло событие. Это необходимо, например, в случае если разные процессы используют общие библиотеки.
    Метод Название метода, возможно, включающий название класса и библиотеки
    Категория события Название слоя или логического модуля
    Уровень Уровень детализации события
    Название Название события (запуск или завершение метода, ошибка, изменение состояние объекта и прочее)
    Детальная информация Например, детальная информация об ошибке (а при критической ошибке может быть и детальная информация о системе), значение параметра(-ов), название объекта или описание действия над объектом
    Учетная запись, под которой работает процесс  
    Учетная запись пользователя, который вызвал действие Учетная запись пользователя, который сделал начальный вызов, что привело к данному событию
    Стек Стек вызовов методов, которая привела к данному событию. Может быть полезен при детальном анализе события
    Корреляционный номер процесса Если приложение многопользовательское, то важно понимать к какому запросу (пользователю) относится та или иная запись о события
    Корреляционный номер инициирующего процесса Если приложение распределенное, то данный номер используется для сопоставления событий на разных серверах (или процессах). Например, можно передавать с клиента на сервер корреляционный номер и сохранять его при трассировке. В дальнейшем можно сопоставлять вызов клиентского приложения с событием на сервере

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

    Уровни в основном используются для фильтрации событий при записи в журнал. Это нужно для предотвращения записи в журнал данных, которые в данный период времени не нужны.
    Например, такой инструмент как NLog, предоставляет по умолчанию 6 уровней событий (от более детального до менее детального): trace, debug, info, warn, error, fatal (более детально см. в документации к NLog)
    Далее, в конфигурации можно указать, что, например, в рабочей среде, в журнал трассировки писать события уровня Error и Fatal (а все остальные игнорировать), а при возникновении проблемы изменить конфигурацию так, чтобы записывать все события.
    Следующая таблица показывает мои рекомендации по выбору уровней событий при трассировке
    Событие Уровень
    Загруженная конфигурация / смена конфигурации Info
    Действия пользователя Info
    Начало и окончание каждого «публичного» метода (или метода, который реализует логику согласно спецификации), входные/выходные параметры, результат работы такого метода Info
    В публичных методах входные/выходные параметры, которые являются наборами данных Debug
    Логика (ветки программы) описанная спецификацией Info
    Начало и окончание остальных методов, входные/выходные параметры, результат работы Trace
    Шаги остальных методов Trace
    Доступ к внешним ресурсам (например: БД, web-сервисы) Info
    Детальная информация о запросах (командах) доступа к внешним ресурсам и полученном результате Debug
    Неожиданные исключения (не критические) Error
    Исключение, описанное в спецификации Warn/Error
    Обработанные исключения Warn/Info/ Debug
    Критическое исключение (обработанное или не обработанное) Fatal

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

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

    Заключение


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

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


    Инфопульс Украина
    Creating Value, Delivering Excellence
    Ads
    AdBlock has stolen the banner, but banners are not teeth — they will be back

    More

    Comments 9

      +4
      Статья весьма дельная и полезная. Однако на мой взгляд Вы забыли упомянуть о том, что в коммерческих приложения логирование может раскрывать секреты и как вывод программист может помогать конкурентам. Было бы здорово, чтобы Вы о таких случаях тоже упомянули.
        0
        После релиза приложения все дебажные логи отключают, оставляя сугубо журнал событий. Оставлять такую информацию, еще и с трейсерными вызовами было бы опрометчиво. Хотя я ловил такие логи у некоторых скачанных с маркета Android приложениях :)
          0
          Как будто java-декомпиляторов не существует…
            0
            Спасибо за комментарий.
            С разработкой коробочных решений я не сталкивался. А решения, в разработке которых брал участие, — полностью, вместе с исходными кодами, передавалось заказчику. Так что, проблемы раскрытия секретов просто не стоял. Кроме того, предоставлялась последующая гарантийная поддержка. И в этом случае полноценное протоколирование и трассировка просто необходимы как самому заказчику, так и команде сопровождения.
            В любом случае очень интересная мысль, — наверное, идея для отдельной статьи :)
            0
            Может кто знает, вопрос конкретно по реализации логирования на С++ под Windows:
            возможно ли каким-то способом прозрачно получить в текущей функции имя вызывающей функции? Прозрачно здесь означает не передавая через параметры это имя явно. В служебных функциях при выводе данных в лог хочется знать кто «виновник» изначально.
              +1
              Smell: если вам действительно это надо — вы скорее всего что-то делаете не так
                +1
                ну через SEH можно www.codeproject.com/Articles/1748/Several-classes-for-exception-handling (обычно стек трейс собственно для ошибок нужен фатальных). Конечно, дампы помогут лучше…
                А еще можно прикрутить AOP (aspect oriented programming)…
                  0
                  Можно подробней о AOP не совсем понял что Вы имеете в виду под «прикрутить»? )
                    0
                    В с++ «из коробки» AOP нет и никогда не было. Возможно добавить свой «логгер» вида «вошли в функцию — вышли из функции» руками (многие так и делают) — но это утомительно. Гораздо проще повесить аспект «логировать вход и выход из функций», который (например) будет логировать входы-выход в per-thread контейнер, доступный из функций непосредственно логгера (например в ERROR строке лога чтобы отображать данные из этого контейнера).

              Only users with full accounts can post comments. Log in, please.