Как мы работаем с логами (сбор логов с сервера, возможность визуализации данных при помощи Graylog) / Хабр

При начале работ, исходить из метрик, или из инфраструктуры?

Соблюдайте баланс. Тезис, высказанный ранее, ответу на вопрос не противоречит:

… такие метрики относятся к самому низкому доступному вам уровню инфраструктуры, с которой вы работаете

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

Основы грамотного логирования

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

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

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

Что и как логировать

Следует придерживаться правил:

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

Elasticsearch, logstash и kibana

Логи всех информационных систем, подключенных к услуге Managed IT, хранятся в распределенном хранилище на базе решения ELK (Elasticsearch, Logstash и Kibana). Механизм сбора логов выглядит так: Logstash собирает логи и переносит их в хранилище, Elasticsearch помогает найти нужные строки в этих логах, а Kibana визуализирует их. Все три компонента разработаны на основе открытого кода, благодаря чему их можно модифицировать под потребности компании.

• Logstash — приложение для работы с большими объемами данных, собирает информацию из разных источников и переводит ее в удобный формат.
• Elasticsearch — система для поиска информации. Помогает быстро найти нужные строки в файлах хранения.
• Kibana — плагин визуализации данных и аналитики в Elasticsearch. Помогает обрабатывать информацию, находить в ней закономерности и слабые места.

Graylog sidecar

Graylog может собирать также логи сервисов, и вообще практически любые логи.

Будем использовать Graylog Sidecar для управления конфигурацией и бэкенд Filebeat, который собирает события и отправляет на Graylog-сервер. Схема работы для данного кейса:

Картинка отсюда.

Мы будем работать с access-логами веб-сервера nginx, работающего под CentOS linux.

Получаем токен

System  →  Sidecars:

Нажимаем на ссылку:

Nlog, log4net, enterprise library, smartinspect…

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

Поэтому, буду пока дружить с NLog.Чего и Вам желаю.

Бизнес-мониторинг и мониторинг бизнес-процессов

Давайте разделять эти понятия.

Мониторинг бизнес-процессов – зона ответственности «инженерного» мониторинга, о который мы с вами обсуждаем (наверное, стоило это сразу обозначить…). Задача здесь – обеспечить контроль за работоспособностью функций.

Бизнес-мониторинг и бизнес-метрики – это совершенно иная кухня, в ней шеф-повара это ваш СЕО и его окружение. Тут обеспечивается контроль за прибылью от функций вашей системы, а главный инструмент – BI-системы.

В своих статьях я не планирую затрагивать второй вид в силу отсутствия компетенций и релевантного опыта.

Теперь можем двигаться дальше.

Боевое развертывание

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

Остановлюсь только на смысловой организации файлов. Их следует разделить на 3 группы. Может потребуется развести логи модулей в разные файлы, но дальше я все равно буду говорить об одном файле для каждой группы.

1. Группа Info, с соответствующим уровнем для всех источников. Это информация для администратора. Здесь могут быть следующие вещи: когда приложение стартовало, правильно ли вычитаны конфиги, доступны ли требуемые сервисы, и т.д. Его основное свойство: файл изменяет размер только при перезагрузке приложения. В процессе работы, файл расти не должен. Это поможет обеспечить автоматизированный внешний контроль успешности запуска приложения. Достаточно проверить отсутствие в файле ключевых слов Error и Fatal. Проверка всегда будет занимать предсказуемо малое время.
2. Группа Warning. Это тоже информация для администратора. Этот файл при нормальной работе должен отсутствовать или быть пустым. Соответственно мониторинг его состояния сразу укажет на сбои в работе. Гибко настроив фильтры по разным источникам, можно подобрать достаточно точный критерий, когда вообще следует обратить внимание на сервис.
3. Группа Наблюдение. Как правило в ходе внедрения выделяются некоторые проблемные модули. Информация от них в детализации Debug как раз и направляется сюда.

Если приложение успешно внедрено, то в работе остаются только первые две группы.

Гарантии сохранности лога

Несмотря на некоторые возможности NLog по авто записи логов, нет гарантии сохранности лога при завершении процесса.

