慢查询日志结果不一致问题

[tao7]

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

• 【TiDB 版本】：4.0.7
• 【问题描述】：使用如下2条sql查询慢日志，发现得到的结果不一致
  1、select count() from INFORMATION_SCHEMA.CLUSTER_SLOW_QUERY where query_time>=1 and db=‘test’ and user=‘test’ and is_internal = false and time > ‘2020-10-28 00:00:00’ and time <= ‘2020-10-29 00:00:00’;
  得到的结果是927条
  2、select count() from INFORMATION_SCHEMA.CLUSTER_SLOW_QUERY where query_time>=1 and db=‘test’ and user=‘test’ and is_internal = false and DATE_FORMAT(time,’%Y-%m-%d’) = ‘2020-10-28’ ;
  得到的结果是537条

这2条sql唯一的区别就是时间的格式不一样，但时间段的选取是一样的，这个是什么原因呢？

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

[yilong (yi888long)]

看看 time = ‘2020-10-28 00:00:00’ 和 time = ‘2020-10-29 00:00:00’ 的有多少， 两个条件这里有些区别

[tao7]

这2个时间点都没有数据

[yilong (yi888long)]

能否麻烦分别上传一个，可以查出的日志和无法查出的日志，我们看下哪里有问题，多谢。

[tao7]

是tidb节点的日志吗？

[yilong (yi888long)]

这个sql查询的应该是 slow 日志，所以可以找几条记录只在一个查询条件的，看看日志记录的是什么样子

[tao7]

可以加微信沟通或者单发吗，有敏感信息。感觉是解析 **DATE_FORMAT(time,’%Y-%m-%d’) = ‘2020-10-28’**这个条件的时候，可能存在非预期行为

[yilong (yi888long)]

可以发私信，根据找到的日志是否能看出来哪里有问题？

[yilong (yi888long)]

请问正常日志也是显示这种值吗？ Time: 2020-10-28T20:30:29.910788133+08:00 两个都能查到的日志

[tao7]

下面这个是2条sql都能查询到的正常日志：

Time: 2020-10-28T23:31:54.970714887+08:00

Txn_start_ts: 420452529224286209

[crazycs520-PingCAP]

@tao7

查询 slow_query 和 cluster_slow_query 有一个潜在的限制是，如果没有明确指定 time 的时间范围（如 time > ‘xxx’ and time < ‘xxx’） ，那么 slow_query 和 cluster_slow_query 只会查询当前的慢日志文件，慢日志文件默认是达到 300M 后就会 rotate 当前文件后写入新的慢日志文件。

这个例子中，第一个 SQL 明确指定了 time 的范围 （time > ‘2020-10-28 00:00:00’ and time <= ‘2020-10-29 00:00:00’）, 所以可以正确的扫描在这个时间范围内的所有慢日志文件。

但是第二个 SQL 的条件中，目前无法根据 DATE_FORMAT(time,’%Y-%m-%d’) = ‘2020-10-28’ 条件准确推断出 time 的时间范围，所以默认只会扫描当前的慢日志文件。

下面是相关的文档：

https://docs.pingcap.com/zh/tidb/stable/identify-slow-queries#慢日志内存映射表

[tao7]

感谢解惑

[yilong (yi888long)]