Тернистим шляхом до системи логування Graylog

Цю статтю спрямовано на огляд дуже універсальної системи логування, приклади й практичний досвід наводитимемо через призму всесвіту .NET/.NET Core. Але вірю, що ця інформація може допомогти всім без винятку, хто шукає системи такого класу.

Матеріал написано у співавторстві з Олександром Гілєвим, .NET розробником у Terrasoft

Пролог. Частина лірична й не обов'язкова

Хто входити тут, покинь усю надію.

Данте Аліг'єрі, «Божественна комедія»

З чого починається збір логів у будь-якому проекті? З того, що одного разу ваш продукт, що добре й стабільно працює, перестає таким бути, а відповіді на запитання «чому?» у вас немає. І ми не маємо на увазі систему у продакшн-середовищі: це може бути навіть 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 виняткових ситуацій, які раніше не було видно через складність оперування логами.
Наявність у системі зручних дашбордів, які показують активність окремих модулів, що також може наштовхнути на оптимізації й поліпшення логування.

Опубліковано: 07/06/19 @ 10:20
Розділ Різне

SEO Блог