«Прочее» на 24 миллиона строк: как мы заставили логи MikroTik разбираться правильно

Как устроен сбор

1. Приём. rsyslog принимает UDP/TCP от сетевых устройств и серверов. Дисковая очередь — логи переживают недоступность коллектора.
2. Буфер. Kafka. Всплеск при разборе накопленного бэклога не роняет разбор.
3. Префильтр. Снятие технического префикса, отпечаток сообщения, маршрутизация потока.
4. Разбор. Фильтры Logstash: 12 веток классификации, гроки под реальные формы сообщений, раскладка адресов и имён по полям ECS.
5. Хранение. Разные типы логов — в разные датастримы Elasticsearch, каждый со своим шаблоном полей и жизненным циклом.

Задача

Логи с сетевого оборудования — это не один формат, а десяток диалектов. Вендорский syslog редко совпадает с RFC, а часто не совпадает и с собственной документацией вендора.

Что мы увидели в живом потоке:

• Заголовок сообщения приходит в пяти разных видах. RFC5424; классический syslog с именем хоста; ISO8601 с хостом; и две формы вообще без имени хоста — только время. Один и тот же маршрутизатор в течение часа шлёт и так, и так.
• Вместо имени хоста в поле приезжает слово уровня. MikroTik умеет прислать строку, где сразу после даты идёт warning denied winbox/dude connect from .... Стандартная защита «имя хоста не содержит двоеточия» тут не срабатывает — и в поле «источник» оседает слово warning. За неделю таких документов набралось 5 443.
• RouterOS называет объект конфигурации своими словами. Не item added by, а filter rule added by, address list entry added by, ssh-key removed by, nat rule added by, иногда просто именем созданного объекта, а иногда — пустым местом. Перечислять существительные в фильтре бессмысленно: их список открыт.
• Часы на приборах сбиты. Часть устройств ставит время в будущее. Индексировать событие «в будущее» нельзя — оно исчезает из любого окна на дашборде.
• Чужие сообщения похожи на нужные. Оборот removed by встречается не только в RouterOS, но и в логах системы резервного копирования (backup file removed by retention policy) — 723 документа, которые легко утянуть в «изменения конфигурации».

Итог: большая часть потока лежала в общем «прочем», а дашборд изменений конфигурации был почти пустым при живых логинах администраторов.

Главное условие — ничего не потерять. Ни одно сообщение не должно быть выброшено только потому, что фильтр его не понял: непонятое получает явный тип «неклассифицировано», а не пропадает молча.

Что сделали

• Разобрали заголовок по пяти шаблонам, а не по одному. Порядок шаблонов — часть логики: грок останавливается на первом совпадении. Добавили две защиты просмотром вперёд — против тега демона в поле хоста (systemd[1]:) и против слова уровня (warning, error, critical). Без второго шаблона «только время» событие вообще не совпадало, время бралось из момента приёма, а не из момента события.

• Заменили перечисление слов проверкой формы строки. Изменение конфигурации ловится регулярным выражением по форме сообщения целиком, с якорем на начало строки. Якорь обязателен: без него чужие removed by уехали бы в конфигурационные события.

• Пересобрали гроки по именам пользователей. Универсальный шаблон «что угодно» заглатывал хвост, и в поле имени оказывалось admin@<MAC>/terminal вместо admin. Контекст после имени бывает не только /action:5, но и /terminal, /terminal/action:10, /script:NAME/action:4 — покрыли все формы, включая короткую, вовсе без метода входа.

• Выстроили порядок веток классификации. Это не оформление, а логика: широкая ветка выше перехватывает события у узкой ниже. Сообщение system,info dhcp network changed by ssh:user@... содержит подстроку dhcp — и уходило в «события DHCP», теряя и тип, и автора правки. Ветка изменений конфигурации поднята в начало цепочки. Аналогично: события link up/down на интерфейсе l2tp-out1 забирала себе ветка PPP — ветку состояния интерфейса поставили выше.

• Добавили типы событий, которых не было. Состояние интерфейсов (со скоростью и дуплексом), неудачное согласование IPsec phase1 как отдельное событие безопасности, общая корзина прочих ошибок IPsec. Раньше всё это лежало в «прочем».

• Сделали запасной разбор имени пользователя. Отдельный блок дозаполняет поле, когда основные ветки его не проставили: sshd, sudo, systemd, ssh-cmd: — девять форм. Перед дорогими регулярками стоит дешёвая проверка по подстроке, иначе грок гонялся бы по всему потоку.

