История про то, как мы тюнили логи в своем проекте и как это переросло во что-то большее. Возможно кому-то это поможет в своих проектах, кому-то будет просто интересно почитать.
Былые времена
Думаю объяснять зачем нужны логи не стоит, уверен что это должно быть очевидно каждом IT-шнику. Но если совсем кратко, то логи нужны чтобы система сообщала, что она делает и потом, читая логи, можно было разобраться в проблемах, возникших внутри системы, ну или не разобраться, и это повод улучшить логирование.
Так вот тогда система писала логи по аналогии с тем как это делается в любой *nix ОСи, т.е. записывала информацию в файл, формат записи плюс/минус был стандартный:
<date time> <level> <message>
Кратко о системе: это сервисы SOAP API, в логи записывались запросы, ответы и важная служебная информация.
Поиск и анализ логов был прост: открываешь файл и поиском по тексту ищешь по шаблону нужное место.
Думаю вы уже догадываетесь какие трудности возникали в результате этого. Основная трудность - это найти в логах информацию о возникшем сбое. По сути есть только время сбоя, причем приблизительное, например "около 12ч дня наблюдали проблемы у сервиса".
Открываешь файл, начинаешь искать по времени с 12:00 по 12:10, ничего не находишь и думаешь "а был ли сбой?".
Или наоборот, конкретный случай у клиента, он в браузере увидел ошибку, система состояла из ряда сервисов, которые взаимодействовали между собой, поэтому сбой мог быть в любом из них. И приходилось смотреть по всем файлам, искать ошибки по ключевому слову ERROR и приблизительному времени, указанному клиентом.
С ростом нагрузки на сервис, анализ логов становился просто невозможным, начинали писать скрипты, которые парсят файлы логов в поисках ошибок и проблем. Удорожание сопровождения становилось все большим, процент времени, уделяемый командой разработки на анализ логов, стремительно возрастал. Нужно было что-то менять.
Рождение PID
Идея с PID возникла всё из тех же предпосылок, связанных с *nix.
Техническая команда запрашивала по возможности предоставлять запрос к системе и её ответ. Это позволяло начать поиск в логах по дате и времени, что упрощало анализ. Однако система состояла из нескольких сервисов. Допустим, у нас есть запрос и ответ от одного сервиса — но как найти остальные логи? Это можно сделать по цепочке, но такой подход отнимал слишком много времени.
Так возникла идея связать логи единым сквозным идентификатором. Его назвали просто — PID.
Принцип работы такой:
Сервис при получении запроса проверял наличие PID.
Если идентификатора не было — генерировал его.
Далее передавал этот PID всем связанным сервисам в рамках процесса.
Важно: PID уникален только в контексте одного внешнего запроса/процесса.
В результате в логах появился дополнительный параметр, который объединял записи всех сервисов, участвующих в обработке запроса. Теперь, имея даже один запрос/ответ, мы могли использовать PID для быстрого поиска всех связанных логов — это занимало меньше времени, чем раньше.
Позже, вместо запроса полных данных стали запрашивать PID из ответа. Это дополнительно ускорило анал��з логов.
Ускорение
Тем не менее скорость анализа оставалась низкой, плюс стало очевидно, что команда разработки не может заниматься полным сопровождением/поддержкой системы. Нужен был отдел технической поддержки, где разбирали бы логи и вносили изменения в настройки системы. Многие ошибки были связанны не с багами системы, а с неверными настройками или отсутствием оных.
Логи в файлах становились препятствием, хоть работа с файлам кажется простой, но сопутствующие ограничения очень сильно мешали подключать ребят из тех. поддержки к анализу. Приведу ряд примеров:
доступы к файлам: т.е. как минимум какой-то ssh-доступ к серверу, где есть логи;
размеры файлов: требовалось отдельно научить и проинструктировать как правильно работать с по-настоящему гигантскими файлами, не правильно откроешь их и сервер накроется медным тазом;
медленный поиск: из-за того что файлов могло быть много от разных сервисов, то приходилось открывать каждый и просматривать. У команды разработки были скрипты, которые они использовали для поиска, но это почти уже кодинг, а отдел ИБ сильно против того, чтобы ребята из тех. поддержки выполняли какой-то скрипт на прод-серверах.
Знаю, знаю, что все выше перечисленные ограничения можно решить, организовав отдельное хранилище с отдельными доступами и т.д. Но это тоже будет часть системы, которую надо сопровождать, на которую тоже придется тратить дополнительные силы.
Поэтому мы решили переехать с файлов в MongoDB, т.е. записывать те��ерь логи в монгу.
Чем понравилась MongoDB:
гибкий формат записи, т.е. можно расширять запись в коллекции дополнительными полями;
довольно быстрая NoSQL БД;
возможность использования индексов, PID идеально подходил под индексирование;
возможность написания скриптов для поиска по записям.
Мы переделали механизм логирования, добавив в него возможность записывать логи в монгу. Теперь вместо файла у нас была коллекция.
Поиск по PID и по всем коллекция был в разы быстрее, вместо открытия десятков файлов, мы просто набирали запрос в монгу с указанием PID и получали все записи логов, сделанные в рамках одного процесса/одного PID'а.
Плюс ко всему получали возможность проводить анализ не по одному процессу, а по всем, указывая в скрипте шаблон поиска определенной ошибки или участка логов.
Из мелких последующих доработок следует отметить разбиение коллекций по времени, т.к. бесконечно записывать в одну коллекцию все логи сервиса было нереально. Мы добавили в название коллекции суффикс года и месяца collection_name_202505.
UI тулз
Через какое-то время от тех. поддержки стали приходить жалобы, что работать с монгой не удобно, особенно, если пользуешься консолью. "Знали бы они, как не удобно было раньше" - думали мы тогда.
Первым решением было использовать Robomongo и это помогло, простой и понятный gui-клиент.
Но со временем неудобства накапливались. Например, самая частая жалоба была на xml-разметку: чтобы отформатировать ее, приходилось копировать данные в сторонние форматеры, что было конечно же не удобно.
Поэтому было решено сделать свой web-интерфейс и уже его дорабатывать как хочется, и xml форматировать, и другие удобства прикручивать.
Проблема возникла откуда не ждали: отдел разработки был загружен бизнес-задачами и никак не мог начать делать UI tools.
Но как говорится "спасение утопающих - дело рук самих утопающих". Один из инженеров в тех. поддержке очень хотел стать программистом, а именно фронтенд-программистом. Решили ему дать задание сделать UI tools для чтения и анализа логов. Парень - молодец! Где-то через месяц сделал первый вариант веб-интерфейса, мы его называли "ч��до-юдо". Тем не менее в работе отдела саппорта тулза прижилась.
К нашему сожалению парень, сделавший "чудо-юдо" ушел в другую контору, становится настоящим программистом. Удачи тебе, герой!
А мы столкнулись с тех. долгом, но уже была основа, и отдел программистов понемногу улучшал "чудо-юдо", превратив его со временем в мощный инструмент для тех. поддержки, но это уже другая история.
Послесловие
Сегодня ребята из тех. поддержки, да и других отделов от разработки до админов/devops, не могут себе представить времена, когда не было UI тулзы для логов, не могут представить себе логи без PID.
