为何COUNT很慢却不写SLOW LOG


1. 问题描述2. 问题排查3. 问题解释3.1 关于聚集索引并行读延伸阅读

MySQL对COUNT(*)一直在优化。

1. 问题描述

某日,群友反馈问题对大表COUNT(*)很慢,但却不会记录到slow log中,这是为什么呢?
我自己根据他提供的信息,复现了这个问题:

# MySQL版本是8.0.20
[root@yejr.run]>\s
...
Server version:        8.0.20 MySQL Community Server - GPL
...

# 确认 long_query_time
[root@yejr.run]>select @@global.long_query_time, @@session.long_query_time;
+--------------------------+---------------------------+
| @@global.long_query_time | @@session.long_query_time |
+--------------------------+---------------------------+
|                 0.010000 |                  0.010000 |
+--------------------------+---------------------------+

# 执行 COUNT(*),耗时超过 0.01,但slow log没有记录
[root@yejr.run]>select count(*) from t1;
+----------+
| count(*) |
+----------+
|   799994 |
+----------+
1 row in set (0.27 sec)

这到底是为什么呢?

2. 问题排查

我们先检查所有和slow log相关的参数:

[root@yejr.run]>show global variables;
...
| log_slow_admin_statements              | OFF      |
| log_slow_extra                         | ON       |
| log_slow_slave_statements              | OFF      |
| long_query_time                        | 0.010000 |
| slow_query_log                         | ON       |
| slow_query_log_file                    | slow.log |
| log_output                             | FILE     |
| min_examined_row_limit                 | 100      |
| log_queries_not_using_indexes          | 1        |
| log_throttle_queries_not_using_indexes | 60       |
...

上面几个参数中,比较可疑有下面几个:

| min_examined_row_limit                 | 100      |
| log_queries_not_using_indexes          | 1        |
| log_throttle_queries_not_using_indexes | 60       |

先说 log_queries_not_using_indexes,这表示把没有使用索引的SQL也当成slow query记录下来,但在本例中,是有走索引的:

[root@yejr.run]>desc select count(*) from t1\G
*************************** 1. row ***************************
           id: 1
  select_type: SIMPLE
        table: t1
   partitions: NULL
         type: index
possible_keys: NULL
          key: PRIMARY
      key_len: 4
          ref: NULL
         rows: 42760
     filtered: 100.00
        Extra: Using index

由此也顺便排除了参数 log_throttle_queries_not_using_indexes 的嫌疑。
那么,只剩下参数 min_examined_row_limit 的嫌疑,它表示当扫描行数少于设定值时,这个SQL也不会被当做slow query记录下来。
那么,本例中的COUNT(*)是否符合这种情况呢?
我们先把参数 min_examined_row_limit 值设置为 0,也就是默认值。

[root@yejr.run]>set global min_examined_row_limit=0;
[root@yejr.run]>set session min_examined_row_limit=0;
[root@yejr.run]>select @@global.min_examined_row_limit, @@session.min_examined_row_limit;
+---------------------------------+----------------------------------+
| @@global.min_examined_row_limit | @@session.min_examined_row_limit |
+---------------------------------+----------------------------------+
|                               0 |                                0 |
+---------------------------------+----------------------------------+

再执行一次 COUNT(*) 查询

[root@yejr.run]>select count(*) from t1;
+----------+
| count(*) |
+----------+
|    43462 |
+----------+
1 row in set (0.02 sec)

果然,这次被记录到slow log中了

# Query_time: 0.026083  Lock_time: 0.000110 Rows_sent: 1  Rows_examined: 0
...
select count(*) from t1;

注意到 Rows_examined 的值是 0,嗯,好像不太科学?

到这里,原因查明了,参数 min_examined_row_limit 的值设置大于 0 了,而本例中的 COUNT(*) 操作因为 Rows_examined=0,所以不会被记录到slow log中。

3. 问题解释

虽然知道问题原因了,但 Rows_examined 表示什么意思呢,文档中的解释如下:

• Rows_examined: 
The number of rows examined by the server layer (not counting any processing internal to storage engines).

可能字面意思上看起来不太好理解,换个思路,其实就是我们执行完一个SQL后,查看状态变量中名为 Handler_read_% 的几个指标即可,例如:

[root@yejr.run]> flush status;
[root@yejr.run]> select count(*) from t1;
...
[root@yejr.run]> show status like 'handler%read%';
+-----------------------+-------+
| Variable_name         | Value |
+-----------------------+-------+
| Handler_read_first    | 0     |
| Handler_read_key      | 0     |
| Handler_read_last     | 0     |
| Handler_read_next     | 0     |
| Handler_read_prev     | 0     |
| Handler_read_rnd      | 0     |
| Handler_read_rnd_next | 0     |
+-----------------------+-------+