Что интересно, попытка завершить запись обработкой события AppDomain.ProcessExit не совсем корректна. В конфигурации может быть настроено много разных способов записи в лог, в том числе и по сети. А обработчик этого события находится в ограниченном окружении. В .

Первое, что следует сделать, это обработать событие AppDomain.UnhandledException. В нем следует записать в лог полную информацию об ошибке и вызвать LogManager.Flush(). Обработчик этого события использует тот же поток, который и вызвал исключение, а по окончании, немедленно выгружает приложение.private static readonly Logger Log = LogManager.

GetCurrentClassLogger();<br/><br/>public static void Main(string[] args)<br/>{<br/>AppDomain.

CurrentDomain.UnhandledException  = OnUnhandledException;<br/>(…)<br/>LogManager.Flush();<br/>}<br/><br/>static void OnUnhandledException(object sender, UnhandledExceptionEventArgs e)<br/>{<br/>Log.

Fatal(“Unhandled exception: {0}”, e.ExceptionObject);<br/>LogManager.Flush();<br/>}

Кроме того, следует вызывать LogManager.Flush() везде, где потенциально возможно завершение процесса. В конце всех не фоновых потоков.

Если ваше приложение представляет собой win-service или Asp.Net, то следует обработать соответствующие события начала и завершения кода.

Зачем нужно логирование

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

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

Логи стоит записывать в процессе работы каждого компонента IT-инфраструктуры. Выгоду от его использования получит каждый специалист:

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

Контроль над приложением необходимо будет продолжить даже после того, как оно пойдет в работу. Это позволит постоянно быть в курсе происходящего, мгновенно реагировать на чрезвычайные происшествия. То есть анализ логов – это одна из обязанностей в работе ИТ-специалистов.

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

Зачем оно вообще нужно, это логирование?

На анализе логов базируется работа большинства ИТ-специалистов. Администраторы  ищут в файлах логирования причины сбоя сервиса. Разработчики опираются на логи, чтобы локализовать и устранить ошибки приложения или веб-сайта. Служба безопасности по логам, как по физическим уликам, определяет вид взлома, оценивает нанесенный ущерб и даже может идентифицировать взломщика.

Файлы логирования

Знакомимся с типами логов

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

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

Дополнительно предусмотрена классификация логов по степени их важности. Так, к группе Fatal/critical error будут относиться те, которые требуют как можно более быстрого выполнения. Ошибки, которые не будут влиять на работу пользователей стоит записывать в группу Not critical error.

Знакомимся с уровнями логирования

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

• Debug. Здесь будут записывать масштабными переходы состояний. Речь идет об обращении к базам данных, запуск и остановка сервиса, подтверждение успешной обработки информации.
• Warning. В этой папке будет находиться все то, что относится к внештатной ситуации, проблемах, требующих внимания. Корявые запросы, некорректные вызовы – все эти логи можно будет найти здесь.
• Error. Этот уровень предполагает сбор типичных ошибок.
• Fatal. Искать проблему серьезных сбоев в работе необходимо в этой папке. Логи, хранящиеся в ней, помогут найти проблему отказа в доступе к базе данных, отсутствии свободного места на жестком диске и пр.
• Trace. Предполагает пошаговую запись происходящих процессов. Сюда стоит заглянуть в том случае, если возникнут сложности с локализацией проблемы.
• Info. Общеознакомительный файл, содержащий информацию о работе сервиса, службы.

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

Инженерный мониторинг не отражает реальное положение дел

Здесь @Dr_Wut приводит такой пример:

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

Если у вас возникла такая ситуация, значит, вам стоит добавить смок-тест функции, ведь результат такого теста – это тоже метрика, о чем я говорю в разделе о их разновидностях.

Какая информация хранится в логах и как ее интерпретировать?

Для большинства пользователей содержимое log-файлов это бессмысленный набор символов. Как читать логи, чтобы понять, что в них зашифровано?Строка access.log сервера содержит:

