利用sys schema解决一次诡异的语句hang问题

一、故事背景

在开始之前，先列出数据库的运行环境信息

操作系统：redhat 7.2 x8_64

文件系统：xfs

数据库版本：MySQL 5.7.17

主机配置： 
* CPU：32 vcpus 
* 内存：128 G 
* 磁盘：sandisk 单盘 SSD lvm 200G（只存放mysql的data和binlog）

主要配置参数设置：

innodb_buffer_pool_size = 96G，innodb_log_file_size = 2G，innodb_flush_method = O_DIRECT，sync_binlog = 1，innodb_flush_log_at_trx_commit = 1，innodb_thread_concurrency = 32,innodb_io_capacity = 20000，innodb_read_io_threads = 4，innodb_write_io_threads = 12，transaction_isolation = READ-COMMITTED，performance_schema=ON，binlog_rows_query_log_events=ON

该实例接入了高可用机制：HA心跳探测机制60S内发现实例持续探测失败时（每5秒探测一次），直接尝试关闭探测失败的MySQL实例和主机，进行高可用切换。

故事情节：

前些天某客户反馈一个诡异的问题，一个MySQL实例一会可访问，一会不可访问，查看相关日志发现该实例反复执行高可用切换，在进行初略排查时，通过监控发现服务器故障时刻磁盘负载都较高，但是并没有完全用满。而在高可用切换之前，数据库中跑着一些insert…select语句和大量心跳检测语句，而心跳检测语句与业务表是独立的，且心跳检测语句只固定更新一行数据，怎么会被阻塞一堆心跳检测语句呢 ？经过了一番折腾总算把原因找到了，具体过程请看下文。

二、复现与剖析

经过初略的分析，虽然业务SQL和心跳SQL操作的是不同的表，不会出现锁等待问题，但是从show processlist;的结果来看，业务SQL执行时间最长，而且不断有新的心跳语句被阻塞（当然，这里要先关掉HA的切换机制，否则待会复现操作时，过了60S就可能被切换了），看起来阻塞心跳SQL的很可能就是业务SQL。而且这些业务SQL操作的数据量多达3千万行（因为是insert…select语句，所以从慢日志或者innodb_trx表、sys.session视图中查看到的数据量实际上多达6KW，翻倍了）。但是两者之间有具体有什么关联无法直观地看出来。我们按照如下步骤进行了复现：

2.1. 首先按照线上环境标准准备好复现环境，搭建了一台测试机

2.2. 创建一张心跳表，插入一行数据

root@localhost :test:33: > CREATE TABLE `xx_heartbeat` (

 `server_id` int(10) unsigned NOT NULL,

 `hb_time` datetime NOT NULL,

 PRIMARY KEY (`server_id`)

) ENGINE=InnoDB DEFAULT CHARSET=utf8 COLLATE=utf8_bin;

root@localhost :test:33: > insert into xx_heartbeat values(@@server_id,now());

root@localhost :test:33: > select * from xx_heartbeat;

+-----------+---------------------+

| server_id | hb_time            |

+-----------+---------------------+

|  3306103 | 2017-10-11 12:33:26 |

+-----------+---------------------+

2 rows in set (0.00 sec)

2.3. 打开performance_schema中的等待事件采集(为了省事，这里使用sys schema下的函数操作，而不使用UPDATE语句直接修改performance_schema的配置表)

root@localhost :test:34: > use sys

Database changed

root@localhost : sys:36: > call ps_setup_enable_instrument('wait');

+-------------------------+

| summary                |

+-------------------------+

| Enabled 303 instruments |

+-------------------------+

1 row in set (0.04 sec)

Query OK, 0 rows affected (0.04 sec)

root@localhost : sys:36: > call ps_setup_enable_consumer('wait');

+---------------------+

| summary            |

+---------------------+

| Enabled 3 consumers |

+---------------------+

1 row in set (0.01 sec)

Query OK, 0 rows affected (0.01 sec)

2.4. 开4个MySQL会话连接，依次对4张不同的表执行insert…select操作，表数据量都为3KW（测试数据为使用sysbench造的4张3KW数据的表）

# 会话1

ADMIN@127.0.0.1 : (none):15: > use sbtest;

Database changed

ADMIN@127.0.0.1 : sbtest:37: > insert sbtest1(k,c,pad) select k,c,pad from sbtest1;

# 会话2

ADMIN@127.0.0.1 : (none):15: > use sbtest;

Database changed

ADMIN@127.0.0.1 : sbtest:37: > insert sbtest3(k,c,pad) select k,c,pad from sbtest3;

# 会话3

ADMIN@127.0.0.1 : (none):18: > use sbtest;

Database changed

ADMIN@127.0.0.1 : sbtest:37: > insert sbtest2(k,c,pad) select k,c,pad from sbtest2;

# 会话4

ADMIN@127.0.0.1 : (none):18: > use sbtest;

Database changed