Розробляємо найзручніший у світі* інтерфейс для перегляду логів

Розробляємо найзручніший у світі* інтерфейс для перегляду логів Якщо Вам доводилося коли-небудь користуватися веб-інтерфейсами для перегляду логів, то Ви напевно помічали, наскільки, як правило, ці інтерфейси громіздкі і (часто) не дуже зручні та чуйні. До деяких можна звикнути, деякі зовсім жахливі, але, як на мене, причина всіх проблем полягає в тому, що ми неправильно підходимо до завдання перегляду логів: ми намагаємося створити веб-інтерфейс там, де краще працює CLI (інтерфейс командного рядка). Мені особисто дуже комфортно працювати з tail, grep, awk та іншими, і тому для мене ідеальним інтерфейсом для роботи з логами було б щось аналогічне tail і grep, але яке при цьому можна було використовувати для читання логів, які прийшли з багатьох серверів . Тобто, звичайно ж, читати їх із ClickHouse!

*на особисту думку хабракористувача youROCK

Зустрічайте logscli

Я не придумав назви своєму інтерфейсу, і, чесно кажучи, він швидше існує у вигляді прототипу, але якщо Ви хочете відразу подивитися вихідники, то ласкаво просимо: https://github.com/YuriyNasretdinov/logscli (350 рядків відбірного коду Go).

можливості

Я ставив собі за мету зробити інтерфейс, який здаватиметься знайомим тим, хто звик до tail/grep, тобто підтримувати такі речі:

  1. Перегляд усіх логів без фільтрації.
  2. Залишити рядки, в яких міститься фіксований підрядок (прапор) -F у grep).
  3. Залишити рядки, що підходять під регулярний вираз (прапор) -E у grep).
  4. За промовчанням перегляд у зворотному хронологічному порядку, оскільки зазвичай насамперед цікаві найсвіжіші логи.
  5. Показ контексту біля кожного рядка (параметри -A, -B и -C у grep, що друкують N рядків до, після, і навколо кожного рядка, що збігається відповідно).
  6. Перегляд логів, що надходять, в режимі реального часу, з фільтрацією і без (по суті tail -f | grep).
  7. Інтерфейс повинен бути сумісний з less, head, tail та іншими – за умовчанням мають повертатися результати без обмежень за їх кількістю; рядки друкуються потоково доти, доки користувач зацікавлений у їх отриманні; сигнал SIGPIPE повинен мовчки переривати стримінг логів, також, як це роблять tail, grep та інші UNIX-утиліти.

Реалізація

Я припускатиму, що ви вже якимось чином вмієте доставляти логи до ClickHouse. Якщо ні, то рекомендую спробувати LsD и kittenhouse, а також цю статтю про доставку логів.

Для початку необхідно визначитися зі схемою бази. Оскільки логи зазвичай хочеться отримувати відсортованими за часом, то є логічним так їх і зберігати. Якщо категорій логів багато і всі однотипні, то можна як першу колонку первинного ключа зробити категорію логів — це дозволить мати одну таблицю замість кількох, що при вставці в ClickHouse буде великим плюсом (на серверах з жорсткими дисками рекомендується вставляти дані не частіше. рази на секунду на весь сервер).

Тобто, нам потрібна приблизно така схема таблиць:

CREATE TABLE logs(
    category LowCardinality(String), -- категория логов (опционально)
    time DateTime, -- время события
    millis UInt16, -- миллисекунды (могут быть и микросекунды, и т.д.): рекомендуется хранить, если событий много, чтобы было легче различать события между собой
    ..., -- ваши собственные поля, например имя сервера, уровень логирования, и так далее
    message String -- текст сообщения
) ENGINE=MergeTree()
ORDER BY (category, time, millis)

На жаль, я не зміг відразу знайти якихось відкритих джерел з реалістичними логами, які можна було б взяти і завантажити, тому я взяв натомість для прикладу відгуки від товарів з Amazon до 2015 року. Безумовно, їхня структура не зовсім така сама, як у текстових логів, але для ілюстрації це не принципово.

інструкція із заливання відгуків 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, їй приходить сигнал SIGPIPE, який за замовчуванням мовчки завершує програму.

У 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 за адресою https://github.com/YuriyNasretdinov/logscli. Радий почути Ваші думки з приводу моєї ідеї для консольного інтерфейсу для перегляду логів на основі ClickHouse.

Джерело: habr.com

Додати коментар або відгук