ClickHouse 慢查询：如何从 system.query_log 找出高频慢查询模式并查看资源消耗-港品优选

ClickHouse 慢查询：如何从 system.query_log 找出高频慢查询模式并查看资源消耗

【免费下载链接】ClickHouseClickHouse® is a real-time analytics database management system项目地址: https://gitcode.com/GitHub_Trending/cli/ClickHouse

生产库上某些查询变慢，但只看单次执行结果很难判断：是某类查询模式反复慢，还是一次偶发慢查询？ClickHouse 默认会把已完成查询的时长、读取行数、内存与缓存活动记录到system.query_log表，这为定位问题提供了证据来源。本文的目标是：按normalized_query_hash把反复出现的慢查询模式从日志里分组出来，挑出一次有代表性的运行核对它的资源消耗，再用EXPLAIN查看该查询的执行计划，在改查询或改表结构之前先形成瓶颈假设。

前提：ClickHouse 把已完成查询写入system.query_log；集群部署下日志数据保存在每个节点本地。示例基于nyc_taxi.trips_small_inferred表（一个约 5.8 GB 的 Parquet 文件推断出的表，含约 3.29 亿行），诊断自己负载时把它换成你的库和表即可。

准备：让 query_log 里有可分析的已完成运行

system.query_log只在查询执行结束后落盘，所以分析前要先确保日志里有目标时间段内、状态为成功完成的运行记录。

示例文档约定：先创建并加载示例数据集，然后把三个基线工作负载查询各运行至少两次，再强制刷新日志：

SYSTEM FLUSH LOGS;

如果你没有权限执行SYSTEM FLUSH LOGS，就等日志自动刷新（刷新周期由服务器配置query_log段的flush_interval_milliseconds控制），再重试第一步的查询。诊断自己的负载时，确保system.query_log里包含你打算检查的时间范围内、已完成运行的记录。

如果还没有这张表，示例数据集的建表语句如下（源 Parquet 文件约 5.8 GB，加载耗时取决于网络与资源）：

CREATE DATABASE IF NOT EXISTS nyc_taxi; USE nyc_taxi; CREATE TABLE nyc_taxi.trips_small_inferred ORDER BY () EMPTY AS SELECT * FROM s3( 'https://datasets-documentation.s3.eu-west-3.amazonaws.com/nyc-taxi/clickhouse-academy/nyc_taxi_2009-2010.parquet', NOSIGN, Parquet ); INSERT INTO nyc_taxi.trips_small_inferred SELECT * FROM s3( 'https://datasets-documentation.s3.eu-west-3.amazonaws.com/nyc-taxi/clickhouse-academy/nyc_taxi_2009-2010.parquet', NOSIGN, Parquet );

三个基线工作负载查询（本文后续步骤会用到它们产生的日志）：

-- 1) 计算车速后再过滤 WITH dateDiff('s', pickup_datetime, dropoff_datetime) AS trip_time, (trip_distance / trip_time) * 3600 AS speed_mph SELECT quantiles(0.5, 0.75, 0.9, 0.99)(trip_distance) FROM nyc_taxi.trips_small_inferred WHERE speed_mph > 30 FORMAT JSON; -- 2) 日期范围内的聚合 SELECT payment_type, count() AS trip_count, formatReadableQuantity(sum(trip_distance)) AS total_distance, avg(total_amount) AS total_amount_avg, avg(tip_amount) AS tip_amount_avg FROM nyc_taxi.trips_small_inferred WHERE pickup_datetime >= '2009-01-01' AND pickup_datetime < '2009-04-01' GROUP BY payment_type ORDER BY trip_count DESC; -- 3) 按乘客数过滤 SELECT avg(dateDiff('s', pickup_datetime, dropoff_datetime)) FROM nyc_taxi.trips_small_inferred WHERE passenger_count = 1 OR passenger_count = 2 FORMAT JSON;

如果目标是记录可重复比较的时长，文档建议在同一会话里先关掉文件系统缓存、查询缓存和查询条件缓存（SET enable_filesystem_cache = 0; SET use_query_cache = 0; SET use_query_condition_cache = 0;），测量结束后恢复原值；本场景只需日志里有代表性运行，这一步可选。

集群与单节点的差异

集群上查询日志不集中，而是留在各节点本地，所以集群版查询用clusterAllReplicas覆盖所有副本，并用merge('system', '^query_log')同时纳入当前的system.query_log表以及系统表 schema 变更后保留的版本化query_log_N表。ClickHouse Cloud 提供示例里用到的default集群；自管理部署下，把default替换为system.clusters中列出的集群名。

下面的 SQL 都会设置skip_unavailable_shards = 1：当某个副本临时不可用时，诊断查询不会因此失败（自动扩缩容期间尤其有用）。代价是被跳过副本的记录不会计入，结果可能不完整。