• адрес ресурса;
• IP-адрес пользователя;
• дата и время посещения, часовой пояс;
• GET/POST – запрос на получение или отправку данных;
• к какой странице обращались;
• протокол пользователя (как зашел на ресурс);
• код отклика сервера;
• число переданных байтов;
• информация о посетителе (боте) – устройство, ОС, другие данные.

Как правило, такой информации достаточно, чтобы проанализировать ситуацию и сделать нужные выводы. Например, заблокировать бота, который создал чрезмерную нагрузку на сайт.Файл ошибок (error.log) регистрирует моменты, когда что-то пошло не так. Из них можно узнать:

• когда произошла ошибка (дата, время), ее тип и IP-адрес пользователя;
• тип события;
• где находится сам файл и строка с сообщением

Конечно, даже после расшифровки, данных логов еще нужно проанализировать. Для этого существует различное ПО, которое помогает отрабатывать данные из логов – Weblog Expert, WebAlyzer, Analog, Webtrends, Awstats, SpyLOG Flexolyzer и другие платные и бесплатные программы.

Настраиваем оповещения

Для примера – отловим приход oom-killer-а c уведомлением в Slack:

Alerts  →  Alerts & Events  →  Get Started!

Шаг 1: “Event Details”:

Title: oom-killer invoked

Description (Optional):  oom-killer was invoked on server or virtual machine

Priority: Normal

Шаг 2: “Filter & Aggregation”:

Condition Type:  Filter & Aggregation

Search Query: “oom-killer”

(Тут правила построения запроса)

Streams (Optional):  All messages

Search within the last:  10 minutes

Execute search every:  10 minutes

Устанавливаем чекбокс Enable

Create Events for Definition if…   Filter has results

Если в логах уже есть такое событие, можно будет наблюдать его в Filter preview.

Шаг 3: “Fields” – не используем.

Шаг 4: “Notifications”  →  Add Notification:

Choose Notification:  Create New Notification…

Title: Slack notification

Notification Type: Slack Notification

Configuration Color:  можно выбрать цвет

Настраиваем сбор логов с сервера

Работаем в web-интерфейсе:

Начнем со сбора syslog

Создаём UDP Input для системных логов:

System/Overview → Inputs

Выбираем тип Input-а:

Select input → Syslog UDP

(Будем использовать UDP, но если кому-то удобнее использовать tcp – почему бы и да)

Нажимаем кнопку Launch new input.

Title:        SyslogUDP 
Bind address: 0.0.0.0
Port:         10514

Немного бесполезного, но красивого

На этапе установки, в первой части статьи мы прикрутили к graylog-у базу geoip. 

Теперь посмотрим, как её использовать, а также выведем карту мира, визуально демонстрирующую, откуда к нам на сайт приходят посетители.

Создаём data adapter

System  →  Lookup Tables  →  кнопка Data Adapters  →  Create data adapter:

Data adapter type  →  Geo IP – MaxMindTM Databases

Title:  GeoIP

Description:   GeoIP Lookup Table

Name:  geoip

File Path:   /etc/graylog/server/GeoLite2-City.mmdb

Database type:  City database

Остальное по умолчанию.

Для завершения нажимаем кнопку Create adapter.

Когда результаты кешируются – всё становится лучше

Создаём Caches:

System  →  Lookup Tables  →  кнопка Caches  →  кнопка Create cache

Cache Type:  Node-local, in-memory cache

Title:  GeoIP

Description:  GeoIP Cache

Name:  geoip

Остальное можно оставить по умолчанию.

Нажимаем кнопку Create Cache:

Создаём Lookup table:

System  →  Lookup Tables  →  Lookup Tables (активна по умолчанию)  →  Create Lookup Table

Title: GeoIP

Description:  GeoIP Lookup

Name: geoip

Data Adapter:  GeoIP (geoip)

Cache:  GeoIP (geoip)

Нажимаем кнопку Create Lookup Table:

Создаём Pipeline (пайплайны позволяют обрабатывать сообщения из потоков):

Сначала правило:

System  →  Pipelines  →  кнопка Manage rules  →  кнопка Create Rule

Description: Incoming connections

Rule source:

rule "GeoIP lookup: remote_addr"
when
  has_field("remote_addr")
