Тернистый путь к системе логирования Graylog

KOGDATA.RU — Статья направлена на обзор очень универсальной системы логирования, примеры и практический опыт наводит через призму вселенной .NET / .NET Core. Но верю, что эта информация может помочь всем без исключения, кто ищет системы такого класса.

С чего начинается сбор логов в любом проекте? Из того, что однажды ваш продукт, хорошо и стабильно работает, перестает быть таковым, а ответа на вопрос «почему?» У вас нет. И мы не имеем в виду систему в продакшн-среде: это может быть даже beta-демка, MVP и другие варианты доказательства правильности концепции вашей будущей системы. Вот в такие моменты и появляются логи.
Обычно в виде файлов в директории Log рядом с бинарными файлами вашего продукта. Конечно, опытный программист сразу привлекает удобный и мощный фреймворк для логирования, например log4net, как сделали мы. Теперь всю важную информацию в читабельном и хорошо структурированном виде разложено на уровнях Error, Warn, Info и Debug, и разработчики / администраторы / техническая поддержка системы имеют ответы на все вопросы и могут решить любую проблему.

В нашем случае системой, в которой большое значение имели качественные логи, был веб-сервис, написанный, как вы могли догадаться, на .NET Framework и размещен в IIS на едином сервере. Все логи писали на отдельный диск и были разделены на отдельные файлы в соответствии с подсистем (incoming requests, Web API, engine и outcoming requests). На первое время этого было достаточно, и даже специалисты службы поддержки могли эти файлы читать и находить там ответы в случае возникновения проблем.

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

Сохраните в соц.сети, ок?

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

Появился герой

В один из периодов обсуждения проблемы логов вынырнуло название Graylog, и после нескольких экспериментов с этой системой было решено запустить ее в продакшн-среду. С другими такими системами глубоких сравнений и анализа не проводилось. В то время это была еще версия 1.0, на момент написания статьи в релизе уже версия 3.0. Что сразу подкупило в этой системе:

Простая интеграция с нашим сервисом. Фактически в конфигурационных файлах log4net просто появился новый апендер Gelf4net (по ссылке найдете инструкции по настройке). В самом коде никаких изменений (почти).
Понятный и дружественный веб-интерфейс самого Graylog.
Быстрый поиск по понятным форматом запросов, благодаря Elasticsearch под капотом.
Теперь немного больше деталей.

GELF - собственный формат описания и передачи логов. Но благодаря имеющимся библиотекам вам не придется в нем очень разбираться. Вы можете просто подключить апендер в конфигурационный файл, и все заработает. Но удобно - есть возможность добавлять к вашим логов новые поля для расширения информации и удобства дальнейшего поиска. В вышеупомянутом репозитории GitHub примеры с добавлением additional fields как константами в конфигурационном файле, так и из кода. И это очень важно для дальнейшей эффективности поиска: вместо того, чтобы добавлять название текущего модуля или любую ключевую информацию в текст вашего сообщения, добавьте отдельное поле, которое быстро индексироваться в Elasticsearch.

По протоколу доставки данных в Graylog: в то время мы попытались HttpAppender и UdpAppender. Выбор сделали в пользу второго за гораздо большую скорость передачи. Elasticsearch было развернуто в кластере с 2 нод. Также было 2 Ноды веб-сервиса самого Graylog.

Через некоторое время оказалось, что сервисом невозможно пользоваться: UI постоянно зависает, результаты поиска возвращаются по 5 минут, половина логов просто теряется. Все это происходило из-за того, что:

Мы подключили к Graylog слишком много систем, независимо от географической удаленности серверов.
Кластер Elasticsearch было некорректно настроен, и, как следствие, обе ноды занимались и поиском, и хранением, и приемом логов.

UDP. Это протокол без гарантии доставки, и в момент больших нагрузок мы просто выбрасывали данные в никуда.
Три отдельные проблемы, которые вместе убили в то время дальнейшее использование нами этой системы.

Новая надежда

Так уж случилось, что тогда из-за нехватки времени и ресурсов мы прекратили поиски путей решения выявленных проблем и вернулись к хранению логов в файловой системе. Шаг назад? Да. Но мы существенно пересмотрели информацию, которая логуется, и лишились информационного мусора: что-то совсем перестали логувать, что-то перевели на уровень Debug.
В продакшн-среде в некоторых компонентах логирования перевели только на уровень Error, зная, что другие уровни сообщений там не нужны. Например, для Web API нам нужны логи входящих запросов, чтобы знать, какие данные поступают к сервису, - это уровень Info; а вот для фоновых процессов нашей системы нам не важно знать их промежуточные данные, нужно только знать, когда случаются исключительные ситуации, - это уровень Error.

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

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

Следующим катализатором к восстановлению поиска взрослого системы обработки логов стал .NET Core. Все компоненты нашего сервиса приобрели вид аккуратных контейнеров в Docker под управлением Kubernetes, а правильный сбор и хранение логов стали насущной необходимостью. И снова мы вспомнили о Graylog, конечно, помня первый негативный опыт. Читатели статьи могут поставить логический вопрос: почему не ELK? Для нас Graylog имел следующие преимущества:

Простой дружественный интерфейс, с которым уже знакома служба поддержки.
Возможность создания и разграничения прав пользователей.
Возможность создания и просмотра в UI потоков логов (первоначальное разделение входных логов с фильтрацией + разграничения прав на потоки).
Возможность объединения логов с различных хостов в одну группу.
Простота развертывания: рабочая система из коробки разворачивается несколькими командами. Для нужд dev среды это очень полезно: я, как разработчик, запускаю Graylog в докере тремя командами из официальной документации.
Расширенная документация и активное community.
На тему сравнения Graylog vs. ELK также достаточно подробная статья .