第一步：按 normalized_query_hash 找出高频慢查询模式

normalized_query_hash对仅字面量取值不同的查询相同，按它分组能把"反复出现的模式"和"某一次慢执行"分开。下面这条查询把最近一小时的初始 SELECT 查询按模式分组，按中位时长排序，并给出每个模式的执行次数、读取量、峰值内存和一条示例查询。

单节点版（主路径）：

SELECT normalized_query_hash, count() AS executions, quantile(0.5)(query_duration_ms) AS median_duration_ms, max(query_duration_ms) AS max_duration_ms, formatReadableSize(avg(read_bytes)) AS avg_read_bytes, formatReadableSize(max(memory_usage)) AS max_memory, any(query) AS example_query FROM merge('system', '^query_log') WHERE type = 'QueryFinish' AND is_initial_query = 1 AND query_kind = 'Select' AND event_time >= now() - INTERVAL 1 HOUR AND has(databases, 'nyc_taxi') GROUP BY normalized_query_hash HAVING executions >= 2 ORDER BY median_duration_ms DESC LIMIT 10

各过滤条件的用途：

type = 'QueryFinish'：只取成功完成的运行，排除启动事件和异常事件。
is_initial_query = 1：排除由其他查询派生的子查询，避免把内部处理步骤单独计数。
query_kind = 'Select'：只看 SELECT。
event_time >= now() - INTERVAL 1 HOUR：检查的时间窗，按你要排查的范围调整。
has(databases, 'nyc_taxi')：限定到某个库；诊断自己的负载时替换成你的库名。
HAVING executions >= 2：只保留至少执行过两次的模式，即"高频"，而不是单次慢执行。

集群版把数据源换成clusterAllReplicas('default', merge('system', '^query_log'))，并在末尾加SETTINGS skip_unavailable_shards = 1，其余相同。

判断方法：executions高、中位时长高、或读取/内存用量高的模式，比单次慢运行更值得调查。query_duration_ms的单位是毫秒。

如果只想快速列出"每个模式最慢的那一次"，可用这条盘点查询（LIMIT 1 BY normalized_query_hash让每个模式只留最慢的一条）：

-- 最近 1 小时内 nyc_taxi 库最慢的已完成运行，每个模式一条 SELECT normalized_query_hash, type, event_time, query_duration_ms, query, read_rows, tables FROM merge('system', '^query_log') WHERE has(databases, 'nyc_taxi') AND event_time >= now() - INTERVAL 1 HOUR AND type = 'QueryFinish' AND is_initial_query = 1 AND query_kind = 'Select' ORDER BY query_duration_ms DESC LIMIT 1 BY normalized_query_hash LIMIT 5 FORMAT VERTICAL

文档示例输出（数值为文档示例，实际以你的负载为准）：

Row 1: ────── normalized_query_hash: 11000678248135956062 type: QueryFinish event_time: 2024-11-27 11:12:36 query_duration_ms: 2967 query: WITH dateDiff('s', pickup_datetime, dropoff_datetime) as trip_time, trip_distance / trip_time * 3600 AS speed_mph SELECT quantiles(0.5, 0.75, 0.9, 0.99)(trip_distance) FROM nyc_taxi.trips_small_inferred WHERE speed_mph > 30 FORMAT JSON read_rows: 329044175 tables: ['nyc_taxi.trips_small_inferred'] Row 2: ────── normalized_query_hash: 4194765292165295011 query_duration_ms: 2026 read_rows: 329044175 Row 3: ────── normalized_query_hash: 1891814463795712754 query_duration_ms: 1860 read_rows: 329044175

文档说明：query_duration_ms字段包含以毫秒计的查询时长；示例中运行最久的查询为 2,967 ms。

如果你更关心"谁最吃资源"而不是"谁最慢"，文档给了另一条按内存排序的查询，附带 CPU 与文件系统缓存活动，可作为可选分支（同样有集群/单节点两版，集群版加clusterAllReplicas与skip_unavailable_shards = 1）：

-- 按内存用量排序的近期查询，并带出 CPU 与缓存读取活动 SELECT type, event_time, query_id, formatReadableSize(memory_usage) AS memory, ProfileEvents.Values[indexOf(ProfileEvents.Names, 'UserTimeMicroseconds')] AS userCPU, ProfileEvents.Values[indexOf(ProfileEvents.Names, 'SystemTimeMicroseconds')] AS systemCPU, (ProfileEvents['CachedReadBufferReadFromCacheMicroseconds']) / 1000000 AS FromCacheSeconds, (ProfileEvents['CachedReadBufferReadFromSourceMicroseconds']) / 1000000 AS FromSourceSeconds, normalized_query_hash FROM merge('system', '^query_log') WHERE has(databases, 'nyc_taxi') AND type = 'QueryFinish' AND is_initial_query = 1 AND query_kind = 'Select' AND event_time >= now() - INTERVAL 2 DAY AND user NOT ILIKE '%internal%' ORDER BY memory_usage DESC LIMIT 30

