机器配置

Clickhouse 配置内存大小: 250G

Zookeeper 配置内存大小：24G

发现问题

企业相干开发人员通过Grafana监控Clickhouse指标察看到，从12点左右呈现了大量的碎片写入，从而引起了相干指标的疾速回升。查看云智慧的数字化运维数据平台 DODB （以下简称DODB）概览页也未查看出异样呈现源头，而当查看服务器负载状况时，曾经回升至900+。

开始排查

  1. 查看是否为执行 SQL 太多

当遇到此类问题时，广泛状况下均会猜想是 SQL 执行太多导致。因而，团队开发人员查看了 Clickhouse 的 Process表，以此判断运行中的 SQL 是否过多。与此同时与算法部门的共事进行沟通，最终确认是通过 DODB 写入数据的。随后又查问了一下执行中的 SOL，发现两台机器上运行中的 SOL 不太平衡。

  1. 查问 Clickhouse 日志

当查看 Clickhouse 日志时，看到有很多 warn 的日志，但并没有呈现有价值的日志。

  1. 查问 Zookeeper 日志

当查看 Zookeeper 日志时，发现数据同步有比拟大的提早，超过了1-2s。

排查同步数据提早是因为须要判断是 load 值上来导致提早还是因为提早导致的 load 值上来。可能是一个大查问导致 load 值上来后，引起 Zookeeper 呈现问题，从而导致数据无奈同步呈现数据沉积的状况。因而，在此时查看了监控的读写状况，是因为load值上来后导致写入变慢。

  1. SQL 语句查问

在 Clickhouse 中，所有被执行 Query 均会记录到system.query_log表中。因而可通过该表监控集群的查问状况。以下列举几种用于监控的罕用SQL。

最近查问

SELECT       event_time,       user,       query_id AS query,       read_rows,       read_bytes,       result_rows,       result_bytes,       memory_usage,       exception  FROM clusterAllReplicas('cluster_name', system, query_log)  WHERE (event_date = today()) AND (event_time >= (now() - 60)) AND (is_initial_query = 1) AND (query NOT LIKE 'INSERT INTO%')  ORDER BY event_time DESC  LIMIT 100

慢查问

SELECT       event_time,       user,       query_id AS query,       read_rows,       read_bytes,       result_rows,       result_bytes,       memory_usage,       exception  FROM clusterAllReplicas('cluster_name', system, query_log)  WHERE (event_date = yesterday()) AND query_duration_ms > 30000 AND (is_initial_query = 1) AND (query NOT LIKE 'INSERT INTO%')  ORDER BY query_duration_ms desc  LIMIT 100

Top10大表

SELECT       database,       table,       sum(bytes_on_disk) AS bytes_on_disk  FROM clusterAllReplicas('cluster_name', system, parts)  WHERE active AND (database != 'system')  GROUP BY       database,       table  ORDER BY bytes_on_disk DESC  LIMIT 10

Top10查问用户

SELECT       user,       count(1) AS query_times,       sum(read_bytes) AS query_bytes,       sum(read_rows) AS query_rows  FROM clusterAllReplicas('cluster_name', system, query_log)  WHERE (event_date = yesterday()) AND (is_initial_query = 1) AND (query NOT LIKE 'INSERT INTO%')  GROUP BY user  ORDER BY query_times DESC  LIMIT 10

应用慢查问的 SQL 查问

查问后果进去，查看所执行 SQL 具体情况，发现很多都是“异样容器”的。

下图为作战地图所查大屏表，且为 left JOIN 表。因为 life 的 JOIN 在网络及其他因素条件有要求，因而比方才查问更耗费资源。随后通过时间段查问判断出现异常工夫是否匹配，比照发现工夫上有些差别。

查问 SQL 查问次数，判断哪次查问 工夫 最长以及查问的均匀时长。

select left(query, 100) as sql, count() as queryNum, sum(query_duration_ms) as totalTime, totalTime/queryNum as avgTime from system.query_log ql where event_time > toDateTime("2022-09-23 12:00:00") and event_time < toDateTime("2022-09-23 17:00:00") group by sql order by queryNum desc limit 10

通过该 SQL 查问，发现 5 个小时 SQL 查问了将近 4 万次，且同类型查问执行次数均较高，均匀执行工夫也比拟长。此外，也有许多 5 个小时执行两三千次的 SQL 查问，该类查问均匀每次耗时均在二三十秒。

查问不蕴含insert into语句的5个小时查问次数超过1000次的 SQL

select * from (select LEFT(query, 100) as sql, count() as quneryNum, sum(query_duration_ms) as totalTime, totalTime/queryNum as avgTime from system.query_log ql where event_time > toDateTime('2022-09-23 12:00:00') and event_time < toDateTime('2022-09-23 17:00:00') and query not like '%INSERT INTO%' group by sql order by avgTime desc) where queryNum > 1000 limit 50

因为上述 SQL 均做了截取，故需依据所查问 SQL 进一步匹配 SQL。