then
  let geo = lookup("geoip", to_string($message.remote_addr));
  set_field("remote_addr_geo_location", geo["coordinates"]);
  set_field("remote_addr_geo_country", geo["country"].iso_code);
  set_field("remote_addr_geo_city", geo["city"].names.en);
end

Нажимаем кнопку Save&Close.

Теперь пайплайн:

System  →  Pipelines  →  кнопка Manage pipelines  →  кнопка Add new pipeline

Title:  Web

Description:  Incoming connections

Наблюдаем сообщение, что только что созданный пайплайн не подключен ни к одному потоку: 

Нажимаем кнопку Edit connections, подключаем:

А также в Stage 0 нажимаем Edit и добавляем к нему правило:

Идём в Streams  →  Sidecars, смотрим новые сообщения…

Проблема – ничего не происходит. Никаких гео-тегов не видно.

Проблема возникает из-за порядка обработки правил.

Идём в System  →  Configurations

По умолчанию так:

1    AWS Instance Name Lookup

2    GeoIP Resolver

3    Pipeline Processor

4    Message Filter Chain

А нам нужно так:

1    AWS Instance Name Lookup

2    GeoIP Resolver

3    Message Filter Chain

4    Pipeline Processor

Нажимаем кнопку Update, перетаскиванием располагаем правила в правильном порядке:

Снова идём в Streams  →  Sidecars, смотрим новые сообщения и видим в них искомые геоданные:

Теперь будем смотреть красивую карту:

В Streams  →  Sidecars  добавляем Aggregation:

Нажимаем Edit:

Visualization type: World Map

Rows: remote_addr_geo_location

Сохраняем:  Save

Теперь можно визуально оценить откуда к нам на сайт приходят посетители:

О алертинге

Основные тезисы были высказаны в предыдущей статье, тут ограничусь парой предложений:

О логах доступа

Как я писал выше, с этим типом журналов всё интереснее. Во-первых, эти логи, при наличии информации о затраченных на обработку запросов ресурсах, внезапно, превращаются… в метрики!

О логах как источнике дополнительной информации

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

Однако же, для многих становится откровением то, что логи бывают нескольких типов. Вот два самых распространенных:

Лог работы приложения – именно о нем думают в первую очередь; полагаю, вам знакома такая конструкция:

2022-04-23 00:39:10,092  INFO  DatabaseConnector – Connection estabilished

Вот это и есть запись из журнала работы. Характерные атрибуты такой записи – идентификатор уровня события и сообщение о событии. Часто также появляются имя класса/библиотеки, вызвавшей логгер, и идентификатор потока, в котором была сформирована эта запись.

Лог доступа к приложению – тут уже интереснее; это информация о том, какие функции приложения запрашивались. В подавляющем большинстве случаев это будут журналы обращения к API. Вот так, например, может выглядеть запись обращения к Nginx:

О логах приложения

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

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

2022-04-27 00:39:10,092  ERROR  DatabaseConnector – Error connecting to database MSSQLDB – connection refused on port 1433

И сразу понятно – у нас порт недоступен.

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

О сборе логов

Видов взаимодействий тут снова два, прямо как с метриками – Pull и Push.

Pull – это когда приложение ведет свой журнал (в файле, в табличке в БД, в журнале операционной системы), а агент журналирования этот журнал читает, обогащает метаданными о приложении/хосте/чем-то ещё и отправляет на дальнейший парсинг и индексацию.

Push – приложение активно отправляет свой журнал в систему парсинга/брокер сообщений/напрямую в базу. В таком случае агент не нужен, но приложение должно знать, где находится точка для сброса логов.

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

О связности с метриками

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

1. Уровень площадки

2. Уровень группы

3. Уровень объекта

4. Уровень фрагмента объекта

5. Уровень инфраструктуры

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

Принцип тот же самый:

1. На первом уровне к логике панели-индикатора добавляется блок, связанный с подсчетом количества событий уровня ERROR и выше

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

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

Тогда диаграмма из предыдущей статьи приобретает такой вид:

О структуризации