• Разложили адреса по типам. Исторически и IP, и MAC складывались в одно текстовое поле. По нему нельзя было ни искать по подсети, ни правильно сортировать: как строка 10.9.9.9 больше, чем 10.10.10.10. Теперь IPv4 — в поле типа ip, MAC — в своё поле, исходные значения сохранены.

• Перешли на ECS — в три шага, без разрыва. Сначала конвейер писал оба имени поля, потом панели переводились по одной со сверкой, и только потом старые имена убрали. Причина осторожности: пропавшее поле не даёт ошибки — панель просто отрисуется пустой, и это выглядит как «событий не было», а не как поломка. Переименование стоит последним действием конвейера: внутренние имена держат на себе условия всех веток.

• Защитили время события. Время в будущем дальше допуска заменяется временем приёма, исходное сохраняется отдельным полем и помечается тегом — по нему видно, у какого прибора сбиты часы. Время в прошлом не трогаем: логи законно опаздывают.

• Развели потоки по датастримам. Маршрутизация в префильтре, до разбора: сетевые логи, Linux auditd, файловый аудит — каждый в свой датастрим со своим шаблоном полей. Событие, для которого поток не определён, не выбрасывается, а уходит в отладочный вывод.

• Пересчитали историю. Все правки применены не только к новому потоку, но и к уже накопленным данным — иначе дашборд показывал бы «до» и «после» как два разных мира.

Результат

Изменения конфигурации

	было	стало
Записей в дашборде	1 469	3 503
Записей без имени автора	больше половины	0

Вынуто из «прочего»

Тип события	Документов
link_up	310 647
link_down	310 482
ipsec_error	230 521
ipsec_phase1_failed	3 468
Итого	855 118

Имена пользователей в своём поле

	было	стало
Документов с именем	582 458	2 340 392

Прибавка — 1,76 млн: события sshd, sudo и systemd, у которых имя раньше лежало только в тексте сообщения и не искалось.

Переход на ECS

event.action  35 971 910 = event_action  35 971 910
user.name      2 358 161 = username       2 358 161
расхождений 0

Классифицировано по категориям 12 856 585 документов, остаток — 0. Документов с потерянными полями (_ignored) на исправленных потоках: 0,3 % против 64,4 % до правок.

Что нашли попутно — и это оказалось важнее логов

После того как события состояния интерфейсов стали видны, выяснилось, что порты флапают: 347 794 перехода на одном интерфейсе, 117 034 на другом, 12 758 подъёмов и 12 725 падений за сутки. Это не проблема логирования — это неисправность физики или автосогласования, которая до этого просто не попадала ни на один дашборд.

Отдельно: 80 % объёма хранилища занимали сообщения сломанного файрвола — по строке на пакет. Диагноз поставлен по данным, файрвол пересобран, поток упал с 9 328 до 1 089 документов в минуту.

Три правила, которые мы вынесли из этой работы

1. Порядок веток разбора — часть логики, а не оформление. Широкое условие выше молча забирает события у узкого ниже. Добавляя ветку, надо проверять запросом, не ловит ли её признак кто-то выше по цепочке.

2. Молчаливые отказы опаснее громких. Подстановка несуществующего поля кладёт в индекс текст шаблона; пропавшее поле рисует пустую панель; неразобранный заголовок подменяет время события временем приёма. Ни одно из этого не даёт ошибки в логе — только неверные данные на экране.

3. Заплатка обязана иметь записанный критерий снятия. Иначе она останется навсегда и замаскирует следующую поломку того же рода.

Чем можем помочь

Если у вас уже стоит ELK, но дашборды по сетевому оборудованию выглядят подозрительно пустыми — скорее всего, дело не в железе и не в объёме, а в разборе.

Берёмся за:

• аудит существующего конвейера — сколько событий на самом деле лежит в «прочем», какие поля пустые, где время события подменено временем приёма;
• фильтры под ваше оборудование — MikroTik/RouterOS, OPNsense/pfSense, управляемые коммутаторы, Linux-серверы, файловый аудит, Windows;
• пересчёт накопленной истории под новые правила разбора — чтобы «до» и «после» были одним набором данных, а не двумя;
• переход на ECS без разрыва дашбордов;
• разделение потоков по датастримам с отдельными шаблонами полей и сроками хранения;
• отсев мусора там, где ему место — в приёмнике, а не в разборе: строку, выброшенную на входе, не нужно ни декодировать, ни хешировать, ни хранить.