select query from system.query_log where event_time > toDateTime('2022-09-23 12:00:00') and event_time < toDateTime('2022-09-23 17:00:00') and query like '%须要匹配的sql查问%' limit 5;

应用第三条 SQL 用 queryNum 排序，查问出执行次数多且均匀耗时比拟大的 SQL，随后定位 SQL。以第二条记录为例：5个小时查问了 38000+次，耗时12s，每分钟查 120+次。

应用第三条 SQL ，将 工夫 范畴改到上午8点到上午12查问。 查问后果比照发现，执行耗时在上午时均很短，但到中午12点当前就变的十分慢了。

因为之前查问发现有局部 left JOIN 的查问，故查问了“异样容器”的left JOIN 的查问,，随后将读取条数为0的排除掉。

select * from (select LEFT(query, 100) as sql, count() as quneryNum, sum(query_duration_ms) as totalTime, totalTime/queryNum as avgTime from system.query_log ql where sql like '%异样容器%' and read_rows != 0 and event_time > toDateTime('2022-09-23 12:00:00') and event_time < toDateTime('2022-09-23 17:00:00') and query not like '%INSERT INTO%' group by sql order by queryNum desc)

依据小时 聚合 每个小时/分钟段查问次数耗时

--依照每小时聚合select toHour(event_time) as t, count() as queryNum, sum(query_duration_ms) as totalTime, totalTime/queryNum as avgTime from system.query_log ql where event_time > toDateTime('2022-09-23 08:00:00') and event_time < toDateTime('2022-09-23 17:00:00') and query not like '%INSERT INTO%' and query like '%异样容器%' and read_rows != 0 group by t limit 50--依照每分钟聚合select toMinute(event_time) as t, count() as queryNum, sum(query_duration_ms) as totalTime, totalTime/queryNum as avgTime from system.query_log ql where event_time > toDateTime('2022-09-23 12:00:00') and event_time < toDateTime('2022-09-23 13:00:00') and query not like '%INSERT INTO%' and query like '%异样容器%' and read_rows != 0 group by t limit 50

查问后果如下：10点开始有，12 点查问响应工夫翻了10倍。

从32s开始，响应工夫变为24s多，前面的工夫也逐步变长。

查问 left JOIN 的查问个数。

select * from (select LEFT(query, 100) as sql, count() as quneryNum, sum(query_duration_ms) as totalTime, totalTime/queryNum as avgTime from system.query_log ql where query like '% JOIN%' and read_rows != 0 and event_time > toDateTime('2022-09-23 12:00:00') and event_time < toDateTime('2022-09-23 21:00:00') and query not like '%INSERT INTO%' group by sql order by queryNum desc)

发现有问题的表时，查问该表构造。

show create table "shard_2"."cw_db_zabbix_metric_data01_replica"

经查问发现该表创立的比拟差，order by 仅有一个 UUID。且该表 JOIN 的 SQL 也比拟多，每次查问的读取的条数也特地大。

停掉 SQL ，察看后果

通过观察，发现有不少相似的 JOIN 的 SQL。当停掉一个异样容器指标的 SQL 时会发现 load 值有些许变动，偶然会降到700多。因为指标治理都是通过 gatewayAPI 调用，停掉 SQL 最快的办法便是间接将 gatewayAPI 停掉，这样只会影响指标 SQL 调，不会影响其余性能应用。将 gatewayAPI 停掉后就不会呈现指标调用 SQL 也全副停掉，此时发现 load 值已升高

总结

遇到此类问题可先查看日志，首先在（Clickhouse 日志 Zookeeper 日志）日志中看是否找到有用的信息，例如间接报错信息等，如果在日志中找不到太多有用的信息的话，能够从上面动手。

个别遇到 load 值比拟高的状况时，基本上都是产生在查问下面。当遇到这种问题时可先查问带有JOIN 的 SQL 语句是不是很多。随后通过 query_log 表中的一些字段去查问重要信息，通过对字段应用一些函数来获取有用的信息，如获取查问的 SQL，SQL 执行次数、执行工夫等。

本次排查过程次要应用query_log表，上面为重要字段：

event_time — 查问开始工夫.

query_duration_ms — 查问耗费的工夫（毫秒）.

read_rows— 从参加了查问的所有表和表函数读取的总行数.

query — 查问语句.

