单行数据查询之谜:为什么慢?细解查询长时间不返回和查询慢

262 阅读4分钟

本文为《MySQL归纳学习》专栏的第四篇文章,同时也是关于《MySQL查询》知识点的第四篇文章。

往期回顾:

MySQL玩转指南:探秘Server层组件及权限校验实践

MySQL战记:Count( *)实现之谜与计数策略的选择

# MySQL排序大揭秘:全字段与rowid的比较与应用

单行数据查询速度缓慢,你有没有想过其中的原因是什么?本文深入分析了单行数据查询为何会变慢的两大类原因:查询长时间不返回和查询慢。我们将揭开这个谜团,并探索其中的细致原因。

首先来看一下这张思维导图,对本文内容有个直观的认识。

img

接下来进入正文。

一般情况下,如果我跟你说查询性能优化,你首先会想到一些复杂的语句,想到查询需要返回大量的数据。但有些情况下,“查一行”,也会执行得特别慢。

CREATE TABLE `t_color` ( `id` int(11) NOT NULL, `c` int(11) DEFAULT NULL, PRIMARY KEY (`id`)) ENGINE=InnoDB;

delimiter ;;
create procedure idata()
begin
  declare i int;
  set i=1;
  while(i<=100000) do
    insert into t_color values(i,i);
    set i=i+1;
  end while;
end;;
delimiter ;

call idata();

查询长时间不返回

select * from t_color where id=1;

查询结果长时间不返回。

img

一般碰到这种情况的话,大概率是表 t 被锁住了。接下来分析原因的时候,一般都是首先执行一下 show processlist 命令,看看当前语句处于什么状态。

等 MDL 写锁

基于 MySQL 5.7版本,按照如下操作步骤执行这两条 SQL,来复现查询结果长时间不返回的情况。

其中在 MySQL5.5及以后的版本中,lock table t1 write 就是通过加 MDL 写锁,来阻止其他线程访问的。

// 先执行
lock table t_color write;
// 后执行
select * from t_color where id=1;

img

img

为了查找解决方案,可以先从执行 show processlist 命令,看看当前语句处于什么状态。

show processlist;

执行结果如下:

img

背后原因分析:

session A 通过 lock table 命令持有表 t_color 的 MDL 写锁,而 session B 的查询需要获取 MDL 读锁。所以,session B 进入等待状态。

通过上述命令并不能准确定位到是哪个 session 持有 MDL 写锁,接下来我们通过另一条命令来定位。

通过查询 sys.schema_table_lock_waits 这张表,我们就可以直接找出造成阻塞的 process id,把这个连接用 kill 命令断开即可。( performance_schema 和 sys 系统库都包含该张表,MySQL 启动时如果设置 performance_schema=on,相比于设置为 off 会有 10% 左右的性能损失 )

我们新开一个连接,执行下述语句,结果为:

select blocking_pid from sys.schema_table_lock_waits;

img

根据 MySQL 官网文章介绍可知,先执行下述语句,看看结果如何。

select * from performance_schema.setup_instruments where name='wait/lock/metadata/sql/mdl';

img

看一下ENABLED和TIMED是不是都是YES,只有两个都是YES的时候才能通过查询 schema_table_lock_waits 表得到阻塞的进程id。所以我们需要执行 update 操作。

UPDATE performance_schema.setup_instruments SET ENABLED = 'YES', TIMED = 'YES' WHERE NAME = 'wait/lock/metadata/sql/mdl';

最后再尝试执行查询阻塞进程id,结果如下:

img

等 flush

MySQL 里面对表做 flush 操作的用法,一般有以下两个:

flush tables t with read lock;

flush tables with read lock;

这两个 flush 语句,如果指定表 t 的话,代表的是只关闭表 t;如果没有指定具体的表名,则表示关闭 MySQL 里所有打开的表。

