慢查询时间统计问题

🪐 TiDB 技术问题 性能调优
1

为提高效率，提问时请提供以下信息，问题描述清晰可优先响应。

  • 【TiDB 版本】：4.0.1

  • 【问题描述】：下面的慢查询日志中的这个查询，Cop_time+Process_time+Wait_time 加起来才100多秒，为什么这个查询执行完需要660多秒，其他的时间是花在哪了？从哪可以看出来？

      # Time: 2020-06-22T20:32:15.538101068+08:00
  # Txn_start_ts: 417550426194051098
  # User: martech@192.168.14.3
  # Conn_ID: 8918
  # Query_time: 666.459045901
  # Parse_time: 0.000104846
  # Compile_time: 0.000480965
  # Cop_time: 31.438840618 Process_time: 10.319 Wait_time: 87.95 Request_count: 15449 Total_keys: 5893499 Process_keys: 5730710
  # DB: mbase
  # Index_names: [rel_topic:PRIMARY]
  # Is_internal: false
  # Digest: f392742f6b036ffc7dfc6369574775f1ef2d5ec58f1377afb512e50aa783d485
  # Stats: rel_topic:417549578708713480
  # Num_cop_tasks: 15449
  # Cop_proc_avg: 0.000667939 Cop_proc_p90: 0.001 Cop_proc_max: 0.025 Cop_proc_addr: 192.168.14.6:20171
  # Cop_wait_avg: 0.005692925 Cop_wait_p90: 0.006 Cop_wait_max: 0.352 Cop_wait_addr: 192.168.14.11:20171
  # Mem_max: 123176090
  # Prepared: false
  # Plan_from_cache: false
  # Has_more_results: false
  # Succ: true
  # Plan: tidb_decode_plan('mwKYMAkzMF8xMQkwCTI4Mzk2NjkuMTI4ODkzNzQwNQkKMQkxM185CTEJSh0A8Fh0YWJsZTpyZWxfd2VpYm9fdG9waWNfc3RhdHVzLCBwYXJ0aXRpb246cDIwMjAwNSwgaW5kZXg6UFJJTUFSWShkYXRlLCB0b3BpYywgbWlkKSwgcmFuZ2U6WwEwGC0wNS0yNywZC2xdLCBrZWVwIG9yZGVyOmZhbHNlCjEJMTBfMTAJ/p8ACZ9CXwA=')
  # Plan_digest: 31d1cf436634356728f6665dbbc21112d9221d7831ed03b15f2b5a88f19a3edf
  select /*+ READ_CONSISTENT_REPLICA() */ date, topic, comment_count from rel_topic where date = '2020-05-27';

若提问为性能优化、故障排查类问题，请下载脚本运行。终端输出打印结果，请务必全选并复制粘贴上传。

2

你好，

看下 dashboard 中 sql 语句分析是否能帮到你。

image
image1920×903 70.3 KB

3

这个Dashboard里SQL语句分析没有记录下来有问题的SQL，我查看了记录下来的SQL发现有较多查询的Coprocessor 等待耗时比较久，想要问一下：

  1. 什么情况下会造成Coprocessor 等待耗时比较久？是不是对于同一个表的并发查询比较多的时候会出现这个问题？针对分区表有什么情况会引起Coprocessor 等待耗时久吗？
  2. 是否可以通过优化配置等方式解决Coprocessor 等待耗时久的问题？
4

coprocessor 时间比较久可以看下 tidb-detail - thread cpu - unified read pool cpu 使用率是否偏高，可以关注下 tikv 是否比较繁忙

可以在文档中搜索下 unified

5

终于在dashboard里看到了异常的数据：

image
image2296×1204 206 KB

看上面各阶段处理的时间也就20多s，但整个查询却花了8分钟，想问一下这种情况是怎么回事

6

unified read pool cpu没有明显的偏高

7

麻烦反馈下问题发生时的over-view tidb detail-tikv 监控，看下整体资源耗时，多谢

8

我们通过设置 FetchSize 为 Integer.MIN_VALUE 解决了慢查询的问题。

9

:+1:

10

当前 tidb 的 slow log 的统计还不是很完全，如果该 sql 是稳定慢，可以使用 trace format=‘row’ 看看执行的情况，并上传下结果，我们可以在跟一下。
https://docs.pingcap.com/zh/tidb/v4.0/sql-statement-trace#示例

11

此话题已在最后回复的 1 分钟后被自动关闭。不再允许新回复。