为什么我只查一行的语句,也执行这么慢?

417 阅读13分钟

前言

在日常工作中,如果我们谈到了 SQL 优化,我们一般会想到什么呢?我们肯定会想到那些复杂的语句,比如 JOIN,比如 子查询,或者是那些需要返回大量数据的 SQL。

我们之前分析过几个案例,如果感兴趣的话可以回顾一下,MYSQL 选错索引问题分析什么,LEFT JOIN 会变成 JOIN?

那么我们有没有想过,有的时候,我们只查一行数据,MYSQL 执行的也特别慢。

可能我们脑子里顿时想到的是这种情况可能发生吗?我怎么没遇到过。

也许是大家日常工作中遇到过却没在意,当然也有可能真没遇到过。

不过这种情况是会存在的,比如我们之前在 HTTP 499 问题处理方法合集 文章中简单提到过,当 MYSQL 向磁盘中刷数据的时候,会占用系统资源,那么就会影响我们的查询语句,当查询数据量特别大,而我们又开启查询缓存,造成锁等待,也会特别慢。

或者说我们的数据库服务器 CPU 或 IO 特别高,数据库本身就很有压力,这种情况下所有语句都会很慢,就不在我们这篇文章讨论的范围中了。

那么,今天我就带大家来看看为什么有时候会出现 只查询一条语句也很慢 的这个奇怪的现象。

数据准备

为了说明今天的问题,我们先来构建一个表,基于该表来说明问题,这个表中有两个字段,a 和 c,并且我向该表中插入了 10 万条数据。

执行过程如下:


