Ищем проблемный запрос в ClickHouse

Если CPU на пределе, память почти закончилась, а запросы тормозят, то самое время искать виноватого. О том, как это сделать хорошо рассказывает автор статьи на хабре: CPU 80%. Как найти проблемный запрос в ClickHouse? Я оставила важные моменты и дополнила нюансами, которых мне не хватило.

Начинаем с того, что смотрим, что выполняется прямо сейчас:

SELECT
    query_id,
    user,
    elapsed,
    formatReadableSize(memory_usage) AS ram,
    formatReadableSize(read_bytes)   AS read_size,
    read_rows,
    query
FROM system.processes
ORDER BY elapsed DESC;

system.processes содержит активные запросы, их длительность, память и чтения. Если запрос явно лишний, его можно остановить через:

-- ASYNC (по умолчанию) — команда вернётся сразу, запрос остановится чуть позже
KILL QUERY WHERE query_id = 'xxx' ASYNC;

-- SYNC — ждёт фактической остановки запроса
KILL QUERY WHERE query_id = 'xxx' SYNC;

Но KILL QUERY требует либо права KILL QUERY у пользователя, либо чтобы запрос принадлежал ему самому, иначе получите ошибку.

За анализом завершённых запросов идём в system.query_log. Чтобы получить свежие данные, предварительно можно выполнить:

SYSTEM FLUSH LOGS;

Важно помнить, что query_log локален для каждого узла. На кластере нужно смотреть на каждом узле отдельно или использовать clusterAllReplicas:

SELECT *
FROM clusterAllReplicas('your_cluster', system.query_log)
WHERE event_date >= today()
  AND type = 'QueryFinish'
ORDER BY query_duration_ms DESC
LIMIT 20;

Ищем виновников среди пользователей и хостов:

SELECT
    user,
    client_hostname,
    count()                                      AS queries,
    round(sum(query_duration_ms) / 1000, 1)      AS total_sec,
    formatReadableSize(sum(read_bytes))          AS total_read
FROM system.query_log
WHERE event_date >= today()
  AND type = 'QueryFinish'
GROUP BY user, client_hostname
ORDER BY total_sec DESC
LIMIT 10;

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

Для поиска конкретно тяжелых запросов сортируем по нужной метрике в зависимости от симптома: query_duration_ms, memory_usage, read_bytes или CPU:

SELECT
    query_id,
    user,
    query_duration_ms / 1000                                      AS duration_sec,
    formatReadableSize(memory_usage)                              AS ram,
    formatReadableSize(read_bytes)                                AS read_size,
    read_rows,
    ProfileEvents['OSCPUVirtualTimeMicroseconds'] / 1e6           AS cpu_sec,
    query
FROM system.query_log
WHERE event_date >= today()
  AND type = 'QueryFinish'
ORDER BY memory_usage DESC   -- меняем на нужную метрику
LIMIT 20;

При этом стоит знать про значения поля type, это поможет при отладке не только медленных, но и падающих запросов:
⭐️QueryStart -> Запрос начался
⭐️QueryFinish -> Успешно завершился
⭐️ExceptionBeforeStart -> Ошибка до старта
⭐️ExceptionWhileProcessing -> Ошибка в процессе

Для поиска падающих запросов:

WHERE type IN ('ExceptionBeforeStart', 'ExceptionWhileProcessing')

Для профилактики появления проблемных запросов полезно использовать:

EXPLAIN indexes = 1
SELECT ... -- подозрительный запрос

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

EXPLAIN PIPELINE
SELECT ...;

Еще один уровень защиты - это пользовательские ограничения на уровне профиля или отдельного пользователя. Они не дают одному запросу положить весь кластер:

max_execution_time = 60          -- максимум 60 секунд на запрос
max_memory_usage = 10000000000   -- максимум ~10 GB RAM на запрос
max_rows_to_read = 1000000000    -- максимум 1 млрд строк

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