news 2026/10/30 20:11:32

ClickHouse 慢查询日志剖析:system.query_log 中排查最耗 CPU 语句

作者头像

张小明

前端开发工程师

1.2k 24
文章封面图
ClickHouse 慢查询日志剖析:system.query_log 中排查最耗 CPU 语句

周二早晨刚开完晨会,运维工程师就在告警群里发了一张 CPU 监控曲线截图:ClickHouse 集群的 3 号计算节点从今天凌晨 4 点开始,CPU 使用率笔直拉平在 99.8%,整整持续了四个小时!节点温度报警灯疯狂闪烁,前台业务发起的即席点查全部排队超时,整个节点仿佛掉进了一个无尽的死循环计算旋涡。

业务线的研发第一反应是甩锅:“是不是底层的 MergeTree 正在执行后台大合成分区(Heavy Merge)?或者是系统定时任务在刷物化视图?”

我连上终端,敲下一行命令打开 ClickHouse 原生内置的系统慢查询全景神表——system.query_log。在这张记录了每一个查询从语法解析、管道调度、内存分配到各个线程物理 CPU 消耗细节的宝藏表里,底层真实的执行真相在三秒钟内无所遁形:一条由某自动化爬虫系统发起的全表不带分区下推、且对数千万未压缩字符串执行深度模糊正则匹配(like '%...%')的“流氓 SQL”,一口气霸占了该节点整整 32 个物理线程,单条查询累积空转消耗了超过 460 万毫秒的纯 CPU 时间!

在分布式 OLAP 引擎的运维与架构调优中,脱离system.query_log去排查慢查询,如同蒙着双眼在雷区散步。掌握从数百万条系统事件日志中精准揪出“CPU 吞噬兽”的高阶剖析技术,是每一位数仓专家守护集群平稳运行的看家本领。


一、 走进底层神表:system.query_log 的运作机制与核心字段

很多工程师只知道 ClickHouse 有日志,但不知道这些日志是如何产生的。在 ClickHouse 内部,每一次查询的生命周期都会触发状态变更事件,并异步批量写入物理系统表system.query_log(其底层由普通 MergeTree 引擎驱动)。

想要精准锁定 CPU 杀手,必须吃透以下八个最硬核的核心度量字段:

+-------------------------------------------------------------+ | system.query_log 核心物理诊断字段矩阵 | +-------------------------------------------------------------+ | 1. ProfileEvents['OSCPUVirtualTimeMicroseconds'] (核心杀招) | | -> 操作系统层级度量的微秒级真实用户态 CPU 耗时 | | 2. query_duration_ms: 查询从发起到结束的物理自然流逝时钟 (毫秒) | | 3. ProfileEvents['RealTimeMicroseconds']: 真实流逝微秒 | | 4. read_rows / read_bytes: 物理从磁盘/缓存中扫描的数据行与字节| | 5. memory_usage: 查询峰值瞬间所吞噬的物理 RAM 字节数 | | 6. type: 查询状态 (QueryFinish 正常完成, ExceptionWhile... 报错)| | 7. exception_code: 异常退出错误码 (如超内存、超时) | | 8. initial_query_id / query_id: 全局链路追踪分布式唯一定位符 | +-------------------------------------------------------------+
为什么不能只看query_duration_ms(执行时间)?

一条查询耗时 10 秒,可能只是因为网络传输慢,或者在等待全局锁,CPU 实际上一直在睡觉(I/O 阻塞或线程挂起);而另一条查询虽然只跑了 3 秒,但它瞬间调用了 64 个 CPU 核心跑满运算,其实际消耗的 CPU 算力是前者的数十倍!因此,排查 CPU 瓶颈必须以 CPU 核心真实消耗时间(CPU Time)为唯一黄金判定标准。


二、 生产级实战诊断:精准定位最耗 CPU 语句的四大黄金 SQL

以下是我们线上排查性能事故时,直接在 ClickHouse 终端粘贴运行的诊断利器:

