system.query_log: анализ медленных запросов

EXPLAIN помогает анализировать запросы до их выполнения. Но для ретроспективного анализа — “какой запрос потребил 20 GB RAM вчера в 3:00?” — нужен другой инструмент: system.query_log. Эта системная таблица содержит детальную запись каждого выполненного запроса: время, продолжительность, использование памяти, прочитанные строки, а также вектор ProfileEvents с сотнями диагностических метрик.

Типы записей в query_log

Топ-10 запросов по использованию памяти

Основной паттерн для поиска resource-heavy запросов:

SELECT
    type,
    event_time,
    initial_query_id,
    formatReadableSize(memory_usage) AS memory,
    ProfileEvents['UserTimeMicroseconds'] AS userCPU,
    ProfileEvents['SystemTimeMicroseconds'] AS systemCPU,
    normalizedQueryHash(query) AS normalized_hash,
    query
FROM system.query_log
WHERE type = 'QueryFinish'
ORDER BY memory_usage DESC
LIMIT 10;

formatReadableSize() преобразует байты в читаемый формат: 2.34 GiB. normalizedQueryHash() создаёт хеш нормализованного запроса — параметры заменяются плейсхолдерами, поэтому SELECT ... WHERE id = 1 и SELECT ... WHERE id = 2 дадут одинаковый хеш.

Медленные запросы за последний час

SELECT
    query_duration_ms,
    formatReadableSize(memory_usage) AS memory,
    read_rows,
    tables,
    query
FROM system.query_log
WHERE event_time >= now() - INTERVAL 60 MINUTE
  AND type = 'QueryFinish'
ORDER BY query_duration_ms DESC
LIMIT 5;

Поле tables содержит массив таблиц, задействованных в запросе. Полезно для быстрой фильтрации: WHERE has(tables, 'db.my_table').

Группировка по normalizedQueryHash

Для выявления повторяющихся тяжёлых паттернов используйте группировку по нормализованному хешу:

SELECT
    normalizedQueryHash(query) AS hash,
    count() AS executions,
    avg(query_duration_ms) AS avg_duration_ms,
    max(memory_usage) AS max_memory,
    formatReadableSize(avg(memory_usage)) AS avg_memory,
    any(query) AS sample_query
FROM system.query_log
WHERE type = 'QueryFinish'
  AND event_time >= now() - INTERVAL 1 DAY
GROUP BY hash
ORDER BY avg_duration_ms DESC
LIMIT 10;

Этот запрос находит паттерны запросов (например, “все SELECT по таблице orders с WHERE по дате”), выполняющиеся тысячи раз в день. Оптимизация одного паттерна — индекс или переписывание — может устранить 90% нагрузки.

Запросы потребляющие более 1 GB памяти

SELECT
    event_time,
    user,
    formatReadableSize(memory_usage) AS memory,
    query_duration_ms,
    read_rows,
    query
FROM system.query_log
WHERE type = 'QueryFinish'
  AND memory_usage > 1e9
  AND event_time >= now() - INTERVAL 1 DAY
ORDER BY memory_usage DESC;

Кластерный анализ через clusterAllReplicas

На кластере query_log ведётся локально на каждом сервере. Для агрегации со всех нод используйте clusterAllReplicas():

SELECT
    hostname(),
    count() AS queries,
    avg(query_duration_ms) AS avg_ms,
    formatReadableSize(max(memory_usage)) AS max_memory
FROM clusterAllReplicas(default, system.query_log)
WHERE type = 'QueryFinish'
  AND event_time >= now() - INTERVAL 1 HOUR
GROUP BY hostname()
ORDER BY avg_ms DESC;

Это позволяет сравнить нагрузку между узлами кластера и выявить горячие шарды.

ProfileEvents: ключевые метрики

Поле ProfileEvents содержит Map(String, UInt64) с сотнями диагностических счётчиков. Наиболее полезные:

-- Запросы с высокой долей системного времени CPU (I/O-intensive)
SELECT
    query,
    ProfileEvents['UserTimeMicroseconds'] AS user_us,
    ProfileEvents['SystemTimeMicroseconds'] AS sys_us,
    round(ProfileEvents['SystemTimeMicroseconds'] * 100.0 /
          (ProfileEvents['UserTimeMicroseconds'] + ProfileEvents['SystemTimeMicroseconds'] + 1)) AS sys_pct
FROM system.query_log
WHERE type = 'QueryFinish'
  AND event_time >= now() - INTERVAL 1 HOUR
ORDER BY sys_pct DESC
LIMIT 5;

Ключевые выводы

1. Всегда добавляйте WHERE type = 'QueryFinish' — без этого фильтра строк будет в 2-4 раза больше из-за QueryStart и Exception-записей.
2. normalizedQueryHash(query) позволяет группировать запросы с разными параметрами по единому паттерну — это главный инструмент для идентификации повторяющихся тяжёлых паттернов.
3. formatReadableSize(memory_usage) делает вывод читаемым: байты превращаются в GiB.
4. ProfileEvents['UserTimeMicroseconds'] и SystemTimeMicroseconds разделяют CPU-time между пользовательским и системным пространством — высокий sys_pct указывает на I/O-bottleneck.
5. clusterAllReplicas(default, system.query_log) объединяет данные со всех узлов кластера в одном запросе.