Парсинг логов – типовая задача для системных администраторов и девопсов. Обычно это регулярная операция. Данные постоянно пишутся в конец файла, поэтому периодически его надо открывать и обрабатывать новые записи. В процессе нужно искать место, где мы закончили чтение в прошлый раз. Давайте автоматизируем этот поиск так, чтобы он не требовал просмотра лога с самого начала.
Первое, что приходит на ум, – запомнить позицию в файле, на которой мы закончили. Её возвращает функция tell. На следующей итерации перейдём сразу на эту позицию и продолжим чтение оттуда. Это делает функция seek практически бесплатно.
Схема простая и рабочая, но при ротации лога возникают проблемы. Во-первых, переход за границу файла не приведёт к ошибке, просто при чтении мы получим пустые данные. Значит, перед переходом надо проверить, что сохранённое значение не превышает размер файла, и если это не так, читать лог с начала. Даже в таком случае после ротации может записатся достаточно данных для успешного прохождения проверки. Тогда мы как ни в чём не бывало продолжим «с места, где закончили» и пропустим кусок данных.
Есть способ усовершенствовать алгоритм: запоминать смещение не конца файла, а начала последней прочитанной строки и её значение. В этом случае мы также перейдём на закешированную позицию, а потом прочитаем строку и сравним её с сохранённой. Если значения совпали, продолжаем чтение дальше. Если различаются, возвращаемся к началу файла. Так как в каждой строке лога обычно есть метка времени, успешное прохождение проверки после ротации практически невозможно.
Я реализовал эту идею в небольшом Python модуле. Он называется cutthelog. В нём есть единственный класс CutTheLog, позволяющий открыть файл и выполнить описанную проверку. Как результат он возвращает итератор по непросмотренным строкам лога. Для создания объекта передаём путь файла и опционально смещение и значение строки, на которой мы закончили чтение. Выглядит это так:
import sys
from cutthelog import CutTheLog
ctl = CutTheLog('/var/log/syslog', offset=7777, last_line=b'...')
with ctl as line_iter:
print('Starting at:', ctl.get_position(), end='', file=sys.stderr)
for line in line_iter:
print(line.decode(), end='')
print('Ending at:', ctl.get_position(), end='', file=sys.stderr)Строки лога имеют тип bytes, так как даже на моей дескпотной убунте в логе /var/log/syslog есть символы, которые нельзя декодировать в юникод. Каждая строка возвращённая итератором, обновляет позицию внутри объекта. Значит, мы можем читать произвольное количество строк, а не только до конца файла. В классе есть методы для сохранения позиции в кеш на диске и чтения её оттуда.
Модуль сам по себе является утилитой командной строки. Она выводит на консоль содержимое файла, сохраняя позицию его конца в кеше. При следующем запуске печатаются только строки, которые были записаны после предыдущего чтения. Выглядит это так:
$ echo -e "one\ntwo\nthree" > example
$ cutthelog example
one
two
three
$ cutthelog example
$ echo -e "four\nfive\nsix" >> example
$ cutthelog example
four
five
six
$ cutthelog example
$ echo -e "seven\neight\nnine\nten\neleven\ntwelve" > example
$ cutthelog example
seven
eight
nine
ten
eleven
twelveКеш хранится в файле .cutthelog в домашней директории пользователя. Запуск под другим пользователем выведет файл полностью. Путь до кеша можно задать вручную опцией -c/--cache-file.
Код модуля находится на github. Python пакет доступен на pypi. Надеюсь, они будут вам полезны.
Комментарии (19)
dyadyaSerezha
00.00.0000 00:00По-моему проблема высосана из пальца, хотя, может, и в случае автора она актуальна. Но в большинстве случаев каждая запись в логе имееи таймстэмп и в логах всегда ищется место по времени инцидента и дальше смотрится, что было непосредственно перед этим. Зачем мне смотреть с последнего просмотренного места? Там гигабайты и гигабайты новых логов!
yaznahar Автор
00.00.0000 00:00Например, чтобы узнавать о проблеме до того, как её заметять пользователи и случится инцидент. Фоновый мониторинг логов на типовые записи о проблемах – стандартная практика.
dyadyaSerezha
00.00.0000 00:00Согласен, но там этим занят специальный сервис (из коробки или свой), и если он падает, то при перезауске просто продолжает мониторить с конца лога (если свой). Перезапустить сервис - секунды. Делается это тоже автоматически.
А еще лучше, как привильно нааисали ниже, просто использовать нормальную систему хранения и обработки логов. Их действительно много.
dph
00.00.0000 00:00+2А зачем вообще руками смотреть логи, да еще и запоминать позицию? Вроде бы уже XXI век, для постоянной работы с логами есть куча утилит и стоит пользоваться именно ими.
yaznahar Автор
00.00.0000 00:00-1Допустим, мы хотим добавить оповещение, если количество ошибок в логе за фиксированный интервал времени превысило порог. Для этого мы сначала кешируем конец лог файла:
$ cutthelog logfile > /dev/nullа потом добавляем в cron вызов такого однострочника с нужным интервалом
[ $(cutthelog logfile | grep "some error" | wc -l) -ge ${THRESHOLD} ] && echo "ALARM"Теперь расскажите, как можно решить эту задачу с помощью вашей кучи утилит.
dph
00.00.0000 00:00+5Э, нет конечно. Мы просто вешаем алерт на систему логгинга (которых бесконечное количество на любой вкус). И делаем это без каких-либо операций с продакшен-системой (типа добавления однострочников), крона и так далее.
В стандартном стеке это делается в несколько кликов в графане. Она при этом еще и письмо пришлет или в телегу напишет.
Ну вот серьезно, уже XXI век на дворе, откуда эти идеи времен "приходящих виндовс-админов"?yaznahar Автор
00.00.0000 00:00Чтобы навесить алерт в графане туда должна прилетать метрика с хоста. Чтобы метрика прилетала, на хосте должен работать собирающий её агент. Чтобы посчитать метрику за прошедший интервал, агент должен открыть лог файл, найти место, где закончил читать его в про... oh, wait!.. так вот же код агента:
echo "stats.${HOSTNAME}.metric_name $(cutthelog logfile | grep "some error" | wc -l) $(date +%s)" | nc ${GRAPHITE} ${GRAPHITE_PORT}Даже в XXII веке утилита и cron будут актуальны. Все логи будут отправлять в ChatGPT бот, чтобы он разобрался, что делать:
cutthelog logfile | send_to_chatgpt_botdph
00.00.0000 00:00Нет, зачем там метрика с хоста? Достаточно метрики на основании запроса в систему логов, так все и делают обычно.
dph
00.00.0000 00:00Кстати, yaznahar, а вы действительно не знаете про современные подходы к observability?
Про системы сбора и хранения метрик, про системы сбора и хранения логов, про разделение метрик, логов и трейсов, про алертинги, про концепцию сайдкаров, про изоляцию продакшена от админов и разработчиков, про контейнеризацию и так далее и так далее?
Пост действительно выглядит как пришедший из прошлого тысячелетия.yaznahar Автор
00.00.0000 00:00Действительно слышал про все эти системы сбора и хранения метрик только краем уха, потому что на масштабах, с которыми работаю, они превращаются в тыкву, и нужно придумывать что-то своё.
dph
00.00.0000 00:00Хм, они нормально работают от масштабов "один маленький сервер в чужом облаке" и до масштабов Гугла. А у тебя какой масштаб?
yaznahar Автор
00.00.0000 00:00Больше десяти тысяч серверов. Завидую твоей осведомлённости о том, как всё работает у Гугла.
dph
00.00.0000 00:00На 10000 серверах на каждом есть пайтон для запуска скриптов, написанных разработчиком? И к каждому с доступом на выполнение скриптов? И с логами, которые пишутся в файлы?
Я не верю )
miga
У меня есть одна утилитка с альтернативным подходом - тейлить логи за последние N секунд. Логи-то отсортированы, содержат таймстамп так что бинарный поиск нужного места - весьма дешев.
yaznahar Автор
Подход действильно альтернитивный, но непонятно, чем он лучше) Зато понятно, чем хуже. Форматы таймспампа в логах разных приложений могут сильно отличаться: там может отсутствовать года, там могут присутствовать нелатинские буквы. Написать универсальный парсер для всего этого, та ещё задачка...
miga
Форматы таймстампа действительно могут быть разные и утилитка это умеет. А парсер для форматов называется strptime(3) и он уже давно написан :)
А использовалась утилитка в дремучие времена до структурированных логов и всяких логстешей, когда метрики не слались самими приложениями, а парсились из их логов