Новый подход к просмотру логов

Одно время, приходилось много работать с логами. Они могли быть большими и находиться на разных серверах. Требовалось не найти что-то конкретное, а понять почему система ведёт себя не так как надо. По некоторым причинам, лог-агрегатора не было.

Хотелось иметь просмотрщик логов, позволяющий, в любой момент, открыть любой файл, без скачивания на локальную машину, как команда less в linux консоли. Но при этом, должна быть удобная подсветка текста, как в IDE, и фильтрация записей по различным параметрам. Фильтрация и поиск должны работать по событиям в логе, а не по строкам, как grep, это важно когда есть многострочные записи, например ошибки со стектрейсами. Так же должна быть возможность просматривать записи сразу из нескольких файлов на одной странице, смёржив их по таймстемпу, даже если файлы находятся на разных нодах.

И я придумал как сделать такую утилиту!

Log Viewer - это небольшое web-приложение, которое работает на нодах, где лежат логи, и показывает эти логи через Web интерфейс. Это именно просмотрщик, а не агрегатор, нет никакой индексации или считывания всего лога в память, читается только та часть лога, которую пользователь смотрит в текущий момент. Такой подход позволяет почти не занимать ресурсов. 

Предвижу вопросы о производительности типа «Разве можно быстро фильтровать записи без индексации? В плохих случаях придётся остcканировать весь лог чтобы найти хоть одну запись подходящую под фильтр». Во первых, сканирование лога работает довольно быстро, 1Гб читается около 3,5сек, это терпимо. Во вторых, обычно известен временной интервал, в котором ищем проблему, если задан фильтр по дате, то будет сканироваться только та часть файла, в которой находятся записи относящиеся к тому времени. Найти границу временного интервала в файле можно очень быстро бинарным поиском.

Отображение лога

Чтобы легче различать границы одной записи, запись под курсором подсвечивается прямоугольником; поле severity подсвечивается различными цветами в зависимости от значения, парные скобки подсвечиваются когда наводишь курсор на одну из них.

Обратите внимание на стектрейс эксепшена, показаны только самые интересные строки, остальные сфолжены под «+» и «…» , интересными строками считаются классы из пакетов принадлежащий главному приложению, соседние с ними, и первая строка. Пакеты главного приложения задаются в конфигурации. В таком виде стектрейс занимает намного меньше места на экране и его удобней смотреть. Возможно такая идея понравится разработчикам Java IDE.

Имя логгера тоже сокращено: «~.SecurityManager». Показывается только имя класса, а пакет сворачивается в «~».

Фолдинг влияет только на отображение, поиск работает по оригинальному тексту. Если совпадение найдётся в сокращённой части текста, то эта часть текста автоматически появится. Также, если пользователь выделит текст и нажмёт Ctrl+C, в буфер скопируется исходный текст, без всяких сокращений.

Архитектура позволяет легко навешивать на текст подсветку или всплывающие подсказки, благодаря этому, сделаны разные приятные мелочи типа показа даты в человеческом формате, если она напечатана в виде числа:

Фильтрация

Набор фильтров зависит от формата лога. Некоторые фильтры доступны всегда, например фильтр по подстроке, а некоторые появляются если в логе присутствует поле определённого типа. Это позволяет создавать специализированные фильтры для некоторых типов полей. Например, если в логе есть поле severity, то в верхней панельке появится такой UI компонент:

Severity filter

Очень удобно добавлять фильтры из контекстного меню. Можно выделить текст, кликнуть правой кнопкой мыши и выбрать «Не показывать записи с таким текстом». На панельку с фильтрами автоматически добавится фильтр по тексту, скрывающий записи с таким текстом. Помогает когда лог завален однообразными записями, не интересными в данный момент.

Добавление фильтров из контекстного меню

Можно кликнуть на запись и выбрать «Скрыть последующие записи» или «Скрыть предыдущие записи», чтобы работать только с определённой частью лога. Скрытие происходит добавлением фильтра по дате.

Для сложных случаев можно задать фильтр с условием написанным на JavaScript. Такой фильтр представляет из себя функцию принимающую одну записи и возвращающую true или false.

Пример фильтра на JavaScript
function isVisibleEvent(text, fields) {
    var match = text.match(/Task completed, elapsed time: (\d+)ms$/)
    if (!match)
        return false // Don't show events not matched the pattern
        
    var time = parseInt(match[1])

    return time > 500 // Show only events where elapsed time is more than a threshold
}