第二步：选一次代表性运行并核对资源消耗

单次慢运行可能是临时负载或临时查询造成的离群值。选代表时，先看同一个normalized_query_hash下的多次运行，挑一次时长和资源使用都接近该模式典型水平的那次，而不是最慢的那次。

把下面查询里selected_hash的值替换为你在上一步选定模式的normalized_query_hash（文档用123456789占位）：

WITH toUInt64(123456789) AS selected_hash SELECT event_time, query_id, query_duration_ms, read_rows, read_bytes, memory_usage, query FROM merge('system', '^query_log') WHERE type = 'QueryFinish' AND is_initial_query = 1 AND normalized_query_hash = selected_hash AND event_time >= now() - INTERVAL 1 HOUR ORDER BY event_time DESC LIMIT 10

判断步骤：

找read_rows和read_bytes相近的运行。
比较这些运行的query_duration_ms和memory_usage。
选query_duration_ms最接近中位数的那条的query_id。

文档提醒：历史查询日志结果会随缓存状态和系统负载变化，用它来"选一条要调查的查询"，不要用它来比较不同优化改动之间的效果。

如果日志里完成运行不够多，在相近条件下把该查询再跑几次。

核对读取规模是否与表体量匹配，用表行数做参照（文档示例输出）：

SELECT count() FROM nyc_taxi.trips_small_inferred

Query id: 733372c5-deaf-4719-94e3-261540933b23 ┌───count()─┐ 1. │ 329044175 │ -- 329.04 million └───────────┘

表有 3.29 亿行，与候选运行里read_rows报告的数值基本一致，说明这些查询读到了整表的大部分或全部。但这一条还不能回答"为什么读这么多行、这个量是否合理"，需要看执行计划。

第三步：用 EXPLAIN 查看执行计划，定位资源消耗来源

选定代表性运行后，用EXPLAIN在不实际执行查询的情况下查看 ClickHouse 如何规划它。文档示例用"计算车速"那条查询：

EXPLAIN actions = 1, compact = 1, pretty = 1, indexes = 1 WITH dateDiff('s', pickup_datetime, dropoff_datetime) AS trip_time, (trip_distance / trip_time) * 3600 AS speed_mph SELECT quantiles(0.5, 0.75, 0.9, 0.99)(trip_distance) FROM nyc_taxi.trips_small_inferred WHERE speed_mph > 30

输出是一棵操作树，子操作在父操作下方。从最深的读操作开始，向上看数据如何被转换成最终结果。文档示例输出：

Output: quantiles(0.5, 0.75, 0.9, 0.99)(trip_distance) Aggregating │ Aggregates: quantiles(0.5, 0.75, 0.9, 0.99)(trip_distance) └──Filter │ Filter column: trip_distance / dateDiff('s', pickup_datetime, dropoff_datetime) * 3600 > 30 └──ReadFromMergeTree (nyc_taxi.trips_small_inferred)

自底向上对照查询：

ReadFromMergeTree从nyc_taxi.trips_small_inferred读取。此处没有Indexes段，加上read_rows与表行数一致，说明 ClickHouse 读的是整表。
Filter给出speed_mph > 30展开后的表达式：对每一行都要算出行程时长和车速，只保留大于 30 英里/小时的行。
Aggregating对过滤后的trip_distance计算分位数。

据此，文档把这条查询识别出三类可测试的工作来源：读取全部行、在过滤时计算speed_mph、计算分位数。

边界与下一步

system.query_log不保存查询结果，只记录元数据与统计；ClickHouse 不会自动删除其中的数据，记录会累积。
一次成功查询会产生QueryStart和QueryFinish两条记录；出错时是QueryStart加ExceptionWhileProcessing（或仅一条ExceptionBeforeStart），所以"看已完成运行"必须过滤type = 'QueryFinish'。
集群下日志分散在各节点，跨节点分析必须用clusterAllReplicas，且skip_unavailable_shards = 1会让结果不完整。
本文定位到的是"资源消耗来源的候选"。要对这些来源做受控测量、比较不同改法的效果，文档指向下一步隔离查询瓶颈，它用逐渐简化的查询形状来确认哪些操作值得进一步调查。

相关字段含义可对照 system.query_log 参考、EXPLAIN 语句与 cluster/merge 表函数。

【免费下载链接】ClickHouseClickHouse® is a real-time analytics database management system项目地址: https://gitcode.com/GitHub_Trending/cli/ClickHouse

创作声明：本文部分内容由AI辅助生成（AIGC），仅供参考

企业官网建设流程全解析