mysql> CREATE TABLE `t` (
  `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 values(i,i);
    set i=i+1;
  end while;
end;;
delimiter ;

call idata();
drop procedure idata;

第一类:长时间不返回

首先我们来执行一下这条 SQL,

mysql> select * from t where id=1;
+----+------+
| id | c    |
+----+------+
|  1 |    1 |
+----+------+
1 row in set (0.00 sec)

正如我们期望的一样,结果立刻返回。

MDL 写锁

然后,我再执行一下上述语句,结果却不一致了,半天没有返回结果:

mysql> select * from t where id=1;


这是为什么呢?是因为我在另一个 session 中执行了 lock table t write; 语句,将这个表加上写锁。

整个过程如下:

session Asession Bsession C
lock table t write;
select * from t where id=1;
show processlist;

导致该问题的原因就是 session A 通过 lock table 命令持有表 t 的 MDL 写锁,而 session B 的查询需要获取 MDL 读锁,所以 session B 进入等待状态。

我们可以通过 show processlist 命令查看 Waiting for table metadata lock 的示意图。

注意:这里单开一个 session 执行 show processlist 命令的原因是 lock tables 语法除了会限制别的线程的读写外,也限定了本线程接下来的操作对象。

mysql> show processlist;
+----+-----------------+-----------+----------+---------+-------+---------------------------------+----------------------------+
| Id | User            | Host      | db       | Command | Time  | State                           | Info                       |
+----+-----------------+-----------+----------+---------+-------+---------------------------------+----------------------------+
|  5 | event_scheduler | localhost | NULL     | Daemon  | 15566 | Waiting on empty queue          | NULL                       |
|  8 | root            | localhost | example1 | Query   |  1146 | Waiting for table metadata lock | select * from t where id=1 |
| 11 | root            | localhost | example1 | Query   |     0 | starting                        | show processlist           |
+----+-----------------+-----------+----------+---------+-------+---------------------------------+----------------------------+
3 rows in set (0.00 sec)

出现这个状态表示:现在有一个线程正在表 t 上请求或者持有 MDL 写锁,把 select 语句堵住了。

这类问题的处理方式,就是找到谁持有 MDL 写锁,然后把他 kill 掉。

不过我们仅仅通过 show processlist 结果也很难去定位问题,只知道是等待锁。

不过我们可以通过 performance_schemasys 系统库就可以很方便的找到问题所在了。

我们再打开一个 session,因为 session A 在等待,session B 锁住了。

我们可以通过查询 sys.schema_table_lock_waits 这张表,我们就可以直接找出造成阻塞的 process id,把这个连接用 kill 命令断开即可。

在查询之前,我们得判断一下 performance_schema 是否打开,从 MySQL5.6 开始,默认打开的。

查询命令如下:

mysql> show variables like 'performance_schema';
+--------------------+-------+
| Variable_name      | Value |
+--------------------+-------+
| performance_schema | ON    |
+--------------------+-------+
1 row in set (0.02 sec)

我们看到 performance_schema 是打开的。那么我们查一下 blocking_pid

mysql> select blocking_pid from sys.schema_table_lock_waits;
+--------------+
| blocking_pid |
+--------------+
|           12 |
+--------------+
1 row in set (0.00 sec)

再执行 kill 命令,select 语句就可以正常执行了。

mysql> kill 12;
Query OK, 0 rows affected (0.00 sec)

等 flush

我们再来看看另外一种查询时被堵住的情况。就是等待 flush。

我们来复现一下这种情况:

session Asession Bsession Csession D
select sleep(1) from t;
flush tables t;
select * from t where id = 1;
show processlist;

我们来简单说明一下上述命令。

在 session A 中,我们每次都调用一次 sleep(1),这样这个语句默认要执行 10 万秒。在这个期间表 t 一直被 session A “打开” 着。

然后 session B 执行 flush tables t; 命令。

这个命令的含义是对表 t 执行 flush 操作,如果我们不加表 t,执行 flush tables; 命令,则是对该库中所有表执行 flush 操作。

然后我们在 session C 中执行正常的查询语句。

这个时候,三条命令应该都卡住了,我们再来执行一下 show processlist 命令来看一下这些命令是为什么会被卡住。

mysql> show processlist;
+----+-----------------+-----------+----------+---------+-------+-------------------------+------------------------------+
| Id | User            | Host      | db       | Command | Time  | State                   | Info                         |
+----+-----------------+-----------+----------+---------+-------+-------------------------+------------------------------+
|  5 | event_scheduler | localhost | NULL     | Daemon  | 90315 | Waiting on empty queue  | NULL                         |
|  8 | root            | localhost | example1 | Query   |    15 | User sleep              | select sleep(1) from t       |
| 14 | root            | localhost | example1 | Query   |     8 | Waiting for table flush | select * from t where id = 1 |
| 15 | root            | localhost | example1 | Query   |    10 | Waiting for table flush | flush tables t               |
| 17 | root            | localhost | example1 | Query   |     0 | starting                | show processlist             |
+----+-----------------+-----------+----------+---------+-------+-------------------------+------------------------------+
5 rows in set (0.00 sec)

可以看到,语句 select * from t where id = 1 被卡住的原因是 Waiting for table flush,等待表 flush。

解决方案也很简单,同上面一样,kill 掉线程即可。比如 kill 8

等行锁

上面我们讨论可能的情况都是表锁,我们再来看一下行锁有没有可能导致查询长时间不返回。

我们先来简单的学习两个概念:共享锁和排它锁。

共享锁

共享锁又称读锁,顾名思义,共享锁就是多个事务对于同一数据可以共享一把锁,都能够访问数据,但是不能够修改。

共享锁的基本语法为 select ... lock in share mode

我们实验一下:

session Asession Bsession C
begin; select * from t where id = 1 lock in share mode;
select * from t where id = 1 lock in share mode;select * from t where id = 1 for update;(排它锁)
select * from t where id = 1;update t set c = 2 where id = 1;

我们来看一下执行结果:

session A

mysql> begin;
Query OK, 0 rows affected (0.00 sec)

mysql> select * from t where id = 1 lock in share mode;
+----+------+
| id | c    |
+----+------+
|  1 |    1 |
+----+------+
1 row in set (0.00 sec)

session B

mysql> select * from t where id = 1 lock in share mode;
+----+------+
| id | c    |
+----+------+
|  1 |    1 |
+----+------+
1 row in set (0.00 sec)

mysql> select * from t where id = 1;
+----+------+
| id | c    |
+----+------+
|  1 |    1 |
+----+------+
1 row in set (0.00 sec)

session C

mysql> select * from t where id = 1 for update;

ERROR 1205 (HY000): Lock wait timeout exceeded; try restarting transaction


mysql> update t set c = 2 where id = 1;

ERROR 1205 (HY000): Lock wait timeout exceeded; try restarting transaction

我们可以看到,当我们对一行数据获取共享锁的时候,是不能对改行执行更新操作的。但是可以执行普通查询操作,也可以加共享锁。

排它锁

排它锁又称写锁,顾名思义,排它锁就是不能与其它锁共存,如一个事务获取了一个数据行的排它锁,其他事务都不能再获取该行的其它锁,包括共享锁和排它锁,但是获取排它锁的事务是可以对改行数据进行读取和修改。

排它锁的基本语法为:select ... for update

我们继续来试验一下排它锁。

session Asession Bsession C
begin; select * from t where id = 1 for update;
select * from t where id = 1 lock in share mode;select * from t where id = 1 for update;
select * from t where id = 1;update t set c = 2 where id = 1;

我们来看一下执行结果:

session A

mysql> begin;
Query OK, 0 rows affected (0.00 sec)

mysql> select * from t where id = 1 for update;
+----+------+
| id | c    |
+----+------+
|  1 |    1 |
+----+------+
1 row in set (0.00 sec)

session B

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

ERROR 1205 (HY000): Lock wait timeout exceeded; try restarting transaction


mysql> select * from t where id = 1;
+----+------+
| id | c    |
+----+------+
|  1 |    1 |
+----+------+
1 row in set (0.00 sec)

session C

mysql> select * from t where id = 1 for update;

ERROR 1205 (HY000): Lock wait timeout exceeded; try restarting transaction


mysql> update t set c = 2 where id = 1;

ERROR 1205 (HY000): Lock wait timeout exceeded; try restarting transaction

从上面的例子我们看出,当以排它锁锁住一行数据的时候,其它事务不能在该数据上增加其它锁,无论是共享锁还是排它锁。但是可以执行基本的 select 语句,不可以执行 update 语句,因为 InnoDB 引擎默认会给 update、delete、insert 命令涉及到的语句加上排它锁。

回到正题

介绍完了共享锁和排它锁之后,我们回到正题,再来看一下复现一下行锁原因导致查询语句长时间不返回的情况。

session Asession Bsession C
begin; select * from t where id = 1 for update;
select * from t where id = 1 for update;
show processlist;

show processlist; 执行结果如下:

mysql> show processlist;
+----+-----------------+-----------+----------+---------+--------+------------------------+-----------------------------------------+
| Id | User            | Host      | db       | Command | Time   | State                  | Info                                    |
+----+-----------------+-----------+----------+---------+--------+------------------------+-----------------------------------------+
|  5 | event_scheduler | localhost | NULL     | Daemon  | 106017 | Waiting on empty queue | NULL                                    |
| 14 | root            | localhost | example1 | Sleep   |   6145 |                        | NULL                                    |
| 15 | root            | localhost | example1 | Query   |      6 | statistics             | select * from t where id = 1 for update |
| 17 | root            | localhost | example1 | Query   |      0 | starting               | show processlist                        |
| 19 | root            | localhost | example1 | Sleep   |   6271 |                        | NULL                                    |
+----+-----------------+-----------+----------+---------+--------+------------------------+-----------------------------------------+
5 rows in set (0.00 sec)

我们可以看到,导致 session B 被堵住的原因就是 session A 启动了事务,占用写锁,还不提交。

那么我们怎么查是谁占用这个写锁呢?

我们执行一下 select * from sys.innodb_lock_waits\G 命令:

mysql> select * from sys.innodb_lock_waits\G
*************************** 1. row ***************************
                wait_started: 2020-09-18 16:58:22
                    wait_age: 00:00:12
               wait_age_secs: 12
                locked_table: `example1`.`t`
         locked_table_schema: example1
           locked_table_name: t
      locked_table_partition: NULL
   locked_table_subpartition: NULL
                locked_index: PRIMARY
                 locked_type: RECORD
              waiting_trx_id: 1427156
         waiting_trx_started: 2020-09-18 16:58:22
             waiting_trx_age: 00:00:12
     waiting_trx_rows_locked: 1
   waiting_trx_rows_modified: 0
                 waiting_pid: 15
               waiting_query: select * from t where id = 1 for update
             waiting_lock_id: 4772845344:37:5:2:140375772431392
           waiting_lock_mode: X,REC_NOT_GAP
             blocking_trx_id: 1427155
                blocking_pid: 19
              blocking_query: NULL
            blocking_lock_id: 4772842824:37:5:2:140375772417568
          blocking_lock_mode: X,REC_NOT_GAP
        blocking_trx_started: 2020-09-18 16:58:20
            blocking_trx_age: 00:00:14
    blocking_trx_rows_locked: 1
  blocking_trx_rows_modified: 0
     sql_kill_blocking_query: KILL QUERY 19
sql_kill_blocking_connection: KILL 19
1 row in set (0.00 sec)

我们可以看到 blocking_pid=19。可以看到,19 号线程是造成阻塞的罪魁祸首。

从上面的查询信息中,我们还应该注意两条 kill 信息。

sql_kill_blocking_query: KILL QUERY 19
sql_kill_blocking_connection: KILL 19

KILL QUERY 19 命令的意思是 停止 19 号线程当前正在执行的语句,但是这个方法其实是没有用的。因为占有行锁的是 update 语句,这个语句之前就已经执行完成了,现在执行 KILL QUERY 命令,无法让这个事务去掉 id=1 上的行锁。

因此我们应该执行 KILL 4 命令,直接断开连接。断开连接后,会自动回滚这个连接里面正在执行的线程,也就释放了 id=1 上的行锁。

第二类:查询慢

上面说了由于各种各样的锁的原因导致查询长时间不返回,我们再来看看查询慢的问题。

我们来看一下下面这个语句,c 上没有索引。

mysql> select * from t where c = 50000;
+-------+-------+
| id    | c     |
+-------+-------+
| 50000 | 50000 |
+-------+-------+
1 row in set (0.01 sec)

那我们再想一想,那是因为这张表很小。我们来想一下,假设这种表有几百万、几千万条数据呢?还会执行这么快吗?恐怕不是,因为字段 c 没有索引,需要扫描全表,所以查询肯定回很慢。

当然这个问题解决也很简单,我们加个索引就可以了,我们这里只是简单的举个例子。

扫描行数多,扫描执行的就慢,这个我们很好理解。我们再来看一下另外一种执行慢的情况。

首先来看一下两条执行结果:

mysql> select * from t where id = 1;
+----+------+
| id | c    |
+----+------+
|  1 |    1 |
+----+------+
1 row in set (1.76 sec)
mysql> select * from t where id = 1 lock in share mode;
+----+--------+
| id | c      |
+----+--------+
|  1 | 855233 |
+----+--------+
1 row in set (0.00 sec)

很奇怪吧,为什么查一条语句加锁和不加锁执行时间竟然不一样,而且不加锁执行时间这么长。

我先给大家来说明一下这个现象复现步骤;

session Asession B
start transaction with consistent snapshot;
update t set c=c+1 where id = 1;(执行 1000000 次)
select * from t where id = 1;
select * from t where id = 1 lock in share mode;

start transaction with consistent snapshot; :一般我们会认为 begin/start transaction 是事务开始的时间点,也就是一旦我们执行了 start transaction,就认为事务已经开始了,其实这是错误的。事务开始的真正的时间点(LSN),是 start transaction 之后执行的第一条语句,不管是什么语句,不管成功与否。当想要达到将 start transaction 作为事务开始的时间点,那么我们必须使用:START TRANSACTION WITH consistent snapshot。它的含义是:执行 start transaction 同时建立本事务一致性读的 snapshot。而不是等到执行第一条语句时,才开始事务,并且建立一致性读的 snapshot。

更新一百万次的执行过程如下:

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

call update_test();

现在我再来给大家说一下为什么不加锁反而查询慢了,加锁反而查询更快。

相信大家其实已经看出问题所在了,两条查询语句的执行结果不一致,一个是 1 另一个确是 855233(其实是 1 到 1,000,001 之间的任何一个数,看你在什么时候执行加共享锁查询语句了)。

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

lock in share mode 的 SQL 语句,是当前读,因此会直接读到 855233 这个结果,所以速度很快;而 select * from t where id=1 这个语句,是一致性读,因此需要从 855233 开始,依次执行 undo log,执行了 855233 次以后,才将 1 这个结果返回。注意,undo log 里记录的其实是“把 2 改成 1”,“把 3 改成 2”这样的操作逻辑,下面这张图有助于帮你理解这个过程。

id=1 状态

总结

今天,我带着大家来看一下简单的一条 SQL 查询慢或者不返回的问题。

日常工作中,如果我们遇到了某条 SQL 执行慢的话,那么我们去优化这条 SQL 即可,一般是加索引等操作。

如果遇到了一条非常简单的 SQL 执行也很慢,那么我们应该考虑考虑其他问题了,是不是由于行锁或者表锁导致的,或者是由于一致性读导致的。

文章列举的情况可能也不全,但是希望能够当你遇到类似问题的时候,能够给你提供一些思路。

参考文档