Что мы изменили, имея первый негативный опыт:

Каждый отдельный кластер сервисов, обслуживает определенный регион пользователей, имеет собственный экземпляр Graylog.
Кластер Elasticsearch имеет отдельные ноды для приема, хранения и поиска данных .
Отказ от UDP в пользу AMQP.

Elasticsearch - кластер всему голова

Можно прочитать кучу статей о настройке кластера Elasticsearch, но количество вопросов только увеличится. А можно прочитать best practices с официального сайта и быть абсолютно счастливым. Мы уже упоминали о том, как в первом знакомстве с Graylog у нас был кластер Elasticsearch из двух нод, которые были и master, и data, и ingest, что очень испортило нам настроение. Какую конфигурацию мы теперь (напомню, что мы имеем отдельные кластеры, обслуживающих отдельный географический регион):

Master - две ноды. Мастер координирует работу кластера. Для выбора, кто сейчас самый-самый Мастер Йода, должно быть хотя бы одна доступна нода (параметр minimum_master_nodes = 1). Можно с этим спорить, ведь мы отошли от best practices, но дальше будет объяснение, почему у нас это работает.
Data - две ноды, собственное хранилище данных.
Ingest - две ноды, которые принимают данные, а также обрабатывают входящие запросы поиска.

О том, почему у нас 2 master-ноды. Есть такая опасная вещь, как split brain. Это ситуация, когда, например, minimum_master_nodes = 1 и одна из master-нод теряет сетевой связь с другими master-нодамы, но все еще связана с подчиненными нодамы кластера. Эта нода сама себя выбирает главной, но остается также и старая главная нода - возникает конфликт. Именно поэтому рекомендуют иметь 3 Ноды с кворумом 2 - тогда только две ноды могут выбрать главную. Как уже упоминалось выше, вся микросервисная архитектура у нас развернута под управлением Kubernetes, который пристально следит за наличием и работой всех экземпляров сервисов.
Помогают ему в этом сервисы проб - liveness и readiness. Первый говорит о том, что сервис запущен, второй - о том, что сервис готов к работе. И если вдруг один из этих показателей станет отрицательным для экземпляра сервиса, Kubernetes не даст ему обрабатывать запросы до того, как корректный состояние восстановится. Именно это и позволяет сэкономить на одном экземпляре master-ноды.

AMQP доставляет

Посмотрев на имеющиеся апендеры в библиотеке Gelf4net, мы нашли реализацию для протокола AMQP . То есть, изменив несколько строк в конфигурационных файлах log4net, мы могли отправлять наши логи к брокеру сообщений. А это было для нас удобно, потому что мы уже давно используем RabbitMQ, показавший себя как быстрый и стабильный продукт. Конечно же, в самом Graylog несколькими кликами можно настроить прием сообщений с брокера. Но окончательно мы были довольны, когда начали использовать AsyncGelfAmqpAppender, что, если сравнить с синхронным апендером, дал прирост скорости передачи логов в четыре раза!

Вместе со скоростью передачи данных (просто из коробки RabbitMQ может принимать 20К сообщений в секунду) мы также получили большую надежность:

В момент высокой нагрузки Graylog не страдает и забирает из очереди логи с комфортной для него скоростью. Все это время логи находятся в persistent очереди и уже не исчезнут, даже если этот инстанс брокера перезагрузится.
Если Graylog временно выйдет из строя, логи, опять-таки, останутся в очереди.
Каждый сервис имеет свою очередь логов, поэтому сервисы не мешают друг другу.
Также в брокере мы имеем свою статистику поступления сообщений в удобном интерфейсе.

А вот так выглядит пример пользы от брокеров сообщений, когда умирает Elasticsearch: все логи есть, но они в очереди и через некоторое время будут доступны для операции.

Мониторинг

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

С тех пор у нас появился мониторинг наличия логов, который был настроен средствами самого Graylog. А оповещения поступают в группу Telegram.

Эпилог

Сейчас Graylog стал местом хранения логов всех микросервисных продуктов многих команд R & D в Terrasoft. Начиная новый проект, команда не заморачивается над тем, что делать с логами: есть шаблонные решения и практический опыт, уменьшает количество стресса в нашей жизни. Мы придерживаемся мнения, что каждый удачный эксперимент должно становиться практикой, распространяться и быть частью нашей повседневной жизни.

Подытоживая, можно выделить следующие пункты, описывающие нашу счастливую жизнь:

Все логи сервиса в одном месте с доступом через LDAP
Быстрый и простой поиск: благодаря возможности добавления новых полей для индексирования (сервис, модуль, идентификатор клиента, отдельные теги и т.д.) поиск нужной информации среди 230М сообщений в месяц выполняется за 2 секунды. Добавьте сюда возможности полнотекстового поиска в тексте сообщения, и вы увидите великолепный инструмент для решения проблем вашей системы.
Служба поддержки радуется: web UI гораздо удобнее, чем поиск в NotePad ++ в папке файлов.
Исправили +100 500 исключительных ситуаций, которые раньше не было видно из-за сложности в обращении с логами.
Наличие в системе удобных дашборда, которые показывают активность отдельных модулей, также может натолкнуть на оптимизации и улучшения логирования.

Категория: Новости о онлайн-медиа и IT-корпорациях Ваш IP записан: 3.147.68.201 (07.06.19)