Приложение может вести логи в разных форматах – plain text, jsonl, logsft, тысячи их. Здесь ключевая задача – привести их к единому виду, и тут рекомендую начинать с определения контрактов событий.

Контракт – соглашение о том, какой минимальный набор полей должны иметь те или иные типы логов после парсинга.

Можно выделить сначала общий контракт:

@timestamp<time>:    Штамп времени события
application<string>: Имя приложения, к которому относится событие; должно соотноситься с таковым в мониторинге
host<string>:        Имя хоста, на котором расположено приложение
log_type<string>:    Тип события; application|access|.... (если приложение пишет не только application логи)
trace_id<string>:    Идентификатор трассировки (при наличии)

А затем определять контракты для других типов.

Например, для журналов приложений:

message<string>:         Значимая часть события
generic_message<string>: Обезличенная значимая часть события
level<string>:           Текстовая репрезентация уровня события
level_value<int>:        Численная репрезентация уровня события
logger_name<string>:     Имя класса, сгенерировавшего событие (при наличии)
thread_name<string>:     Идентификатор потока, сгенерировавшего событие (при наличии)
stack_trace<string>:     Трассировка стека; в более общем виде - вторая и последующие строки сообщения (при наличии)

И для журналов доступа:

status_code<int>:           Код ответа по запросу
elapsed_time<int>:          Время, затраченное на обработку запроса в миллисекундах
requested_resource<string>: Запрошенный ресурс
method<string>:             Метод запроса

Здесь очень важно соблюдать установленные контракты при передаче логов на дальнейшие индексацию и хранение.

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

Следование контракту приносит пользу сразу с нескольких сторон:

Только не пользуйтесь, пожалуйста, уровнем «EMERGENCY», если не уверены, что абсолютно каждый, кому предстоит работать с структурированными журналами, точно знает, что он обозначает. Я встречал очень мало таких людей, поэтому вместо него использую «FATAL» – достаточно говорящее обозначение для всех.

Обезличенные сообщения

Внимательные читатели могли заметить, что в контракте журналов приложений есть поле «generic_message». Рассказываю.

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

Дженерик – это значимая часть события, приведенная к обезличенному шаблону. Вот пример:

Пусть исходное сообщение у нас такое:

Error on AMQP connection <0.12956.79> (127.0.0.1:52879 -> 127.0.0.1:5672, state: starting):

Из него часть информации можно заменить на маркеры, тогда получается дженерик:

Error on AMQP connection <{connection_id}> ({remote_host} -> {destination_host}, state: {connection_state}):

Извлекаемые значения при этом записываются в соответствующие поля события с становятся доступны для поиска.

Но что это дает? А вот что:

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

Под капотом nlog

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

Часто, при разработке кода, возникает необходимость посмотреть значение какой либо переменной в процессе выполнения. Обычно, используют дебаггер и останавливают программу в интересующем месте. Для меня же, это явный признак, что этом месте будет полезен Trace вывод.

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

В NLog используются следующие приемы:

Исходный код класса можно посмотреть тут.

Отлично! Для NLog можно быть уверенным, что ваши сколь угодно детальные сообщения могут быть отключены и это минимально скажется на производительности. Но, это не повод посвящать логированию половину кода.

Проблемы, с которыми сталкиваются реальные приложения

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

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

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

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

Продумать уровни тревоги

Абсолютно верная мысль @sizziff которую я недостаточно раскрыл.

Если вы заводите уровень «катастрофа» и отправляете нотификацию по СМС, это должно быть оправдано на 150%, иначе, рано или поздно, ваша команда поддержки будет выглядеть так:

Разбор полетов

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

Расследование сбоев

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

Как раз это и должен позволять делать приличный логгер. Когда мы получили подтверждение о том, что новая конфигурация успешно применена, то пытаемся опять спровоцировать сбой. Желательно несколько раз. Это обеспечит возможность для его воспроизведения в «лабораторных» условиях. Дальше уже работа программистов. А пока можно и перезагрузиться.

Сколько логировать

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

Собирать всё или только минимальный объем?