1. 抓捕今日累积消耗 CPU 时间 Top-5 的“头号恶魔”
SELECT user, query_id, toStartOfMinute(event_time) AS minute_window, query_duration_ms / 1000 AS duration_sec, -- 提取用户态与系统态累积 CPU 耗时 (折算为秒) round(ProfileEvents['OSCPUVirtualTimeMicroseconds'] / 1000000, 2) AS user_cpu_sec, round(ProfileEvents['OSCPUSystemTimeMicroseconds'] / 1000000, 2) AS sys_cpu_sec, formatReadableSize(memory_usage) AS peak_mem, formatReadableSize(read_bytes) AS scanned_disk, read_rows, -- 提取规范化后的 SQL 前 200 字符 normalizeQuery(query) AS normalized_sql FROM system.query_log WHERE event_date = today() AND type = 'QueryFinish' ORDER BY user_cpu_sec DESC LIMIT 5;
2. 计算“CPU 虚耗比”:揪出那些产出极低却极耗算力的低效垃圾查询

有些查询扫了数十亿行,算了大半天,最后只向客户端吐出了 10 行数据,且没有命中任何聚合索引:

SELECT query_id, user, query_duration_ms, read_rows, result_rows, -- 计算每一万行扫描消耗的 CPU 微秒数 (CPU 密度指标) round(ProfileEvents['OSCPUVirtualTimeMicroseconds'] / nullIf(read_rows, 0) * 10000, 2) AS cpu_per_10k_rows, query FROM system.query_log WHERE event_date = today() AND type = 'QueryFinish' AND read_rows > 1000000 ORDER BY cpu_per_10k_rows DESC LIMIT 10;
3. 实时追踪:当前正在集群中疯狂燃烧 CPU 的活跃长查询

如果问题正在发生,必须立刻抓出当前的正在运行态(type = 'QueryStart'且尚未 Finish):

SELECT query_id, user, elapsed, formatReadableSize(memory_usage) AS current_mem, formatReadableSize(read_bytes) AS current_read, query FROM system.processes WHERE is_cancelled = 0 ORDER BY elapsed DESC LIMIT 5;

找到对应的query_id后,若判定为失控查询,可直接执行强制击杀:

KILL QUERY WHERE query_id = 'xxxx-yyyy-zzzz';

三、 深度剖析:从 ProfileEvents 诊断 CPU 暴涨的四大底层根因

当我们定位到了具体的慢 SQL 后,拆开其ProfileEvents字典,往往能一针见血发现 CPU 耗尽的具体原因:

+-------------------------------------------------------------+ | ProfileEvents 指标异常模式与对应病灶 | +-------------------------------------------------------------+ | 1. RegexpCreated / RegexpExecuted 极高 | | -> 病灶: 在 WHERE 或 SELECT 中滥用复杂未编译正则表达式 | | 2. FileOpen / ReadBufferFromFileDescriptorReadBytes 极高 | | -> 病灶: 碎片化小文件过多,频繁解压缩小数据块吃满 CPU | | 3. HashTableAdd / HashTableResize 极高 | | -> 病灶: GROUP BY 超高基数字段,哈希表反复扩容与哈希冲突 | | 4. SelectedMarksPk / MarksLoader 极高 | | -> 病灶: 索引基准失效,执行器对数百万个主键 Mark 进行暴力扫描| +-------------------------------------------------------------+

例如,当发现一条查询中RegexpExecuted高达数千万次时,证明开发人员在对未分词的日志列使用了全量文本正则搜索。在 ClickHouse 中,这完全是在逼迫 CPU 跑密集的标量指令集。此时将其优化为原生支持的multiSearchAny或基于ngrambf_v1跳数索引的字符串匹配,CPU 消耗能瞬间削减 95%!


四、 生产集群防护与配置闭环

为了不让这类消耗万秒 CPU 的失控查询在生产环境中再次演化为灾难,我们必须在用户配置(users.xml)中构筑起三道硬核熔断阈值:

<clickhouse> <profiles> <default> <!-- 1. 物理执行时间熔断:单条即席查询最多允许运行 180 秒,超时直接自动掐死 --> <max_execution_time>180</max_execution_time> <!-- 2. 最大扫描数据量保护:单次查询超过 200 亿行直接阻断,防止全表扫荡 --> <max_rows_to_read>20000000000</max_rows_to_read> <read_overflow_mode>throw</read_overflow_mode> <!-- 3. 最大 CPU 核心线程限制:限制单个查询最大并发线程数,防止单挑全核 --> <max_threads>16</max_threads> <!-- 4. 开启慢查询自动异步采样持久化 --> <log_queries>1</log_queries> <log_queries_min_type>QueryFinish</log_queries_min_type> <!-- 仅针对执行超过 1 秒的查询记录详细日志,节省系统表自身磁盘 I/O --> <log_queries_min_query_duration_ms>1000</log_queries_min_query_duration_ms> </default> </profiles> </clickhouse>

