MySQL · 案例分析 · Waiting for table flush

发表于 | 更新于 | 分类于 | 阅读次数：

背景

MES 工厂反馈业务查询慢，登录数据库手工执行 SQL 操作也没有响应，怀疑是 02:00 执行的备份任务导致。

分析

  • 登录数据库，执行 show processlist 查看当前会话，发现大量线程状态为 Waiting for tables flush。
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
mysql> show processlist;
+---------+-----------------+----------------------+--------------------+-------------+-------+---------------------------------------------------------------+------------------------------------------------------------------------------------------------------+
| Id      | User            | Host                 | db                 | Command     | Time  | State                                                         | Info                                                                                                 |
+---------+-----------------+----------------------+--------------------+-------------+-------+---------------------------------------------------------------+------------------------------------------------------------------------------------------------------+
| 3074726 | cosmo_dsj       | 10.138.225.194:41311 | NULL               | Binlog Dump | 31808 | Master has sent all binlog to slave; waiting for more updates | NULL                                                                                                 |
| 3080884 | cosmo_t         | %                    | cosmo_im_1021      | Connect     | 12515 | Sending data                                                  | CALL  procedure_imp_table                                                                            |
| 3082179 | cosmo_t         | 10.138.228.42:36560  | cosmo_im_1021      | Sleep       |    19 |                                                               | NULL                                                                                                 |
| 3082727 | root            | localhost            | NULL               | Query       |  6180 | Waiting for table flush                                       | FLUSH NO_WRITE_TO_BINLOG TABLES                                                                      |
| 3082888 | cosmo_r         | 10.180.221.43:52153  | cosmo_im_1021      | Sleep       |     5 |                                                               | NULL                                                                                                 |
| 3082892 | cosmo_r         | 10.180.221.43:52155  | cosmo_im_1021      | Sleep       |     1 |                                                               | NULL                                                                                                 |
| 3082919 | cosmo_t         | %                    | cosmo_im_1021      | Connect     |  6125 | Waiting for table flush                                       | CALL procedure_assembly_work                                                                         |
| 3082940 | cosmo_t         | %                    | cosmo_im_1021      | Connect     |  6104 | Waiting for table flush                                       | UPDATE board_datas bo inner join (
            SELECT times,
                   cNum                 |
| 3083094 | cosmo_t         | 10.180.221.45:59111  | cosmo_im_1021      | Query       |     6 | Waiting for table flush                                       | SELECT a.*,TIMESTAMPDIFF(MINUTE,a.CallTime,NOW()) as Tdiff from
(SELECT DISTINCT pmcall.Call_ID ,ca |
| 3083127 | cosmo_t         | %                    | cosmo_im_1021      | Connect     |  5924 | Waiting for table flush                                       | UPDATE board_datas bo inner join (
            SELECT times,
                   cNum                 |
| 3083260 | cosmo_t         | %                    | cosmo_im_1021      | Connect     |  5744 | Waiting for table flush                                       | UPDATE board_datas bo inner join (
            SELECT times,
                   cNum                 |

  • 找到首次出现此状态执行的操作 FLUSH NO_WRITE_TO_BINLOG TABLES，执行时间 6125s，线程ID 3082727，这是 XtraBackup 执行全量备份的一个线程，主要作用是关闭所有打开的表，强制关闭所有正在使用的表，并刷新查询缓存和预准备语句缓存。

  • 备份正常执行这个操作是不会锁表的，但是如果在此期间存在慢查询 CALL procedure_imp_table，执行时间 12515s，线程ID 3080884，就会占用全局只读锁，阻止关闭打开的表。

  • 结论：使用 mysqldump、XtraBackup 备份期间出现了慢查询并且慢查询长时间阻塞，就会出现 Waiting for tables flush。

解决

  • 找出超时的慢查询，执行 kill 3080884 ，问题解决
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
mysql> kill 3080884;
Query OK, 0 rows affected (0.00 sec)

mysql> show processlist;
+---------+-----------------+----------------------+--------------------+-------------+-------+---------------------------------------------------------------+------------------------------------------------------------------------------------------------------+
| Id      | User            | Host                 | db                 | Command     | Time  | State                                                         | Info                                                                                                 |
+---------+-----------------+----------------------+--------------------+-------------+-------+---------------------------------------------------------------+------------------------------------------------------------------------------------------------------+
|       1 | event_scheduler | localhost            | NULL               | Daemon      |     4 | Waiting for next activation                                   | NULL                                                                                                 |
| 3061488 | cosmo_t         | 10.180.199.156:49161 | cosmo_im_1021      | Sleep       |    34 |                                                               | NULL                                                                                                 |
| 3074726 | cosmo_dsj       | 10.138.225.194:41311 | NULL               | Binlog Dump | 31920 | Master has sent all binlog to slave; waiting for more updates | NULL                                                                                                 |
| 3080883 | cosmo_t         | 10.138.42.106:42146  | cosmo_im_1021      | Sleep       |   144 |                                                               | NULL                                                                                                 |
| 3081434 | cosmo_t         | 10.138.42.106:44741  | cosmo_im_1021      | Sleep       |   144 |                                                               | NULL                                                                                                 |
| 3082179 | cosmo_t         | 10.138.228.42:36560  | cosmo_im_1021      | Sleep       |   131 |                                                               | NULL                                                                                                 |
| 3082888 | cosmo_r         | 10.180.221.43:52153  | cosmo_im_1021      | Sleep       |     1 |                                                               | NULL                                                                                                 |
| 3082892 | cosmo_r         | 10.180.221.43:52155  | cosmo_im_1021      | Sleep       |     4 |                                                               | NULL                                                                                                 |
| 3083094 | cosmo_t         | 10.180.221.45:59111  | cosmo_im_1021      | Sleep       |    27 |                                                               | NULL                                                                                                 |
| 3083531 | cosmo_r         | 10.180.207.197:61769 | cosmo_im_1021      | Sleep       |     3 |                                                               | NULL