mysql查看sql执行时间

查看SQL执行时间步骤

1.show profiles

2.show variables查看profiling 是否是on状态；

3.如果是off，则执行命令 set profiling=1

4.执行SQL语句

5.show profiles 就可以查询到SQL语句的执行时间

MYSQL_OPT_READ_TIMEOUT 是 MySQL c api 客户端中用来设置读取超时时间的参数。在 MySQL 的官方文档中，该参数的描述是这样的：

MYSQL_OPT_READ_TIMEOUT (argument type: unsigned int *)The timeout in seconds for each attempt to read from the server. There are retries if necessary, so the total effective timeout value is three times the option value. You can set the value so that a lost connection can be detected earlier than the TCP/IPClose_Wait_Timeout value of 10 minutes.

也就是说在需要的时候，实际的超时时间会是设定值的 3 倍。但是实际测试后发现实际的超时时间和设置的超时时间一致。

而具体什么时候发生三倍超时，在文档中没有找到。所以对 MySQL 5.7.20 的源码进行了一些分析。

使用 GDB 调试代码找了实际与 mysql server 通信的代码，如下：

请点击输入图片描述

其中 vio_read() 函数中，使用 recv 和 poll 来读取报文和做读取超时。net_should_retry() 函数只有在发生 EINTR 时才会返回 true。从这段代码来看是符合测试结果的，并没有对读取进行三次重试。只有在读取 *** 作被系统中断打断时才会重试，但是这个重试并没有次数限制。

从上面代码的分析可以看出，代码的逻辑和文档的描述不符。于是在一顿搜索后，找到了一个 MySQL 的 BUG(Bug #31163)。该 BUG 报告了在 MySQL 5.0 中，MySQL c api 读取的实际超时时间是设置的三倍，与现有文档描述相符。于是对 MySQL 5.0.96 的代码又进行分析。

同样使用 GDB 找到了通信部分的代码。这次找到了重试三次的代码，如下：

请点击输入图片描述

这个版本的 MySQL api 的读写超时是直接使用的 setsockopt 设置的。第一次循环，在 A 点发生了第一次超时（虽然注释写的非阻塞，但是客户端的连接始终是阻塞模式的）。然后在 B 点将该 socket 设置为阻塞模式，C 点这里重置 retry 次数。由于设置了 alarm 第二次以后的循环会直接进入 D 点的这个分支，并且判断循环次数。作为客户端时net->retry_count 始终是 1，所以重试了两次，共计进行了 3 次 vioread 后从 E 点退出函数。

由上面的分析可知，MySQL 文档对于该参数的描述已经过时，现在的 MYSQL_OPT_READ_TIMEOUT 并不会出现三倍超时的问题。而 Bug #31163 中的处理结果也是将文档中该参数的描述更新为实际读取超时时间是设定时间的三倍。也许是 MySQL 的维护者们在后续版本更新时忘记更新文档吧。

右下角的时间是从点击查询到输出查询结果的总时间，而profile中的是收集在执行语句的时候所使用的资源，包括执行sql时完整的数据查询逻辑明细及耗时时间，其中包含查询语句执行时间、索引排序时间、查询结果展示时间等

---