一、问题由来
这是一个朋友问我的(@成都--麦涩可),原问题如下:
- 数据库发送数据给客户端这个时间算是sql的执行时间嘛?
要解决问题我们需要知道MySQL何时将数据传输给了客户端,既然是要传输实际的数据给客户端那么肯定是select语句了,同时我们要明白一个正常select运行到底要经历哪些阶段。
二、一个简单SELECT语句经历的阶段
2392 T@10: | | | | | THD::enter_stage: 'checking permissions' /root/mysql5.7.14/percona-server-5.7.14-7/sql/auth/sql_authorization.cc:843
2404 T@10: | | | | | | THD::enter_stage: 'Opening tables' /root/mysql5.7.14/percona-server-5.7.14-7/sql/sql_base.cc:5719
2512 T@10: | | | | | THD::enter_stage: 'init' /root/mysql5.7.14/percona-server-5.7.14-7/sql/sql_select.cc:121
2681 T@10: | | | | | | | THD::enter_stage: 'System lock' /root/mysql5.7.14/percona-server-5.7.14-7/sql/lock.cc:321
2772 T@10: | | | | | | | THD::enter_stage: 'optimizing' /root/mysql5.7.14/percona-server-5.7.14-7/sql/sql_optimizer.cc:151
2865 T@10: | | | | | | | THD::enter_stage: 'statistics' /root/mysql5.7.14/percona-server-5.7.14-7/sql/sql_optimizer.cc:386
3329 T@10: | | | | | | | THD::enter_stage: 'preparing' /root/mysql5.7.14/percona-server-5.7.14-7/sql/sql_optimizer.cc:494
3466 T@10: | | | | | | THD::enter_stage: 'executing' /root/mysql5.7.14/percona-server-5.7.14-7/sql/sql_executor.cc:119
3474 T@10: | | | | | | THD::enter_stage: 'Sending data' /root/mysql5.7.14/percona-server-5.7.14-7/sql/sql_executor.cc:195
3668 T@10: | | | | | THD::enter_stage: 'end' /root/mysql5.7.14/percona-server-5.7.14-7/sql/sql_select.cc:199
3685 T@10: | | | | THD::enter_stage: 'query end' /root/mysql5.7.14/percona-server-5.7.14-7/sql/sql_parse.cc:5174
3754 T@10: | | | | THD::enter_stage: 'closing tables' /root/mysql5.7.14/percona-server-5.7.14-7/sql/sql_parse.cc:5252
3882 T@10: | | | THD::enter_stage: 'freeing items' /root/mysql5.7.14/percona-server-5.7.14-7/sql/sql_parse.cc:5855
实际上整个阶段都算到了语句的实际消耗时间之中的,但是慢查询记录的是:
- 实际执行时间 = (freeing items 末端的时间) 实际消耗时间 - (System lock末端的时间 )比如MDL LOCK等待时间 - (Innodb层锁定的时间)行锁等待消耗时间
关于慢查询的详细情况可以参考我的一篇文章,这里不再重述。
#####https://www.jianshu.com/p/1ffadf29d6c0 MySQL慢查询记录原理和内容解析
三、什么是Sending data状态
实际上这个状态是select语句才会有的,如果是DML则不同但是都有等同的阶段如下:
- select:Sending data
- insert语句:Update
- delete/update:Updating
这个阶段非常的巨大,它至少包含了:
- Innodb 层数据的定位返回给MySQL 层
- Innodb 层数据的查询返回给MySQL 层
- Innodb 层数据的修改(如果是MDL)
- Innodb 层加锁以及等待
- 等待进入Innodb层(innodb_thread_concurrency参数)
- MySQL 层发送数据给客户端
可以看到基本所有和Innodb层打交道的过程都包裹在这个状态下面,当然我只是列举了我想到的一些,其实可能还有很多很多,这里我也把 MySQL 层发送数据给客户端包含在 Sending data的答案给出了,下面我们进行分析。
四、如何证明Sending data状态包含了网络数据传输的时间
之前你可以参考一下我的文章
https://www.jianshu.com/p/25fed8f1f05e MySQL:Innodb Handler_read_*变量解释
我们建立一个简单的表如下,并且填充数据如下:
Create Table: CREATE TABLE `ty` (
`id` int(11) NOT NULL AUTO_INCREMENT,
`a` int(11) DEFAULT NULL,
`b` int(11) DEFAULT NULL,
PRIMARY KEY (`id`),
KEY `idxa` (`a`)
) ENGINE=InnoDB AUTO_INCREMENT=12 DEFAULT CHARSET=utf8mb4
mysql> select * from ty;
+----+------+------+
| id | a | b |
+----+------+------+
| 8 | 2 | 3 |
| 9 | 5 | 4 |
| 10 | 6 | 7 |
| 11 | 6 | 8 |
+----+------+------+
4 rows in set (4.14 sec)
我们执行如下语句:
mysql> desc select * from ty where a =6 and b=8;
+----+-------------+-------+------------+------+---------------+------+---------+-------+------+----------+-------------+
| id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra |
+----+-------------+-------+------------+------+---------------+------+---------+-------+------+----------+-------------+
| 1 | SIMPLE | ty | NULL | ref | idxa | idxa | 5 | const | 2 | 33.33 | Using where |
+----+-------------+-------+------------+------+---------------+------+---------+-------+------+----------+-------------+
mysql> select * from ty where a =6 and b=8;
+----+------+------+
| id | a | b |
+----+------+------+
| 11 | 6 | 8 |
+----+------+------+
1 row in set (7.22 sec)
注意:这里的语句执行时间很长是因为我打了GDB断点所以看起来很久而已
我做了语句的trace,这个语句大概需要如下步骤:
- 首先Innodb定位到索引
idxa
数据6所在位置这是初次定位调用函数ha_innobase::index_read,返回数据| 10 | 6 | 7 |给MySQL层,但是MySQL层过滤掉不符合条件 a =6 and b=8 不需要返回给客户端。
1547 T@12: | | | | | | | | >handler::ha_index_read_map
1548 T@12: | | | | | | | | | >index_read (这里进行初次访问索引定位)
1552 T@12: | | | | | | | | | | >row_search_mvcc
1553 T@12: | | | | | | | | | | | >btr_cur_search_to_nth_level
1554 T@12: | | | | | | | | | | | <btr_cur_search_to_nth_level 2009
...
1593 T@12: | | | | | | | | | | <row_search_mvcc 6070
1594 T@12: | | | | | | | | | <index_read 9179
1595 T@12: | | | | | | | | <handler::ha_index_read_map 3190
1596 T@12: | | | | | | | | >evaluate_join_record (这里进入MySQL 层where条件判断流程,不满足不发送)
...
1600 T@12: | | | | | | | | <evaluate_join_record 1701
- 定位完成后再次访问索引
idxa
的下一条数据,Innodb直接读取就好了调用函数ha_innobase::index_next_same,返回数据| 11 | 6 | 8 |给Mysql层,因为满足条件 a =6 and b=8所以返回给客户端
。
1601 T@12: | | | | | | | | >handler::ha_index_next_same(这里就是顺序访问索引的下一行数据了)
1602 T@12: | | | | | | | | | >general_fetch
1603 T@12: | | | | | | | | | | >row_search_mvcc
....
1607 T@12: | | | | | | | | | | <row_search_mvcc 6070
1608 T@12: | | | | | | | | | <general_fetch 9487
1609 T@12: | | | | | | | | <handler::ha_index_next_same 3414
1610 T@12: | | | | | | | | >evaluate_join_record(这里进入MySQL 层where条件判断流程,满足条件需要发送)
1613 T@12: | | | | | | | | | >end_send
1614 T@12: | | | | | | | | | | >Query_result_send::send_data(这里就是发送数据给客户端了,也就是通过网络发送数据给客户端了)
1615 T@12: | | | | | | | | | | | >send_result_set_row
1616 T@12: | | | | | | | | | | | <send_result_set_row 4967
1620 T@12: | | | | | | | | | | <Query_result_send::send_data 2915
1621 T@12: | | | | | | | | | | >Protocol_classic::end_row
1622 T@12: | | | | | | | | | | <Protocol_classic::end_row 1198
1625 T@12: | | | | | | | | | <end_send 2991
1626 T@12: | | | | | | | | <evaluate_join_record 1701
- 因为是非唯一索引因此需要再次访问下一条数据来判断已经读取了所有a=6的数据,因此Innodb需要在读取索引
idxa
的下一条数据调用函数ha_innobase::index_next_same。
1627 T@12: | | | | | | | | >handler::ha_index_next_same(这里就是顺序访问索引的下一行数据了)
1628 T@12: | | | | | | | | | >general_fetch
1629 T@12: | | | | | | | | | | >row_search_mvcc
...
1639 T@12: | | | | | | | | | | <row_search_mvcc 6070
1640 T@12: | | | | | | | | | <general_fetch 9487
1641 T@12: | | | | | | | | <handler::ha_index_next_same 3414
所以总结整个流程一共经历了一次索引定位,两次索引顺序读取,一共读取了三条数据,但是返回给MySQL层的只有前面两条数据,通过MySQL层的过滤只发送给了客户端一条满足条件的数据。
五、总结
很显然数据返回给客户端的时间包含在了整个语句的实际消耗时间中,同时包含在了慢查询的实际执行时间(Query_time指标)中,它是在sending data状态下完成的。
作者微信:gp_22389860