Тернистим шляхом до системи логування 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. Що відразу підкуповувало в цій системі:

Тепер трохи більше деталей.

GELF — власний формат опису й передачі логів. Але завдяки наявним бібліотекам вам не доведеться в ньому дуже розбиратися. Ви можете просто під'єднати апендер до конфігураційного файлу, і все запрацює. Альо що зручно — є можливість додавати до ваших логів нові поля для розширення інформації та зручності подальшого пошуку. У вищезгаданому репозиторії GitHub є приклади з додавання additional fields як константами в конфігураційному файлі, так і з коду. І це дуже важливо для подальшої ефективності пошуку: замість того, щоб додавати назву поточного модуля або яку завгодно ключову інформацію до тексту вашого повідомлення, додайте окреме поле, яке швидко індексуватиметься в Elasticsearch.

Щодо протоколу доставки даних у Graylog: на тій годину ми спробували HttpAppender та UdpAppender. Вибір нікого на користь іншої через набагато більшу швидкість передачі. Elasticsearch було розгорнуто в кластері з 2 нсд. Також було 2 ноди веб-сервісу самого Graylog.

За деякий час виявилося, що сервісом неможливо користуватися: UI постійно зависає, результати пошуку повертаються за 5 хвилин, половина логів просто губиться. Усе це відбувалося через те, що:

Три окремі проблеми, які вкупі вбили на тій годину подалі використання нами цієї системи.

Нова надія

Так вже сталося, що тоді через брак часу й ресурсів ми припинили пошуки шляхів розв'язків язання виявлених проблем і повернулися до зберігання логів у файловій системі. Крок назад? Так. Але ми суттєво переглянули інформацію, що логується, і позбулися інформаційного сміття: щось зовсім перестали логувати, щось перевели на рівень Debug. У продакшн-середовищі в деяких компонентах логування перевели лише на рівень Error, знаючи, що інші рівні повідомлень там не потрібні. Наприклад, для Web API нам потрібні логи вхідних запитів, щоб знаті, які дані надходять до сервісу, — це рівень Info; а від для фонових процесів нашої системи нам не важливо знаті їхні проміжні дані, потрібно лише знаті, коли трапляються виняткові ситуації, — це рівень Error.

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

Ці кроки дали нам змогу зоптимізувати не тільки якість логів, а ще й швидкодію системи (про швидкість є хороша стаття тут ).

Наступним каталізатором до відновлення пошуку дорослої системи обробки логів ставши .NET Core. Усі компоненти нашого сервісу набули вигляду акуратних контейнерів у Docker під управлінням Kubernetes, а правильний збір і зберігання логів стали нагальною потребою. І знову ми згадали про Graylog, звісно, пам'ятаючи перший негативний досвід. Читачі статті можуть поставити логічне запитання: чому не ELK? Для нас Graylog мав такі переваги:

На тему порівняння Graylog vs. ELK також є досить докладна стаття .

Що ми змінили, маючи перший негативний досвід:

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

Можна прочитати цілу купу статей про налаштування кластера Elasticsearch, альо кількість запитань тільки збільшиться. А можна прочитати best practices з офіційного сайту й бути абсолютно щасливим. Ми вже згадували про ті, як у годину першого знайомства з Graylog у нас був кластер Elasticsearch із двох мод, які булі й master, і 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К повідомлень на секунду) ми також здобули більшу надійність:

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

Моніторинг

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

Відтоді в нас з'єднання явився моніторинг наявності логів, який було налаштовано засобами самого Graylog. А сповіщення надходять до групи Telegram.

Епілог

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

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

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

Рекомендуємо:

Туторіал по розгортанню Rails-додатків на Amazon за допомогою Docker. Частина 1
Олег Рогінський, CEO People.ai: «Простіше підняти $60 млн інвестицій, ніж найняти 10 інженерів»
Як прокачати емоційний інтелект, щоб спілкуватися з колегами результативно
Кейс: Просування з нуля сайту школи психологічного консультування
Рейтинг вишів DOU 2019: біля Могилянки з'єднання явився конкурент за перше місце, а КПІ за межами 10-ки лідерів