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