Если Вам приходилось когда-нибудь пользоваться веб-интерфейсами для просмотра логов, то Вы наверняка замечали, насколько, как правило, эти интерфейсы громоздки и (зачастую) не слишком-то удобны и отзывчивы. К некоторым можно привыкнуть, некоторые совсем ужасны, но, как мне кажется, причина всех проблем заключается в том, что мы неправильно подходим к задаче просмотра логов: мы пытаемся создать веб-интерфейс там, где лучше работает CLI (интерфейс командной строки). Мне лично очень комфортно работать с tail, grep, awk и прочими, и поэтому для меня идеальным интерфейсом для работы с логами было бы что-то аналогичное tail и grep, но которое при этом можно было использовать для чтения логов, которые пришли с множества серверов. То есть, конечно же, читать их из ClickHouse!
*по личному мнению хабрапользователя
Встречайте logscli
Я не придумал названия своему интерфейсу, и, сказать честно, он скорее существует в виде прототипа, но если Вы хотите сразу посмотреть исходники, то добро пожаловать: (350 строк отборного кода на Go).
Возможности
Я ставил перед собой цель сделать интерфейс, который будет казаться знакомым тем, кто привык к tail/grep, то есть поддерживать следующие вещи:
- Просмотр всех логов, без фильтрации.
- Оставить строки, в которых содержится фиксированная подстрока (флаг
-Fуgrep). - Оставить строки, подходящие под регулярное выражение (флаг
-Eуgrep). - По умолчанию просмотр в обратном хронологическом порядке, поскольку обычно в первую очередь интересны самые свежие логи.
- Показ контекста возле каждой строки (параметры
-A,-Bи-Cуgrep, печатающие N строк до, после, и вокруг каждой совпадающей строки соответственно). - Просмотр поступающих логов в режиме реального времени, с фильтрацией и без (по сути
tail -f | grep). - Интерфейс должен быть совместим с
less,head,tailи прочими — по умолчанию должны возвращаться результаты без ограничений по их количеству; строки печатаются потоково до тех пор, пока пользователь заинтересован в их получении; сигналSIGPIPEдолжен молча прерывать стриминг логов, также, как это делаютtail,grepи остальные UNIX-утилиты.
Реализация
Я буду предполагать, что вы уже каким-то образом умеете доставлять логи до ClickHouse. Если нет, то рекомендую попробовать и , а также .
Для начала нужно определиться со схемой базы. Поскольку логи обычно хочется получать отсортированными по времени, то представляется логичным так их и хранить. Если категорий логов много и они все однотипные, то можно в качестве первой колонки первичного ключа сделать категорию логов — это позволит иметь одну таблицу вместо нескольких, что при вставке в ClickHouse будет большим плюсом (на серверах с жёсткими дисками рекомендуется вставлять данные не чаще ~1 раза в секунду на весь сервер).
То есть, нам нужна примерно следующая схема таблиц:
CREATE TABLE logs(
category LowCardinality(String), -- категория логов (опционально)
time DateTime, -- время события
millis UInt16, -- миллисекунды (могут быть и микросекунды, и т.д.): рекомендуется хранить, если событий много, чтобы было легче различать события между собой
..., -- ваши собственные поля, например имя сервера, уровень логирования, и так далее
message String -- текст сообщения
) ENGINE=MergeTree()
ORDER BY (category, time, millis)К сожалению, я не смог сразу найти каких-либо открытых источников с реалистичными логами, которые можно было бы взять и скачать, поэтому я взял вместо этого для примера . Безусловно, их структура не совсем такая же, как у текстовых логов, но для иллюстрации это не принципиально.
инструкция по заливке отзывов Amazon в ClickHouse
Создадим таблицу:
CREATE TABLE amazon(
review_date Date,
time DateTime DEFAULT toDateTime(toUInt32(review_date) * 86400 + rand() % 86400),
millis UInt16 DEFAULT rand() % 1000,
marketplace LowCardinality(String),
customer_id Int64,
review_id String,
product_id LowCardinality(String),
product_parent Int64,
product_title String,
product_category LowCardinality(String),
star_rating UInt8,
helpful_votes UInt32,
total_votes UInt32,
vine FixedString(1),
verified_purchase FixedString(1),
review_headline String,
review_body String
)
ENGINE=MergeTree()
ORDER BY (time, millis)
SETTINGS index_granularity=8192В датасете Амазона есть только дата для отзыва, но нет точного времени, поэтому заполним эти данные рандоном.
Можно не скачивать все tsv-файлы и ограничиться первыми ~10-20, чтобы уже получить достаточно большой набор данных, который не влезет в 16 Гб оперативной памяти. Для заливки TSV-файлов я использовал следующую команду:
for i in *.tsv; do
echo $i;
tail -n +2 $i | pv |
clickhouse-client --input_format_allow_errors_ratio 0.5 --query='INSERT INTO amazon(marketplace,customer_id,review_id,product_id,product_parent,product_title,product_category,star_rating,helpful_votes,total_votes,vine,verified_purchase,review_headline,review_body,review_date) FORMAT TabSeparated'
doneНа стандартном Persistent Disk (который HDD) в Google Cloud размером в 1000 Гб (такой размер я взял в основном для того, чтобы скорость была чуть выше, хотя, возможно SSD нужного объема вышел бы дешевле) скорость заливки составила примерно ~75 Мб/сек на 4 ядрах.
- должен оговориться, что я работаю в Google, но я использовал личный аккаунт и эта статья к моей работе в компании отношения не имеет
Все иллюстрации я буду производить именно с этим датасетом, поскольку это всё, что у меня было под рукой.
Показ прогресса сканирования данных
Поскольку в ClickHouse мы будем использовать full scan по таблице с логами, а эта операция может занимать существенное время и долго не отдавать никаких результатов, если совпадений найдено мало, желательно уметь показывать прогресс выполнения запроса до получения первых строк с результатом. Для этого в HTTP-интерфейсе есть параметр, позволяющий отдавать прогресс в заголовках HTTP: send_progress_in_http_headers=1. К сожалению, стандартная библиотека Go не умеет читать заголовки по мере их получения, но интерфейс HTTP 1.0 (не путайте с 1.1!) поддерживается ClickHouse, поэтому можно открыть сырое TCP-соединение с ClickHouse, послать туда GET /?query=... HTTP/1.0nn и получить в ответ заголовки и тело ответа без какого-либо экранирования и шифрования, так что нам в этом случае стандартную библиотеку использовать даже не требуется.
Стриминг логов из ClickHouse
В ClickHouse уже относительно давно (с 2019 года?) есть оптимизация для запросов с ORDER BY, так что запрос вида
SELECT time, millis, message
FROM logs
WHERE message LIKE '%something%'
ORDER BY time DESC, millis DESCНачнет сразу возвращать строки, у которых в message есть подстрока "something", не дожидаясь окончания сканирования.
Также, было бы очень удобно, если бы ClickHouse сам отменял запрос, когда с ним закрыли соединение, но это не является поведением по умолчанию. Автоматическую отмену запроса можно включить опцией cancel_http_readonly_queries_on_client_close=1.
Корректная обработка SIGPIPE в Go
Когда Вы выполняете, скажем, команду some_cmd | head -n 10, каким именно образом команда some_cmd прекращает свое исполнение, когда head вычитал 10 строк? Ответ прост: когда head завершается, pipe закрывается, и stdout команды some_cmd начинает указывать, условно, «вникуда». Когда some_cmd пытается записать в закрытый pipe, .
В Go по умолчанию это тоже происходит, но обработчик сигнала SIGPIPE в конце также печатает "signal: SIGPIPE" или похожее сообщение, и чтобы это сообщение убрать, нужно просто самому обработать SIGPIPE так, как мы хотим, то есть просто молча выйти:
ch := make(chan os.Signal)
signal.Notify(ch, syscall.SIGPIPE)
go func() {
<-ch
os.Exit(0)
}()Показ контекста сообщения
Часто хочется увидеть контекст, в котором произошла какая-то ошибка (например, какой запрос вызвал панику, или какие сопутствующие проблемы были видны до падения), и в grep для этого служат опции -A, -B и -C, которые показывают указанное число строк после, до, и вокруг сообщения соответственно.
К сожалению, я не нашел простого способа сделать то же самое в ClickHouse, поэтому, для отображения контекста, на каждую строчку результата посылается дополнительный запрос примерно следующего вида (детали зависят от сортировки и от того, показывается контекст до или после):
SELECT time,millis,review_body FROM amazon
WHERE (time = 'ВРЕМЯ_СОБЫТИЯ' AND millis < МИЛЛИСЕКУНДЫ_СОБЫТИЯ) OR (time < 'ВРЕМЯ_СОБЫТИЯ')
ORDER BY time DESC, millis DESC
LIMIT КОЛИЧЕСТВО_СТРОК_КОНТЕКСТА
SETTINGS max_threads=1Поскольку запрос посылается почти сразу после того, как ClickHouse вернул соответствующую строку, она попадает в кеш и в целом запрос выполняется достаточно быстро и тратит немножко CPU (обычно запрос занимает около ~6 мс на моей виртуалке).
Показ новых сообщений в режиме реального времени
Для того, чтобы показывать приходящие сообщения в режиме (почти) реального времени, просто исполняем запрос раз в несколько секунд, запомнив последний timestamp, который мы встретили до этого.
Примеры команд
Как выглядят типичные команды logscli на практике?
Если Вы загрузили датасет Amazon, который я упоминал в начале статьи, то сможете выполнить следующие команды:
# Показать строки, где встречается слово walmart
$ logscli -F 'walmart' | less
# Показать самые свежие 10 строк, где встречается "terrible"
$ logscli -F terrible -limit 10
# То же самое без -limit:
$ logscli -F terrible | head -n 10
# Показать все строки, подходящие под /times [0-9]/, написанные для vine и у которых высокий рейтинг
$ logscli -E 'times [0-9]' -where="vine='Y' AND star_rating>4" | less
# Показать все строки со словом "panic" и 3 строки контекста вокруг
$ logscli -F 'panic' -C 3 | less
# Непрерывно показывать новые строки со словом "5-star"
$ logscli -F '5-star' -tailfСсылки
Код утилиты (без документации) доступен на github по адресу . Буду рад услышать Ваши мысли по поводу моей идеи для консольного интерфейса для просмотра логов на основе ClickHouse.
Источник: habr.com