При изменении фильтров, просмотрщик старается максимально сохранить позицию в логе. Если есть выделенная запись, то изменение фильтров не изменит её положения на экране, а записи вокруг пропадут или появятся. Пользователь может задать фильтр, чтобы были видны только ошибки, найти подозрительную ошибку, затем убрать фильтр и смотреть что происходило вокруг этой ошибки.

Состояние панели фильтров отображается в параметрах URL, чтобы можно было добавить в закладки браузера текущую конфигурацию.

Мелкие, но полезные фичи

Когда находишь что-то интересное — хочется поделиться этим с командой, для этого можно создать специальную ссылку на текущую позицию в логе, и любой кто её откроет увидит точно такую же страницу, которая была при создании ссылки, включая состояние фильтров, текста в поле поиска, выделенной записи и т.д.

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

Конфигурация

Я старался сделать конфигурацию как можно проще, чтобы всё работало из коробки. Если попросить пользователя задать формат лога, то большинство просто закроют приложение и пойдут смотреть по старинке. Поэтому формат лога распознаётся автоматически. Конечно, это работает не всегда и часто не точно. Для таких случаев можно задать формат лога вручную в файле конфигурации. Можно использовать паттерны log4j, logback или просто регексп. Если ваш лог не распознался, но вам кажется что должен — создайте issue на GitHub, этим вы поможете проекту.

Самая нужная настройка — список видимых файлов. По умолчанию доступны все файлы с расширением «.log» и видна вся структура каталогов, но это не очень хорошо с точки зрения секьюрити. В конфигурационном файле можно ограничить видимость файлов с помощью списка паттернов типа такого:

logs = [
  {
    path: "/opt/my-app/logs/*.log"
  },
  {
    path: ${HOME}"/work/**"
  }
]

Пользователю будут доступны только .log файлы в директории /opt/my-app/logs и любые файлы в директории ~/work и её поддиректориях.

Более подробная информация в документации на GitHub.

Работа с несколькими нодами

Мёрж файлов, расположенных на разных нодах — это киллер фича, ради которой и затевался проект. Как я уже говорил, файл никогда не скачивается полностью с одной ноды на другую и не индексируется. Поэтому, на каждой из нод должен быть запущен Log Viewer. Пользователь открывает web UI на одной из нод, указывает расположение логов, и Log Viewer коннектится к другим инстансам LogViewer чтобы подгружать содержимое лога через них. Записи из всех открытых файлов мёржатся по таймстемпу и показываются как буд-то это один файл.

Вкратце опишу как это работает под капотом. Когда пользователь открывает страницу, надо показать конец лога, для этого на каждую ноду отправляется запрос «дай последние N записей», где N — количество строк помещающихся на экран. Полученные записи сортируются по таймстемпу, берутся последние N записей и показываются пользователю. Когда пользователь скролит страницу вверх, на все ноды посылается запрос «дай последние N записей с таймстемпом меньше T», где T — таймстемп самой верхней записи на экране. Полученные записи сортируются и добавляются на страницу. При скроле вниз происходит тоже самое, только в другую сторону. Поиск позиции в файле, где находятся записи старше/младше T, работает очень быстро, так как записи отсортированы по таймстемпу и можно использовать бинарный поиск. Там есть много нюансов, но общая схема такая. Мёрж работает только если система смогла определить фомат лога и в каждой записи задан полный тайстемп.

На данный момент, нет UI для выбора файлов на разных нодах, приходится прописывать файлы в параметрах URL в таком виде:
http://localhost:8111/log?path=/opt/my-app/logs/a.log@hostname1&path=/opt/my-app/logs/b.log@hostname1&path=/opt/my-app/logs/c.log@hostname2
здесь каждый параметр "path" задаёт один файл, после "@" указывается хост, на котором лежит файл и запущен инстанс просмотрщика логов. Можно указать несколько хостов через запятую. Если "@" отсутствует — файл находится на текущей ноде. Чтобы не иметь дела с огромными URL, есть возможность задать короткие ссылки в конфигурации, в разделе log-paths = { … }.

Встраивание просмотрщика в своё приложение

Log Viewer можно подключить к своему Java Web приложению как библиотеку, чтобы оно могло показывать пользователю свои логи. Иногда это удобней чем запуск отдельным приложением. Достаточно просто добавить зависимость на библиотеку библиотеку через Maven/Gradle и подключить один конфигурационный класс в spring context. Всё остальное сконфигурится автоматически, log viewer сам распознает какая система логгирования используется и возьмёт из её конфигурации расположение и формат логов. По умолчанию UI маппится на /logs, но всё можно кастомизировать. Пока автоматическая конфигурация работает только с Log4j и Logback.