但是正常这两个语句执行起来都很快,除非它们也被别的线程堵住了。所以,出现 Waiting for table flush 状态的可能情况是:有一个 flush tables 命令被别的语句堵住了,然后它又堵住了我们的 select 语句。

复现步骤

select sleep(1) from t_color;

flush tables t_color;

select * from t_color where id=1;

img

在 session A 中,故意每行都调用一次 sleep(1),这样这个语句默认要执行 10 万秒(全表扫描,每行sleep 1秒 ),在这期间表 t_color 一直是被 session A“打开”着。然后,session B 的 flush tables t_color命令再要去关闭表 t_color,就需要等 session A 的查询结束。这样,session C 要再次查询的话,就会被 flush 命令堵住了。

最后再执行 show processlist 命令。

img

等行锁(当前读)

mysql> select * from t_color where id=1 lock in share mode; 

由于访问 id=1 这个记录时要加读锁,如果这时候已经有一个事务在这行记录上持有一个写锁,我们的 select 语句就会被堵住。

复现步骤

begin;
update t_color set c=c+1 where id=1;

select * from t_color where id=1 lock in share mode;

img

执行 show processlist 命令。

img

如果你用的是 MySQL 5.7 版本,可以通过 sys.innodb_lock_waits 表查到。

select * from sys.innodb_lock_waits where locked_table='`mysql_db`.`t_color`'\G

img

上图中有这样两个参数:sql_kill_blocking_query、sql_kill_blocking_connection,前者表示停止 19 号线程当前正在执行的语句,而这个方法其实是没有用的。因为占有行锁的是 update 语句,这个语句已经是之前执行完成了的,现在执行 KILL QUERY,无法让这个事务去掉 id=1 上的行锁。

尝试执行 KILL QUERY 19,没有效果,如下图所示:

img

因为 blocking_pid 为 19,所以执行 kill 19,直接断开这个连接,这里隐含的一个逻辑就是,连接被断开的时候,会自动回滚这个连接里面正在执行的线程,也就释放了 id=1 上的行锁。

查询慢

无索引 limit 1

select * from t_color where c=50000 limit 1;

由于字段 c 上没有索引,这个语句只能走 id 主键顺序扫描,因此需要扫描 5 万行。

此处我们需要通过设置慢查询,可以看到扫描了多少数据行。

开启慢查询的两个步骤,全局变量设置:

  1. 将 slow_query_log 全局变量设置为“ON”状态
    1. mysql> set global slow_query_log='ON'; 
      
  2. 查询超过0秒就记录
    1. set global long_query_time=0;
      

查看配置效果:

mysql> show variables like 'slow_query%';
mysql> show variables like 'long_query_time';

img

执行上述查询语句后,查看日志(注意,需要使用sudo命令才可以有权限看日志):

img

扫描行数多,所以执行慢。

主键索引 一致性读,undolog空间激增

如果根据主键来查询单行数据呢?会不会出现很慢的情况。

mysql> select * from t_color where id=1

虽然扫描行数是 1,但执行时间却长达 1.2秒。

img

如果我把这个 slow log 的截图再往下拉一点,你可以看到下一个语句,select * from t where id=1 lock in share mode,执行时扫描行数也是 1 行,执行时间是 0.08 毫秒。

img

复现过程

start transaction with consistent snapshot;

delimiter ;;
create procedure iudata()
begin
  declare i int;
  set i=1;
  while(i<=1000000) do
    update t_color set c=c+1 where id=1;
    set i=i+1;
  end while;
end;;
delimiter ;

call iudata();


select * from t_color where id=1;
select * from t_color where id=1 lock in share mode;

img

session B 更新完 100 万次,生成了 100 万个回滚日志 (undo log)。

带 lock in share mode 的 SQL 语句,是当前读,因此会直接读到 1000001 这个结果,所以速度很快;而 select * from t where id=1 这个语句,是一致性读,因此需要从 1000001 开始,依次执行 undo log,执行了 100 万次以后,才将 1 这个结果返回。