Clickhouse query_log 表中所有字段

  • type (Enum8) — 执行查问时的事件类型. 值:

    • 'QueryStart' = 1 — 查问胜利启动.
    • 'QueryFinish' = 2 — 查问胜利实现.
    • 'ExceptionBeforeStart' = 3 — 查问执行前有异样.
    • 'ExceptionWhileProcessing' = 4 — 查问执行期间有异样.
  • event_date (Date) — 查问开始日期.
  • event_time (DateTime) — 查问开始工夫.
  • event_time_microseconds (DateTime64) — 查问开始工夫（毫秒精度）.
  • query_start_time (DateTime) — 查问执行的开始工夫.
  • query_start_time_microseconds (DateTime64) — 查问执行的开始工夫（毫秒精度）.
  • query_duration_ms (UInt64) — 查问耗费的工夫（毫秒）.
  • read_rows (UInt64) — 从参加了查问的所有表和表函数读取的总行数. 包含：一般的子查问, IN 和 JOIN的子查问. 对于分布式查问 read_rows 包含在所有正本上读取的行总数。 每个正本发送它的 read_rows 值，并且查问的服务器-发起方汇总所有接管到的和本地的值。 缓存卷不会影响此值。
  • read_bytes (UInt64) — 从参加了查问的所有表和表函数读取的总字节数. 包含：一般的子查问, IN 和 JOIN的子查问. 对于分布式查问 read_bytes 包含在所有正本上读取的字节总数。 每个正本发送它的 read_bytes 值，并且查问的服务器-发起方汇总所有接管到的和本地的值。 缓存卷不会影响此值。
  • written_rows (UInt64) — 对于 INSERT 查问，为写入的行数。 对于其余查问，值为0。
  • written_bytes (UInt64) — 对于 INSERT 查问时，为写入的字节数。 对于其余查问，值为0。
  • result_rows (UInt64) — SELECT 查问后果的行数，或INSERT 的行数。
  • result_bytes (UInt64) — 存储查问后果的RAM量.
  • memory_usage (UInt64) — 查问应用的内存.
  • query (String) — 查问语句.
  • exception (String) — 异样信息.
  • exception_code (Int32) — 异样码.
  • stack_trace (String) — Stack Trace. 如果查问胜利实现，则为空字符串。

  • is_initial_query (UInt8) — 查问类型. 可能的值:

    • 1 — 客户端发动的查问.
    • 0 — 由另一个查问发动的，作为分布式查问的一部分.
  • user (String) — 发动查问的用户.
  • query_id (String) — 查问ID.
  • address (IPv6) — 发动查问的客户端IP地址.
  • port (UInt16) — 发动查问的客户端端口.
  • initial_user (String) — 初始查问的用户名（用于分布式查问执行）.
  • initial_query_id (String) — 运行初始查问的ID（用于分布式查问执行）.
  • initial_address (IPv6) — 运行父查问的IP地址.
  • initial_port (UInt16) — 发动父查问的客户端端口.

  • interface (UInt8) — 发动查问的接口. 可能的值:

    • 1 — TCP.
    • 2 — HTTP.
  • os_user (String) — 运行 clickhouse-client的操作系统用户名.
  • client_hostname (String) — 运行clickhouse-client 或其余TCP客户端的机器的主机名。
  • client_name (String) — clickhouse-client 或其余TCP客户端的名称。
  • client_revision (UInt32) — clickhouse-client 或其余TCP客户端的Revision。
  • client_version_major (UInt32) — clickhouse-client 或其余TCP客户端的Major version。
  • client_version_minor (UInt32) — clickhouse-client 或其余TCP客户端的Minor version。
  • client_version_patch (UInt32) — clickhouse-client 或其余TCP客户端的Patch component。

  • http_method (UInt8) — 发动查问的HTTP办法. 可能值:

    • 0 — TCP接口的查问.
    • 1 — GET
    • 2 — POST
  • http_user_agent (String) — The UserAgent The UserAgent header passed in the HTTP request。
  • quota_key (String) — 在quotas 配置里设置的“quota key” （见 keyed).
  • revision (UInt32) — ClickHouse revision.
  • ProfileEvents (Map(String, UInt64))) — Counters that measure different metrics. The description of them could be found in the table 零碎。流动
  • Settings (Map(String, String)) — Names of settings that were changed when the client ran the query. To enable logging changes to settings, set the log_query_settings 参数为1。
  • thread_ids (Array(UInt64)) — 参加查问的线程数.
  • Settings.Names (Array（String)) — 客户端运行查问时更改的设置的名称。 要启用对设置的日志记录更改，请将log_query_settings参数设置为1。
  • Settings.Values (Array（String)) — Settings.Names 列中列出的设置的值

开源我的项目举荐

云智慧已开源数据可视化编排平台 FlyFish 。通过配置数据模型为用户提供上百种可视化图形组件，零编码即可实现合乎本人业务需要的炫酷可视化大屏。 同时，飞鱼也提供了灵便的拓展能力，反对组件开发、自定义函数与全局事件等配置， 面向简单需要场景可能保障高效开发与交付。

如果喜爱咱们的我的项目，请不要遗记点击下方代码仓库地址，在 GitHub / Gitee 仓库上点个 Star，咱们须要您的激励与反对。此外，即刻参加 FlyFish 我的项目奉献成为 FlyFish Contributor 的同时更有万元现金等你来拿。

GitHub 地址： https://github.com/CloudWise-...

Gitee 地址： https://gitee.com/CloudWise/f...

微信扫描辨认下方二维码，备注【飞鱼】退出AIOps社区飞鱼开发者交换群，与 FlyFish 我的项目 PMC 面对面交换～