Протоколирование в программировании

Сайтам, так же как и самолётам, нужны «чёрные ящики», помогающие выяснять подробности изменений в системе или оперативно определять источники сбоев. Рано или поздно возникнет вопрос: «кто вносил изменения в эту запись?», «когда и кем был загружен файл?», «что делал этот посетитель?» Вопрос по-страшнее: «почему это не работает?» На эти, и многие другие вопросы, связанные с протоколированием, будет отвечать инженер, занимающийся поддержкой сайта. Поэтому, хороший программист на этапе разработки любезно и щедро внедряет логирование.

Работа воркеров, обработка запросов пользователей, нештатные ситуации в функционировании приложения — всё это должно логироваться. Цель логирования заключается не только в том, что бы зафиксировать факт какого-либо события, но и в том, что бы предоставить инженеру, занимающемуся поддержкой проекта, исчерпывающую информацию о произошедшем событии, которая позволит упростить и ускорить процесс отладки.

Правила хорошего лога

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

1. Помощь

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

2. Контекст

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

3. Категоризация

Логи нужно «раскидывать» по категориям, что бы было удобнее их анализировать.

4. Мониторинг

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

5. Резервирование

Если вы пишите логи в БД проекта (очень плохой вариант) или во внешние системы (например, «Сентри»), добавляйте в приложение резервный логер, параллельно пишущий в файл на сервере.

Рассмотрим несколько наглядных примеров.

Плохо

Хорошо

Не удалось получить данные RSS.

Level: error.

Не удалось прочитать данные из RSS.

Level: error.

Category: news_import.

Source: http://site.ru/rss.

HTTP status of source: 503.

Trace: <…>.

Ошибка отправки данных.

Level: ошибка.

Не удалось экспортировать статистику в ЦРМ.

Level: error.

Category: statistics_import.

Server: http://site-crm.ru/api/statistic.

Request: <…>.

HTTP status: 500.

Response: <…>.

Trace: <…>.

Произошла критическая ошибка.

Level: emergency.

Ошибка создания новости в БД.

Level: emergency.

Category: news.

Query: <…>.

Trace: <…>.

Ошибка в форме обратной связи.

Уровень: ошибка.

Невалидное сообщение из формы обратной связи.

Level: info.

Category: feedback.

Query: <…>.

User IP: <…>.

User Agent: <…>.

Cookies: <…>.

Session: <…>.

Browser: <…>.

Trace: <…>.

Агрегация

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

Выкатили релиз на тестовую площадку — что-то пошло не так.

Например, выкатив очередной релиз на тестовую площадку, сравните объём записей до и после. Если он непредвиденно резко изменился — что-то пошло не так. И конечно же, настройте рассылку оповещений, что бы в случае ошибок вы моментально о них узнали.

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

Что бы не быть голословным, приведу в пример один из своих проектов. У нас была форма обратной связи, и в какой-то момент часть пользователей начали жаловаться на сообщения об ошибках: «сервис временно недоступен». Однако, в логах бекенда подобных ошибок ни разу не фиксировалось.

Форма была весьма важной частью сайта, критичный функционал, так сказать. Поэтому я логировал абсолютно все уровни ошибок, в т. ч. некорректно заполненные формы от пользователей. Проанализировав такие логи, я обнаружил интересную аномалию — иногда клиент присылал на бекенд сообщения, в которых отсутствовала часть обязательных полей. Без их заполнения клиент просто не мог отправить запрос серверу. Спамеры? Нет, текст сообщений был совершенно адекватен. Запросы присылались в обход «толстого клиента» сайта? Нет, другого приложения не было.

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

Не будь у меня логирования невалидных запросов с заголовками пользователя, процесс поиска ошибки сильно увеличился бы.

Установите удобную систему агрегации логов и она ещё не раз вас выручит. «Кибана», «Сентри», «Грейлог» и другие — выбирайте на свой вкус и под свои задачи.


P. S. Логи — как автотесты — потратив пару лишних минут на разработку, экономишь часы на поддержку проекта. Утверждение «пару лишних минут» не взято с потолка: действительно, имея грамотно настроенные приложение и логер, протоколирование работы скрипта входит в привычку, а сам процесс сводится к простейшему вызову метода и передачи ему сообщения.

Поделиться
Отправить
Запинить
Популярное