五、 架构师实战经验总结

  1. system.query_log自身也需要清理生命周期:默认情况下该表会永久沉淀在磁盘上,高并发场景下一天就能产生几十 GB 日志。必须在config.xml中配置该表的 TTL(例如TTL event_date + INTERVAL 14 DAY),防止系统日志反噬把磁盘填满。
  2. 善用normalizeQuery进行模板化聚合:如果上千次慢查询来自同一个报表(仅仅是参数不同),通过normalizeQuery(query)可以把具体的日期和 ID 替换为通配符,进而使用GROUP BY normalizeQuery(query)找出是哪个业务模板在整天蚕食集群算力。
  3. 将 CPU 监控与钉钉/飞书告警自动打通:在调度巡检中心写一个定时任务,每隔 10 分钟检索一次system.query_log中单次 CPU 消耗超过 300 秒的查询,自动将负责人的工号与 SQL 片段推送至团队群,让滥用资源的研发同学在第一时间收到整改提醒。
版权声明: 本文来自互联网用户投稿,该文观点仅代表作者本人,不代表本站立场。本站仅提供信息存储空间服务,不拥有所有权,不承担相关法律责任。如若内容造成侵权/违法违规/事实不符,请联系邮箱:809451989@qq.com进行投诉反馈,一经查实,立即删除!
网站建设 2026/10/12 22:40:31

Superpowers开发者工作流:Claude Code+Antigravity+Codex+Cursor实战指南

1. 项目概述&#xff1a;Superpowers 不是超能力&#xff0c;而是开发者工具链的“认知杠杆”最近在多个技术社区和开发者的私聊里&#xff0c;频繁看到“superpowers”这个词被当作一个具体可安装、可配置、可调试的实体来讨论——不是漫威电影里的变种人能力&#xff0c;而是…

作者头像 李华
网站建设 2026/10/19 21:15:57

TFLite内存规划器:用张量生命周期精打细算每一块内存

1. 内存规划器在做一件什么事第一次看到 TFLite 内存规划器&#xff08;Memory Planner&#xff09;这个名字时&#xff0c;我脑子里冒出来的画面是一个仓库管理员&#xff1a;一箱一箱的中间结果要被临时存放&#xff0c;又要在用完以后及时腾出空间&#xff0c;好让下一批货物…

作者头像 李华
网站建设 2026/10/30 0:27:17

AI绘画中ponytail发型实战:提示词、LoRA与参数调优全指南

1. 先搞清楚&#xff1a;ponytail 到底是发型还是插件&#xff1f;1.1 从热搜词看 ponytail 的真实含义如果你也是因为“ponytail skill”“ponytail 插件”这些词搜到这里&#xff0c;那我猜你大概率跟我一样&#xff0c;第一反应是“这不就是个马尾辫嘛&#xff0c;怎么还扯上…

作者头像 李华
网站建设 2026/10/25 22:22:55

PyTorch模型内存三笔账:参数、激活与计算开销深度解析

1. 为什么模型文件只有几MB&#xff0c;加载后内存却暴涨到几个GB&#xff1f; “这个模型权重文件才4.2MB&#xff0c;我用torch.load()一加载&#xff0c;GPU显存直接飙到3.8GB&#xff0c;系统内存也涨了2个G——这账到底怎么算的&#xff1f;”这是我在三个不同技术群、两…

作者头像 李华
网站建设 2026/10/25 21:03:55

Agent Skills 实战:从设计开发到 GKE 生产部署全流程

1. 从“skills”这个热词说起&#xff1a;它到底是什么&#xff0c;为什么突然火了最近几个月&#xff0c;不管是在技术社区、开发者群聊&#xff0c;还是在做AI应用的朋友圈子里&#xff0c;“skills”这个词出现的频率高得离谱。有人叫它 Agent Skills&#xff0c;有人叫它 C…

作者头像 李华
网站建设 2026/10/14 15:30:08

饲料配料控制系统全解析:从称重到批次追溯的PLC工程实践

接到 No.888 这个编号时&#xff0c;我正在办公室看图纸&#xff0c;甲方只给了很简短的需求&#xff1a;一条新建的配料饲料加工产线&#xff0c;要把称重、混合、输送、打包这几个环节统一到一套控制系统里&#xff0c;实现从配方下达到成品出库的全过程可追溯。听起来是标准…

作者头像 李华