ELK в боевом окружении: пять серверов, один Kibana-дашборд и 30 секунд до ответа

В январе мы разворачивали ELK на тестовом клиенте и остались в целом довольны, хотя и набили там пару шишек с памятью и ротацией индексов. С тех пор стек обжился, и на этой неделе мы закончили полноценный перенос продакшн-окружения одного из клиентов: пять серверов, разнородный стек - nginx, PostgreSQL, пара Java-приложений и служебные демоны.

До этого перехода картина была классическая: инцидент, дежурный тянется к терминалу, открывает несколько ssh-сессий и начинает grep по каждому хосту по очереди. Это спокойная, вдумчивая работа. Минут на двадцать, если повезёт и сразу угадаешь с хостом и временным окном.

Почему именно сейчас

Два триггера. Первый - в мае поймали инцидент, когда Java-приложение на app01 начало падать с OOM-ошибками, а причиной оказалась долгая транзакция на PostgreSQL-сервере db01. Связать это вручную заняло минут сорок - пока перелопатили логи на обоих хостах с нужным временным окном. Второй - в июле CentOS 7 поменял формат логов systemd-сервисов, и часть cron-скриптов, которые парсили /var/log/messages, тихо перестала работать. Обнаружили через несколько дней.

После второго случая стало ясно: grep по ssh и разрозненные файлы - это не рабочий инструмент при нескольких серверах. Пора заканчивать с самодеятельностью.

Схема: как выглядит пайплайн

Архитектура получилась в три уровня:

[app01]  rsyslog ──┐
[app02]  rsyslog ──┤
[db01]   rsyslog ──┼──> Logstash :5514/tcp ──> Elasticsearch ──> Kibana
[web01]  rsyslog ──┤
[mon01]  rsyslog ──┘

На каждом сервере rsyslog настроен на пересылку всего потока через TCP на порт 5514. TCP вместо UDP - потому что UDP тихо теряет пакеты при всплеске нагрузки, а терять события как раз в момент инцидента особенно обидно.

Logstash поднят на отдельной виртуалке с 8 ГБ ОЗУ - половину отдали под JVM-кучу Elasticsearch, как и учила январская шишка. Elasticsearch 1.2, Logstash 1.4, Kibana 3.

Парсинг: grok или падение на «message»

Самая трудоёмкая часть - описать структуру входящих логов. Logstash умеет разбирать syslog из коробки: hostname, severity, facility, timestamp достаются автоматически. Дальше начинается ручная работа.

Для каждого типа логов свой grok-паттерн:

nginx access log - готовый паттерн COMBINEDAPACHELOG покрывает большинство стандартных конфигов. Вытаскивает IP, метод, URI, статус, размер тела и время обработки запроса. Последнее особенно ценно - можно строить в Kibana гистограмму времён ответа и мгновенно видеть деградацию.

PostgreSQL slow query log - пришлось писать руками. Формат у PostgreSQL свой, grok-отладчик (нашли онлайн-тул, очень помогает) потратили на него часа полтора. Зато теперь любой запрос медленнее порога попадает в Elasticsearch с полем duration_ms, и поиск «все запросы дольше 5 секунд за последний час» - одна строчка в Kibana.

Java-стектрейсы - отдельная головная боль. Одно исключение - это 20-50 строк лога, и каждая приходит как отдельное syslog-сообщение. Logstash имеет codec multiline, который умеет склеивать строки по паттерну. Настроили на признак «строка начинается с пробела или с at » - это маркер продолжения стектрейса. Работает, хотя на пиковой нагрузке иногда режет стектрейс пополам между двумя буферными циклами.

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

Что изменилось в работе

Первый же реальный инцидент после запуска расставил всё по местам. На прошлой неделе app02 начал выдавать 502 от nginx. Открываем Kibana, выставляем фильтр host: web01 AND status: 502, смотрим на временную шкалу - ошибки начались в 14:31. Переключаемся на host: app02, смотрим что было в 14:31 - видим connection refused на соединение с db01. Переключаемся на db01 в то же время - PostgreSQL-логи показывают max_connections exceeded.

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

Несколько наблюдений из первых недель работы в продакшне:

• Видимость аномалий. Временная шкала событий в Kibana показывает всплески без специального запроса - просто смотришь на форму графика.
• Кросс-хостовая корреляция. Это главное, чего не хватало раньше. Один временной диапазон, все хосты рядом.
• Медленные запросы без мониторинга. PostgreSQL slow query log в Elasticsearch - отдельный дашборд с топом медленных запросов. Обнаружили два запроса, которые запускались по расписанию и никто не замечал, что они тормозят.

Что ещё не решили

Ротация индексов пока через cron: каждую ночь скрипт удаляет индексы старше двух недель. Работает, но грубо - нет плавного удаления по объёму. Curator для управления индексами Elasticsearch нашли на GitHub, хотим перейти на него.

Алертинг через Kibana не закрыт - сам Kibana 3 уведомлений не отправляет, это просто визуализация. Пока дежурный смотрит дашборд руками при инцидентах. Zabbix у клиента есть, связать его с Elasticsearch через внешние скрипты - следующий шаг.

TLS между rsyslog и Logstash не настроен: трафик идёт открытым текстом по внутренней сети. Для изолированного клиентского влана сейчас приемлемо, но если появится межсегментная пересылка - придётся закрывать.

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