可以看到以上几个值均为 0,因此 Rows_examined 也为 0,就不会被记录到slow log中了。

3.1 关于聚集索引并行读

说到这里,我还要隆重介绍MySQL 8.0的另一个新特性。
从8.0.14版本起,新增参数 innodb_parallel_read_threads,支持对聚集索引的并行扫描,需要满足以下几个条件:

  • 参数 innodb_parallel_read_threads 值 > 0

  • 只支持聚集索引

  • 只支持无锁查询

  • 不是INSERT…SELECT查询

主要用于加速以下两种场景:

  • CHECK TABLE操作

  • 不带WHERE条件的全表COUNT(*)

因此,COUNT(*)也是可以并行读聚集索引的,从error log中可以看到类似下面的信息:

[Note] [MY-011825] [InnoDB] Parallel scan: 4
[Note] [MY-011825] [InnoDB] ranges: 130 max_threads: 4 split: 128 depth: 1
[Note] [MY-011825] [InnoDB] n: 20914
[Note] [MY-011825] [InnoDB] n: 18066
[Note] [MY-011825] [InnoDB] n: 4482

从上述日志能看出来几点:

  1. 设置了最高4个并行线程

  2. 实际并行3个线程,实际并行数从1~4,不一定每次都跑最高并行

  3. 分别扫描行数是 20914、18066、4482,即 COUNT() 结果总数是 43462

对t1表加上一个辅助索引后,再来看下面这个COUNT(*)

# 看起来这个查询是走辅助索引
[root@yejr.run]>desc select count(*) from t1\G
*************************** 1. row ***************************
           id: 1
  select_type: SIMPLE
        table: t1
   partitions: NULL
         type: index
possible_keys: NULL
          key: k1
      key_len: 5
          ref: NULL
         rows: 42760
     filtered: 100.00
        Extra: Using index

# 实际执行一把
[root@yejr.run]>select count(*) from t1;
+----------+
| count(*) |
+----------+
|    43462 |
+----------+
1 row in set (0.01 sec)

# 发现 Handler_read_% 的值还是 0
[root@yejr.run]>show status like 'handler%read%';
+-----------------------+-------+
| Variable_name         | Value |
+-----------------------+-------+
| Handler_read_first    | 0     |
| Handler_read_key      | 0     |
| Handler_read_last     | 0     |
| Handler_read_next     | 0     |
| Handler_read_prev     | 0     |
| Handler_read_rnd      | 0     |
| Handler_read_rnd_next | 0     |
+-----------------------+-------+        

且此时error log中依然有并行扫描的记录

[Note] [MY-011825] [InnoDB] Parallel scan: 4
[Note] [MY-011825] [InnoDB] ranges: 91 max_threads: 4 split: 88 depth: 1
[Note] [MY-011825] [InnoDB] n: 21493
[Note] [MY-011825] [InnoDB] n: 21486
[Note] [MY-011825] [InnoDB] n: 483

看到了么,实际上还是用到了聚集索引的并行扫描特性来加速。

提醒:上述error log中记录并行扫描聚集索引信息的功能在8.0.20中又被去掉了,上面之所以能看到这段日志是因为我排查到后面又回退到8.0.19版本了,有点费劲。。。
看下8.0.20 Release Notes

InnoDB: Unnecessary messages about parallel scans were printed to the error log. (Bug #30330448)

其实留着不挺好的嘛,搞不懂为毛要去掉的说。。。

延伸阅读

  • 15.14 InnoDB Startup Options and System Variables, https://dev.mysql.com/doc/refman/8.0/en/innodb-parameters.html#sysvar_innodb_parallel_read_threads

  • MySQL 8.0.20 Release Notes, https://dev.mysql.com/doc/relnotes/mysql/8.0/en/news-8-0-20.html

  • WL#11720: InnoDB: Parallel read of index, https://dev.mysql.com/worklog/task/?id=11720

  • MySQL 8.0.14: A Road to Parallel Query Execution is Wide Open, https://www.percona.com/blog/2019/01/23/mysql-8-0-14-a-road-to-parallel-query-execution-is-wide-open/

Enjoy MySQL 8.0 :)

全文完。


  • 由叶老师主讲的知数堂「MySQL优化课」课程早已升级到MySQL 8.0版本了,现在上车刚刚好,扫码开启MySQL 8.0的修行之旅吧。


    另外,叶老师在腾讯课堂《MySQL性能优化》精编版第一期已完结,本课程讲解读几个MySQL性能优化的核心要素:合理利用索引,降低锁影响,提高事务并发度

    下面是自动拼团的二维码直接享受组团价

     

评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值