Здесь моя позиция такова – собирать надо все метрики, которые объект способен отдавать. Как заметил @BugM они лежат в БД, есть не просят, никому не мешают. А вот если у вас их нет, но они вдруг понадобились, особенно за, допустим, прошлый месяц – тут ничего сделать не получится.

Перефразируя знаменитую пословицу о бэкапах: «люди делятся на два типа – на тех, кто еще не собирает метрики, и тех, кто уже собирает».

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

Типы логов и где их найти

Месторасположение логов зависит от используемого ПО, настроек, прописанного админом пути. Чаще всего server logs сохраняются в var/log/. Однако, не все сервисы помещают файлы регистрации в эту директорию. В любом случае, можно уточнить такую информацию у веб-хостера.У дистрибутивов Linux CentOS или Fedora логи серверной машины лежат в /var/log/. Там можно найти:

• файл регистрации ошибок error.log;
• данные о доступах log;
• основной системный журнал syslog;
• файл загрузки ОС dmesg;
• журнал nginx.

Лог ошибок MySQL ($hostname.err) хранится в /var/lib/mysql/. Для Debian или Ubuntu местоположение логов аналогично, за исключением log file ошибок MySQL: /mysql/error.log. А также – логи веб сервера Apache сохраняются по пути /var/log/apache2.У ОС Windows дружной метод структурирования log-файлов. События делятся на несколько уровней:

• предупреждение – Warning;
• подробности (System и EventData);
• ошибка – Error;
• сведения – Information;
• критический – Critical.

Их можно отсортировать или отфильтровать и выбрать необходимое.

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

Трассировки

Еще на логах можно строить трассировки. Работает это примерно так:

1. Входная точка в вашей DMZ устанавливает идентификатор трассировки (trace ID) на запрос; должна быть предусмотрена возможность ручной установки!

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

Если такое предусмотрено вашим приложением, trace ID стоит записывать не только в лог доступа, но и в лог работы – так вам будет легче связывать ошибки с конкретными запросами.

Очень обобщенно, это можно представить следующим образом:

Преимущества трассировок сложно переоценить – на их основе можно, как минимум:

Чего же мне еще не хватает в nlog?

• Дополнительные перегрузки методов логгера, для того чтобы избежать генерации классов лямбда-функций. Хочется иметь вызов вида
  Log.Trace<TArg1, TArg2>(Func<TArg1, TArg2, string> messageCreater, TArg1 arg1, TArg2 arg2)
  Но на текущий момент, самый короткий человекочитаемый вариант подразумевает скрытую генерацию класса:
  Log.Trace(() => MessageCreate(arg1, arg2))
• Бинарная совместимость. Помогает быстро тестировать сервисы на разных платформах. В NLog очень много инструкций условной компиляции в зависимости от платформы. Т.е. бинарник для Mono может неожиданно работь в DotNet. А очень желательна предсказуемость, хотя бы и в ограниченной комплектации.
• Условная расширяемость. Понятно, что с бинарной совместимостью придется жертвовать функционалом, но у нас уже есть удобный механизм расширений. Осталось только, чтобы он фильтровал расширения в зависимости от платформы. Вместе с предыдущей возможностью, это еще и дает простое развертывание через копирование директории с IL-бинарниками.
• Логгирование внутренних сообщений в общем контексте. Был бы полезен список создаваемых в системе логгеров. К сожалению, не уверен, что можно избежать рекурсии. Например, когда вывод в файл начнет писать ошибки вывода в себя же.

Чего с логгером делать не следует

Логгер должен быть простым и надежным как молоток. И у него должна быть четко очерчена область применения в конкретном проекте. К сожалению, разработчиков часто трудно удержать. Паттерны проектирования, это в основном полезно, но не этом случае. Достаточно часто стал замечать предложения выделить для логгера обобщенный интерфейс (пример) или реализовать обертку в проекте, чтобы отложить муки выбора NLog vs log4net на потом.

Что бы ни было тому причиной, надо точно помнить, что в первую очередь, такие удобства напрочь убивают компилятору возможность оптимизации.

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

Заключение

Итак, допустимо ли отрывать логи от метрик?

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