Что такое отправить лог разработчикам
Что такое логирование?
Известно, что программисты проводят много времени, отлаживая свои программы, пытаясь разобраться, почему они не работают — или работают неправильно. Когда говорят про отладку, обычно подразумевают либо отладочную печать, либо использование специальных программ – дебагеров. С их помощью отслеживается выполнение кода по шагам, во время которого видно, как меняется содержимое переменных. Эти способы хорошо работают в небольших программах, но в реальных приложениях быстро становятся неэффективными.
Сложность реальных приложений
Возьмем для примера типичный сайт. Что он в себя включает?
И это только самый простой случай. Реальность же значительно сложнее: множество разноплановых серверов, системы кеширования (ускорения доступа), асинхронный код, очереди, внешние сервисы, облачные сервисы. Все это выглядит как многослойный пирог, внутри которого где-то работает нами написанный код. И этот код составляет лишь небольшую часть всего происходящего. Как в такой ситуации понять, на каком этапе был сбой, или все пошло не по плану? Для этого, как минимум, нужно определить, в каком слое произошла ошибка. Но даже это не самое сложное. Об ошибках в работающем приложении узнают не сразу, а уже потом, — когда ошибка случилась и, иногда, больше не воспроизводится.
Логирование
И для всего этого многообразия систем существует единое решение — логирование. В простейшем случае логирование сводится к файлу на диске, куда разные программы записывают (логируют) свои действия во время работы. Такой файл называют логом или журналом. Как правило, внутри лога одна строчка соответствует одному действию.
Выше небольшой кусок лога веб-сервера Хекслета. Из него видно ip-адрес, с которого выполнялся запрос на страницу и какие ресурсы загружались, метод HTTP, ответ бекенда (кода) и размер тела ответа в HTTP. Очень важно наличие даты. Благодаря ей всегда можно найти лог за конкретный период, например на то время, когда возникла ошибка. Для этого логи грепают:
Когда программисты только начинают свой путь, они, часто не зная причину ошибки, опускают руки и говорят «я не знаю, что случилось, и что делать». Опытный же разработчик всегда первым делом говорит «а что в логах?». Анализировать логи — один из базовых навыков в разработке. В любой непонятной ситуации нужно смотреть логи. Логи пишут все программы без исключения, но делают это по-разному и в разные места. Чтобы точно узнать, куда и как, нужно идти в документацию конкретной программы и читать соответствующий раздел документации. Вот несколько примеров:
Многие программы логируют прямо в консоль, например Webpack показывает процесс и результаты сборки:
Во фронтенде файлов нет, поэтому логируют либо прямо в консоль, либо к себе в бекенды (что сложно), либо в специализированные сервисы, такие как LogRocket.
Уровни логирования
Чем больше информации выводится в логах, тем лучше и проще отладка, но когда данных слишком много, то в них тяжело искать нужное. В особо сложных случаях логи могут генерироваться с огромной скоростью и в гигантских размерах. Работать в такой ситуации нелегко. Чтобы как-то сгладить ситуацию, системы логирования вводят разные уровни. Обычно это:
Поддержка уровней осуществляется двумя способами. Во-первых, внутри самой программы расставляют вызовы библиотеки логирования в соответствии с уровнями. Если произошла ошибка, то логируем как error, если это отладочная информация, которая не нужна в обычной ситуации, то уровень debug.
Во-вторых, во время запуска программы указывается уровень логирования, необходимый в конкретной ситуации. По умолчанию используется уровень info, который используется для описания каких-то ключевых и важных вещей. При таком уровне будут выводиться и warning, и error. Если поставить уровень error, то будут выводиться только ошибки. А если debug, то мы получим лог, максимально наполненный данными. Обычно debug приводит к многократному росту выводимой информации.
Уровни логирования, обычно, выставляются через переменную окружения во время запуска программы. Например, так:
Существует и другой подход, основанный не на уровнях, а на пространствах имен. Этот подход получил широкое распространение в JS-среде, и является там основным. Фактически, он построен вокруг одной единственной библиотеки debug для логирования, которой пронизаны практически все JavaScript-библиотеки как на фронтенде, так и на бекенде.
Принцип работы здесь такой. Под нужную ситуацию создается специализированная функция логирования с указанием пространства имен, которая затем используется для всех событий одного процесса. В итоге библиотека позволяет легко отфильтровать только нужные записи, соответствующие нужному пространству.
Запуск с нужным пространством:
Ротация логов
Со временем количество логов становится большим, и с ними нужно что-то делать. Для этого используется ротация логов. Иногда за это отвечает сама программа, но чаще — внешнее приложение, задачей которого является чистка. Эта программа по необходимости разбивает логи на более мелкие файлы, сжимает, перемещает и, если нужно, удаляет. Подобная система встроена в любую операционную систему для работы с логами самой системы и внешних программ, которые могут встраиваться в нее.
С веб-сайтами все еще сложнее. Даже на небольших проектах используется несколько серверов, на каждом из которых свои логи. А в крупных проектах тысячи серверов. Для управления такими системы созданы специализированные программы, которые следят за логами на всех машинах, скачивают их, складывают в заточенные под логи базы данных и предоставляют удобный способ поиска по ним.
Здесь тоже есть несколько путей. Можно воспользоваться готовыми решениями, такими как DataDog Logging, либо устанавливать и настраивать все самостоятельно через, например, ELK Stack
Профессиональный подход к ведению логов
Логи можно сравнить с уликами на месте преступления, а разработчиков — с криминалистами. Роль логов трудно переоценить, ведь когда необходимо найти баг или причину сбоя, сразу обращаются к ним. Подобно тому, как отсутствие улик приводит к нераскрытым делам, отсутствие содержательных логов осложняет диагностику и устранение ошибок, превращая их в затянувшийся или вовсе невыполнимый процесс. Мне приходилось наблюдать, как люди мучились с такими инструментами, как Strace и tcpdump, или развертывали новый код в продакшене во время сбоя лишь затем, чтобы получить больше лог-файлов для выявления проблемы.
Как говорится: “Хорошо подготовиться — половину дела сделать”, так что каждому профессиональному разработчику следует научиться эффективно вести логи и быть готовым к работе с ними. В данной статье мы не только рассмотрим список полезных практик логирования в приложении, но и разберем теоретические основы данного процесса: что записываем, когда и кто этим должен заниматься.
Как осуществляется процесс отладки?
Прежде чем начать разговор о логах, необходимо ответить на два вопроса:
Программа как переходы состояний
Программа — это серия переходов между состояниями.
Состояния — это вся информация, которую программа хранит в своей памяти в определенный момент времени, а код программы определяет то, как она переходит от одного состояния к другому. Разработчики, использующие императивные языки программирования, такие как Java, зачастую акцентируют больше внимания на самом процессе (коде), чем состояниях. Однако понимание того, что программа является серией состояний, очень важно, поскольку они существенно ближе к тому, что должна делать программа, а не как.
Отладка
Отладка — это мысленная реконструкция переходов состояний. Разработчики проигрывают в уме сценарий программы: как она принимает вводные данные, проходит через ряд изменений состояний и осуществляет вывод, а затем определяют, что пошло не так. Во время разработки этот мыслительный процесс подкрепляется использованием отладчика. Однако в продакшене делать это уже гораздо сложнее, поэтому на данном этапе чаще прибегают к помощи логов.
Понимая суть процесса отладки, мы с легкостью ответим на этот вопрос:
Логи должны содержать информацию, необходимую для реконструкции переходов состояний.
Невозможно, да и не нужно, фиксировать все состояния во все отрезки времени. Например, полиции достаточно лишь нескольких точных набросков, а не видеоклона, для поимки преступника. Тоже самое относится и к логам: разработчикам нужно только внести в них информацию о том, когда происходит переход в критическое состояние. Кроме того, логи должны содержать ключевые характеристики текущего состояния и причину перехода.
Переход в критическое состояние
Не все переходы состояний стоит записывать в лог. Важно рассмотреть программу как серию изменяемых состояний, разделить их на фазы и затем сосредоточиться на времени, когда выполнение переходит от одной фазы к другой.
Предположим, что существуют 3 фазы запуска приложения:
Было бы очень разумно вести логи в начале и конце каждой фазы. Если бы произошла ошибка на этапе подключения к зависимостям и приложение бы зависло, то логи отчетливо показали бы, что после загрузки настроек оно вошло во вторую фазу процесса, не завершив его. Располагая этой информацией, разработчики смогли бы быстро определить проблему.
Ключевые характеристики
Логирование состояний напоминает создание эскизов программы только с учетом ключевых характеристик основ бизнес-логики. Если есть информация закрытого характера, например персональные данные, то ее также нужно записать в лог, но в завуалированном виде.
Например, когда HTTP-сервер переходит из состояния ожидания запроса в состояние получения запроса, он должен зафиксировать в логе HTTP-метод и URL, так как они описывают основы HTTP-запроса. Остальные его элементы (заголовки или часть тела сообщения) записываются в том случае, если их значения влияют на бизнес-логику. Например, если поведение сервера сильно отличается между состояниями Content-Type:application/json и Content-Type:multipart/form-data, заголовок следует записать.
Причина перехода состояния
Логирование причины перехода состояния чрезвычайно полезно для отладки. Логи должны кратко охватывать содержание предыдущих и следующих состояний, а также объяснять их причины. Они помогают разработчикам получить общую картину и ориентироваться в процессе реконструкции (отладки) выполнения программы.
Пример
Рассмотрим простой пример для обобщения всего сказанного. Предположим, что сервер получает некорректный номер социального страхования, и разработчик намерен внести в лог информацию об этом событии.
Вот несколько анти-шаблонов логов, в которых отсутствуют ключевые характеристики состояния и причины:
Все они содержат определенную информацию, но ее недостаточно для ответов на вопросы, которые могут возникнуть у разработчиков в процессе поиска ошибки. Какой запрос не смог обработать сервер? Почему номер социального страхования был отклонен? Какой пользователь столкнулся с этой ситуацией? Грамотный и полезный для отладки лог будет выглядеть так:
[2020–04–20T03:36:57+00:00] server.go: Received a SSN request(track id: “e4a49a27–1063–4ab3–9075-cf5faec22a16”) from user uuid “123e4567-e89b-12d3-a456–426655440000”(previous state), rejecting it(next state) because the server is expecting SSN format AAA-GG-SSSS but got **-***(why)
([2020–04–20T03:36:57+00:00] server.go: Получен запрос номера социального страхования (трек id: “e4a49a27–1063–4ab3–9075-cf5faec22a16”) от пользователя user uuid “123e4567-e89b-12d3-a456–426655440000” (предыдущее состояние), запрос отклонен (следующее состояние), так как сервер требует номер социального страхования в формате AAA-GG-SSSS, а получил **-*** (причина)
Кто должен записывать логи?
Типичная ошибка, которую многие допускают, связана с тем, “кто” должен фиксировать информацию. Ведение логов не теми функциями оборачивается дублированием или дефицитом информации.
Программа как уровни абстракции
Большинство грамотно созданных программ подобны пирамиде с уровнями абстракции. Классы/функции верхних уровней разбивают сложную задачу на подзадачи, тогда как классы/функции нижних уровней абстрагируют реализацию подзадач, таких как черные ящики, и предоставляют интерфейсы для вызова верхним уровнем. Эта парадигма облегчает программирование, поскольку каждый уровень сосредоточен на своей логике, не беспокоясь о всевозможных деталях.
Например, веб-сайт может состоять из следующих уровней: бизнес-логика, HTTP и TCP/IP. Реагируя на URL-запрос, уровень бизнес-логики решает, какую веб-страницу показать, и отправляет ее контент на уровень HTTP, где он превращается в HTTP-ответ. Следующий уровень TCP/IP преобразует HTTP-ответ в пакеты TCP и рассылает их.
Ведите логи только на правильных уровнях
Как следствие абстракции, разные уровни имеют разные степени понимания выполняемой задачи. В предыдущем примере уровень HTTP не владел данными ни о количестве отправляемых пакетов TCP, ни о намерении пользователей в момент URL-запроса. Предпринимая попытку логирования, разработчикам следует выбрать правильный уровень, который содержит полную информацию о переходах состояний и причинах.
Вернемся к нашему примеру проверки корректности номера социального страхования. Допустим, что логика его проверки обернута в класс Validator следующим образом:
Есть еще другая функция, которая проверяет запрос, обновляющий информацию о пользователе, и вызывает проверку номера социального страхования.
Однако это вовсе не означает, что логирование на нижних уровнях программы совершенно необязательно, особенно когда они не раскрывают ошибки верхним уровням. Например, сетевой уровень может иметь встроенную логику повторных попыток, из чего следует, что верхние уровни не замечают проблем с прерывающимися соединениями. В общем, нижние уровни могут вести логи больше на уровне DEBUG, чем на INFO, в целях сокращения многословности. При необходимости разработчики могут настроить уровень лога для получения большего количества деталей.
Сколько должно быть логов?
Существует очевидное соотношение между объемом логов и их полезностью. Чем более содержательные логи, тем легче реконструировать переходы состояний. Вы можете воспользоваться двумя способами контроля количества логов:
Установите соотношение между логами и рабочей нагрузкой
Для контроля объема логов сначала важно его правильно измерить. Большинство программ имеют 2 типа рабочей нагрузки:
В большинстве случаев процесс логирования запускается рабочей нагрузкой: чем больше ее у программы, тем больше логов она записывает. Могут быть и другие логи, не связанные с рабочей нагрузкой, но они становятся малозначимыми, когда программа начинает работу. Разработчики должны сохранять соотношение # логов и # рабочих элементов линейным. Иначе говоря:
# логов = X * # рабочих элементов+ константы
где X можно определить, изучив код. Разработчики должны иметь хорошее представление об X-факторах для своих программ и приводить их в соответствие с возможностями логирования и бюджетом. Вот еще несколько типичных случаев X:
Используйте уровни логов
Что, если X все еще слишком большой даже после оптимизации? На помощь приходят уровни логов. Если X намного больше, чем 1, то можно поместить логи на уровень DEBUG, тем самым снизив X уровня INFO. В процессе устранения неполадок программа может временно выполняться на этом уровне для предоставления дополнительной информации.
Краткие выводы
Чтобы профессионально писать логи, следует рассматривать программу как серию переходов состояний с уровнями абстракции. Владея теоретическими знаниями, можно ответить на ключевые вопросы о логировании в приложении:
1.Когда писать логи? В момент перехода в критическое состояние.
2.Что записывать в лог? Ключевыехарактеристики текущего состояния и причину перехода состояния.
3.Кто должен записывать логи? Логирование должно происходить на правильном уровне, содержащем достаточно информации.
4.Каким должно быть количество логов? Определите X-фактор (по формуле # логов = X * # рабочих элементов+ константы) и настройте его экономно, но выгодно.
Логирование. NLog Platform. Зачем нужны логи в приложении
Здесь мы затронем тему логирования в нашем приложении, что такое логи, и как правильно вести логи, насколько это необходимо и полезно. Рассмотрим систему логирования NLog Platform.
Ведение логов помогает разработчику в процессе создания и последующего сопровождения приложения, при поиске ошибок в коде и в разрешении непонятных ситуаций, когда наше приложение в момент работы ведет себя странным образом, и нам нужно найти причину такого поведения.
Любой разработчик сталкивается с подобными ситуациями, когда какой-то компонент приложения отрабатывает странным образом, выдает не тот результат или вообще перестает работать. Использование логов поможет нам в подобных ситуациях. Время поиска проблемных мест в нашем коде сократится в разы, и мы быстрее сможем решить ту или иную проблему.
Вообще, на сегодняшний момент ни одно более или менее серьезное приложение не обходится без написания логов.
Под таким журналом можно понимать и записи в обычный текстовый файл, и записи в базу данных, и записи на удаленный веб-сервис, и даже email-письма на определенный адрес о тех или иных состояниях нашего приложения.
Какие записи делать в этот журнал, то есть, какую конкретно информацию записывать, определяет сам разработчик. Это могут быть сведения о том, что все работает в штатном режиме, то есть просто ежедневный мониторинг нашего приложения, или что произошла какая-то ошибка, на которую нужно максимально срочно отреагировать и устранить, и так далее.
Всего существует шесть уровней логирования, каждый из которых предназначен для сообщений того или иного типа, той или иной важности:
Trace – максимально детальная информация о том, что происходит с целевым участком кода, по шагам. Например: Попытка открыть подключение к БД, успешно\неуспешно. Сколько времени заняла эта операция. Сколько времени выполнялась выборка из БД, успешно\неуспешно. Сколько записей извлечено. Какая была нагрузка на систему, сколько использовано памяти. Сколько записей прошло нужную фильтрацию. Сколько записей оказалось в результирующей выборке, куда эти записи отправились дальше. Проверка нужных значений в каждой записи.
Debug – это информация для отладки. Логирование крупных операций, менее детально, чем в Trace. Здесь мы не так подробно описываем весь процесс операции, но, тем не менее, заносим в журнал основные операции. Например: Совершено обращение к БД. Из базы выбрано N записей. Записи успешно обработаны и отправлены клиенту.
Info – это более общие информационные сообщения о текущей работе приложения, что происходит с системой в процессе ее использования. Например: Была выгрузка студентов в Excel-файл. На сайте зарегистрирован новый студент. Студент добавил новый отчет. Студент перемещен в другую группу.
Warn – сообщения о странной или подозрительной работе приложения. Это еще не серьезная ошибка, но следует обратить внимание на такое поведение системы. Например: Добавлен студент с возрастом 2 года. Студент получил отрицательный балл. Преподаватель завершил курс, в котором училось 0 студентов. В группе находится больше студентов, чем максимально возможно.
Error – сообщения об ошибках в приложении. Подобные сообщения – это уже большая проблема, которую нужно решить для дальнейшей правильной работы системы. Например: Ошибка сохранения нового студента в БД. Невозможно загрузить студентов в данной группе. Ошибка при входе в личный кабинет студента.
Fatal – сообщения об очень серьезных ошибках в системе. Чаще всего это связано с работоспособностью всего приложения или его окружения на сервере. На такие сообщения следует реагировать МАКСИМАЛЬНО оперативно. Например: Приложение постоянно перезагружается из-за нехватки памяти или места на жестком диске. Приложение завершило работу по неизвестной причине. Нет доступа к базе данных. Нет доступа к сети. Заблокирован какой-то порт.
То есть, прежде чем отправить какое-то сообщение в лог, нам нужно отнести его к той или иной группе.
Например, мы написали новый функционал и хотим его протестировать, как правильно и быстро он работает. Для этого мы будем использовать тип сообщений Trace, то есть все наши сообщения в логе будут помечены как Trace.
Подобным образом мы можем описать, как работает наше приложение в целом, сообщения будут с пометкой Info.
Если же в опасных участках кода мы генерируем исключение, то теперь мы также добавим запись в лог с пометкой Error.
К какой группе отнести то или иное сообщение решает сам разработчик. К данному вопросу следует подойти с максимальной серьезностью. Очевидно, что ошибки не следует помечать как Info, не следует игнорировать ошибки и просто не записывать их в лог. От правильно настроенной системы логирования будет зависеть простота сопровождения всей системы, оперативность реагирования на ошибки и время, затраченное на устранение проблемы.
Иногда разработчики ленятся писать логи, не хотят тратить на это время. В дальнейшем оказывается, что время, затраченное на поиск и исправление ошибок, в разы больше времени, которое потребовалось бы на создание системы логов.
Естественно, многое зависит от сложности проекта. Если вы создаете простейший трехстраничный сайт-визитку или консольное приложение для собственных нужд у себя на локальном компьютере, то написание сложной системы логирования может быть дольше, чем создание самого проекта. В таком случае в логи можно записывать только сообщения об ошибках или почему упал сайт. Но если вы работаете над сложным проектом в команде с другими разработчиками, то грамотное ведение логов просто обязательно.
Для того, чтобы начать логирование, мы подключим в наш проект платформу NLog. Это можно легко сделать посредством менеджера NuGet (прямо из Visual Studio).
Обратите внимание на конфигурационный файл NLog.config. В этом файле находятся настройки логгера (куда будут выводиться логи, формат записи логов и т.д.). Давайте настроим файл следующим образом:
Далее уже в коде объявим новый логгер (здесь код проекта приводится в сокращенном виде, исходный код всего проекта можно скачать в конце статьи):
Чаще всего следует объявлять один статичный логгер в пределах всего класса. Здесь мы посредством класса-менеджера LogManager объявили новый логгер, с которым будем работать.
Начнем логирование с уровня Trace. В методе, где мы выбираем студента по его идентификатору, давайте максимально подробно опишем как это происходит:
Теперь давайте добавим несколько сообщений уровня Debug. Как мы помним, это тоже отладочная информация, но менее детальная. Данный подход мы используем в другом методе, для наглядности:
Идем далее. На уровне Info мы описываем регулярные операции в нашем приложении, то есть поднимаемся еще на уровень выше. Предположим, что мы работаем над ASP.NET MVC приложением, и у нас есть действие в контроллере, которое обращается к ранее описанному методу GetStudentById():
Теперь добавим в логи сообщения уровня Warn. Как мы помним, на этом уровне логирования мы описываем все потенциально опасные ситуации, странное и нелогичное поведение компонентов. Будем заносить в лог запись, если студенту меньше 15 лет:
Далее обработаем ошибку в нашем коде и запишем в лог сообщение уровня Error:
Теперь определим, что же нам записать на уровне Fatal. В нашем простейшем примере просто смоделируем подобную ситуацию:
Мы рассмотрели все шесть уровней логирования и описали процесс работы нашего приложения максимально подробно. Теперь мы можем сразу проанализировать работу сайта, просто изучив логи, и не заглядывать в исходный код.
Подобным образом происходит логирование. В нашем простейшем примере, где мы моделируем работу со студентами, все предельно ясно и прозрачно даже без логов. Но в сложных проектах ведение логов является неотъемлемой частью разработки.
Конечно, это далеко не полные возможности настройки платформы NLog. В конфигурационном файле можно настроить запись логов в другие места, например, в базу данных, на консоль, в оперативную память, отправлять как емаил-сообщение, отправлять сообщения по сети и так далее. Также можно настроить фильтрацию сообщений, более сложный шаблон сообщений. Если вас не устраивает стандартный функционал логгера, то можно написать свое собственное расширение и подключить.
На этом здесь все, давайте подведем небольшой итог. Мы изучили тему логирования в приложении. Посмотрели как правильно логировать те или иные участки кода, а также познакомились с одной из самых популярных платформ логирования – это NLog Platform, также рассмотрели ее возможности и как можно настроить генерацию логов на этой платформе.