Это тестировалось на маленьком количестве приложений, если у вас возникнут проблемы — смело пишите в discussions на GitHub.

Что планируется сделать в будущем

Было бы удобно, если бы была возможность оставлять комментарии к записям. Например, прикрепить номер тикета к сообщению об ошибке. Комментарий должен быть виден всем пользователям и, когда такая же ошибка вылетит в следующий раз, будет понятно что с ней делать.

Есть много идей по мелкому улучшению UI. Например, если в тексте встретился кусок JSON, то хочется чтобы просмотрщик умел показывать его в отформатированном виде, а не одной строкой. Хочется иметь возможность задать фильтр по severity для отдельного класса, а не сразу для всех.

Иногда нет возможности открыть порт на сервере для просмотра логов, есть только SSH доступ. Можно сделать поддержку работы через SSH. Web UI будет подниматься на локальной машине, коннектиться через SSH к серверу и запускать там специального агента. Агент будет принимать команды через input stream и возвращать нужные части лога через output stream.

Буду рад услышать фидбэк.

Проект на GitHub: https://github.com/sevdokimov/log-viewer

Комментарии 25

    +2
    Кликхаус, Elasticsearch

    Люди уже сделали хорошие средства для хранения логов и работы с ними. А вы все еще сидите на текстовых файликах.
      0

      Плюс Sentry еще как облачная альтернатива для логирования на клиенте и сервере

        +4

        Давно ли в сентри стали логи хранить?


        К слову, сентри можно не только в облаке держать, но и на своих серверах.

        +7
        Люди уже сделали хорошие средства для хранения логов и работы с ними. А вы все еще сидите на текстовых файликах.

        ни то, ни то не является "хорошим" средством для хранения логов и работы с ними. Скорее являются "стандартными" и наиболее известными средствами. Причем эластик в лидерах. Кстати, про graylog забыли. Ну, и я ставлю, что почти наверняка эффективность хранения в КХ будет выше, чем в эластике. Просто потому что как правило полнотекстовый поиск как в эластике нафиг не нужен… В этом отношении очень интересен подход Loki (Grafana), когда они выделяют самые существенные метки в лог-сообщениях.
        Еще добавлю, что логи — это просто жесть как дорого с точки зрения хранения и обработки. И поэтому нужно взвешивать все плюсы и минусы и нужно ли действительно хранить логи на каком-то уровне логирования. Потому что это все равно упадет костами на продукт. Тот же Яндекс недавно озвучивал мнение, что вместо того, чтобы писать логи — лучше сразу стараться писать нормальный код… А логи не нужны ))))
        /это не относится к ситуации необходимости отправки СОБЫТИЙ из приложения — например, событий аудита, но неправда ли — это совершенно другой юзкейс, чем просто поток логов для отладки/разработки?/


        p.s. ну, и добавлю, что есть вообще-то принципиальная разница между "логами" и "трейсами" (тем более между различными приложениями — реверанс в сторону jaeger/dynatrace и прочих apm)...

          +1
          Известное как правило лучше неизвестного. Люди умеют с ними работать, настраивать, so работает. Если нет прям очень веских доводов за самое лучшее решение вместо стандартного я буду голосовать за стандартное.

          Графана — это отличная морда для графиков, мониторингов и подобного. Использовать ее для тестовых логов как-то странно. Не пробовал.

          Не писать логи это смело. Не писать каждый чих наверно стоит, но с возможностью бстро включить если что не так. Деньги экнономить стоит.
          А вот вообще не писать страшно. Потом же концов не найдешь.
          Баланс нужен.

          Логи это логи. Приложение пишет текстом что-то важное для нее. Я только об этом.
            +1
            Графана — это отличная морда для графиков, мониторингов и подобного. Использовать ее для тестовых логов как-то странно. Не пробовал.

            Не страннее, чем использовать графану вместо кибаны для вывода информации из ES.


            Логи это логи. Приложение пишет текстом что-то важное для нее. Я только об этом.

            Опыт показывает, что правы те люди, которые говорят, что логи не нужны. Может вы вместо ES хотите Jaeger/dynatrace? Или Sentry? Или что-то ещё? Потому что из логов очень быстро мы доходим до антипаттернов вроде «метрики из логов» (wat?) или «алертинг по логам». Вместо того, чтобы использовать более подходящие решения.
            Дополнительно — «плоский» текстовый формат логов тоже вынуждает бороться с ним. Потому что логи — это структурированная информация (когда вылетает из приложения), потом текст как универсальный способ передачи, потом нам приходится парсить текст logstash и прочим, чтобы восстановить исходную структуру. Представляете себе сколько тактов процессора на это жжется в никуда? И мы получаем все «прелести» обработки логов вроде truncated сообщения или необходимость клеить multiline.


            Насчёт быстрого переключения лог-левела на ходу — полностью согласен с Вами.

              0
              Вы прям все антипаттерны собрали. За такое надо сразу бить по рукам. При первой попытке что-то такое сделать. На основе логов нельзя делать никакой автоматики. Их надо просто складировать на черный день.

              Логи что бы было что почитать когда прод начал себя вести как-то странно. Или еще хуже перестал работать. Когда прод взрывается и даже некуда посмотреть что вообще проиходит это печально.
              Сам момент странного поведения или прекращения работы по логам отслеживать естесвенно нельзя.

              Формат это старое легаси. С ним все научились жить. Что поделать. Может и доживем до какой революции в этом месте.
                0
                Опыт показывает, что правы те люди, которые говорят, что логи не нужны.

                Либо вы должны сейчас привести пример как находится и решается проблема которая возникла на проде но нигде в логах не зафиксирована. Либо это все же не опыт а его отсутствие вместе с фантазиями на тему идеального ПО.)
                Метрики и алертинг по логам это просто и удобно — очень junion подход все пытаться оптимизировать по потребляемым ресурсам RAM, CPU и т.д., когда в подавляющем большенстве случаев нужно оптимизировать трудозатраты.

              0
              лучше сразу стараться писать нормальный код

              И обязательно без багов!
              +2
              ELK — штука классная, конечно же, на серьёзных production environment надо использовать её.
              Но иногда, установка агрегатора логов — это оверкил, бывает много ситуаций когда надо посмотреть лог не попадающий в агрегатор. Это не конкурент ELK или Graylog, это конкурент Notepad и «tail -F foo.log»
                0
                Если у вас прод не в общей системе это факап. Надо все бросать и чинить.
                Если у вас любое другое постоянное окружение не в общей системе это серьезная бага. Надо починить при первой возможности.

                И остаются только временные CI стенды. А на них ничего и не будет. По понятным причинам. Хотя и не очень надо, grep и less с головой хватает. Там логов немного.
                  0
                  Если у вас прод не в общей системе это факап.

                  Разверните мысль, пожалуйста? Почему это прод (в общем) должен быть в общей системе? Легко может оказаться, что каждая команда (мы про agile) может иметь своё хранилище… и это будет лучше — ну, например, потому что у каждой команды свой набор чувствительных данных в логах

                    0
                    Чуствительных данных в логах не должно быть. Одно из первых мест для утечки же.

                    Общее место для команды, отдела, подразделения, да любой организационной
                    единицы как вы там работаете.

                    Хотя когда команд 10+ стоит подумать и сделать всем одинаково. Чуствительную информацию ловить общими средствами и заставлять удалять, настраивать один раз, админить один раз, просто клевые идеи друг у друга таскать легко. Времени можно вагон наэкономить.
                      0
                      Чуствительных данных в логах не должно быть. Одно из первых мест для утечки же.

                      Спорный вопрос. В явном виде — наверное, да, но если мы говорим про observability все равно должен быть способ понять — что это запросы от клиента А, а это от клиента Б… Пускай будет маскирование и обфускация — я не против. Но это ещё сильнее повышает общую стоимость солюшена. Ну, и плюс я гарантирую, чтобы всегда что-то «чувствителньое» возьмёт и просочится в логи…


                      Хотя когда команд 10+ стоит подумать и сделать всем одинаково.

                      Есть разница между «общее хранилище как единый инстанс эластика» и «managed elastic, который может себе поднять сам по общим шаблонам». В первом случае там ещё 100500 вопросов возникает вроде мультитенантности, разделения костов по потребителям и пр. Т.е. необходимо централизованное, но «не совсем» решение

                        0
                        В явном виде — наверное, да, но если мы говорим про observability все равно должен быть способ понять — что это запросы от клиента А, а это от клиента Б… Пускай будет маскирование и обфускация — я не против.

                        Я именно про явный вид.
                        Совсем чуствительная вроде паролей вообще ни каком виде не должна быть.
                        А id юзера тот же хешированный почему бы и нет. Соседний отдел пусть видит так и общей защиты от утечек хватит. Да и утечет не очень страшно.

                        Но это ещё сильнее повышает общую стоимость солюшена.

                        Да не особо он ее повышает. Хеш посчитать несложно, заменить все чуствительное на какой-нибдуь ray-id тоже несложно.
                        Если у вас логи забиты ФИО юзеров, то у вас проблема и исправлять ее дорого. Но надо и срочно, утечка это только вопрос времени. А если уже все хорошо, то поддерживать недорого.

                        Ну, и плюс я гарантирую, чтобы всегда что-то «чувствителньое» возьмёт и просочится в логи…

                        Сканирующая в фоне и ставящая блокеры на команды разработки (тут уже можно под контролем человека) автоматика рулит. От простейшей по ключевым словам, до сколь угодно сложной. Посоветовать не могу, таких публичных решений не знаю.

                        Есть разница между «общее хранилище как единый инстанс эластика» и «managed elastic, который может себе поднять сам по общим шаблонам». В первом случае там ещё 100500 вопросов возникает вроде мультитенантности, разделения костов по потребителям и пр. Т.е. необходимо централизованное, но «не совсем» решение

                        Это уже совсем дело вкуса и маштабов. И то и то типовое и подходит под условие у всех все одинаково.

                        Главное что бы не было у одних эластик, у вторых кликхаус, у третих текстовые логи и обертка самописная над ними. В этот момент стоит задуматься и обобщить лучшие практики. И заставить всех на них перейти. Хотя бы за год.
              +1

              штука действительно интересная, если нет желания городить страшилу из графаны и эластиков, а нужно быстро сориентироваться по событиям из разных мест.
              Спасибо.


              это я недосмотрел, или нет ссылки на гит?

                0

                Недосмотрели, да.

                0
                  +1

                  Больше похоже на самобытный такой хоум-проект, который можно заодно толкнуть в универе как курсач.
                  А если по теме, то всё давно изобретено — clickhouse, ELK

                    0
                    да, так и есть, это pet project. С заголовком я переборщил, «Новый подход к просмотру логов» выглядит уж слишком многообещающим.

                    clickhouse, ELK — это другое, они — агрегаторы логов, они индексируют содержимое в отдельной базе, иногда это оверкил. Моя штука нужна когда просто хочешь посмотреть содержимое лог-файла.
                      +2

                      А вы не смотрели на lnav? Или это немного не то?

                        0
                        Не знал про lnav. Прикольно, это почти тоже самое что моя штука, но UI сделан через терминал, а не через Web.
                          0

                          Ну можно и через веб (кликабельно)… ;-)
                          image

                    0
                    Поставил к нам на тестово-девелоперский сервер. Закрыл сверху авторизацией через наш локальный YouTrack с помощью oauth2-proxy — удобненько получилось.
                    Пока заметил, что даже небольшое несовпадение паттерна в конфиге с паттерном в логе ломает весь парсинг.
                    Будем посмотреть. Спасибо!
                      0

                      Круто! То что нужно! Собирался в свободное время написать что-то похожее, но вы меня сильно опередили. На проде есть кластер из 3 нодов, пока проходит сертификация и rollout приложения нужно часто копаться в логах. А использовать SSH+консоль контрпродуктивно. А ELK и прочаие сторонние тулзы не предусмотрены контрактом.


                      Есть пожелание по поводу настройки работы с rolled-файлами. Допустим роллинг файлов сконфигурирован по паттерну: service.${hostname}_%d{yyyy-MM-dd}.%i.log, то есть текущий лог записывается на каждой ноде в файл service.nodeX.log, который потом заворачивается в напр. service-nodeX_2021-01-20.0.log по дате и лимиту в МБ. Насколько я понял, для того, чтобы сработал мёрж нужно указать все файлы на всех нодах вручную, а мы точно не знаем сколько их. Поэтому в шорткатах будет очень удобно иметь возможность использовать URL-параметры и wildcards|regexp для задания фильтра на файлы, а также указывать имя хоста:


                      log-paths = {
                          daily = {
                              file = [
                                  ${HOME}"/my-app/logs/service.node-cn-01_${date}.*.log@node-cn-01",
                                  ${HOME}"/my-app/logs/service.node-cn-02_${date}.*.log@node-cn-02", 
                                  ${HOME}"/my-app/logs/service.node-cn-03_${date}.*.log@node-cn-03"
                              ]
                          }
                      }

                      И использовать в URL типа http://localhost:8111/log?log=daily&date=2020-01-20.

                      Только полноправные пользователи могут оставлять комментарии. Войдите, пожалуйста.

                      Самое читаемое