Mysql单条查询性能剖析 show profile

有时候我们在mysql的slowlog中发现一条慢查询，分析这条sql，除了使用explain查看执行计划外，想查询这条sql语句的每个步骤及其花费时间，可以使用show profile工具。
profiling 是由会话变量 profling 控制的，默认情况下是关闭的[off]，设置profiling变量为1或者on打开查询剖析记录。

mysql> SET profiling = 1;

show profiles 展示了当前会话最近的查询记录列表，列表的数量是由会话变量 profiling_history_size 控制的，默认为15条，最大可以设置为100条，如果会话查询数量超过这个变量设置后，新查询会顶替老查询。

mysql> SET profiling_history_size = 20;

除了 SHOW PROFILE 和 SHOW PROFILES外的所有查询语句都会被记录，即使是语法错误的语句。当一条查询提交给服务器时，此工具会记录剖析信息到一张临时表。并给与每个查询一个从1开始的自增id。使用show profile指定id 查询相应的执行步骤及时间消耗。

mysql> SHOW PROFILE for query_id = id;

如果SHOW PROFILE没有指定id，默认显示最近查询的一条的执行详情。
show profile默认展示的是执行步骤和花费的时间，同时通过指定type参数，提供了cpu，内存，io消耗以及更多的信息。

mysql> SHOW PROFILE [all|cpu|memory|block io]for query_id = id;

show profile输出是按照执行步骤顺序排序，而不是按照时间花费排序，因此我们很难看出具体是哪几部的消耗最大。但是show profile输出又不能使用类似order by的排序。幸运的是mysql同时把剖析记录写入INFORMATION_SCHEMA.PROFILING这张临时表中。所以我们可以按需格式话输出

mysql> SET @query_id = id;

mysql> SELECT
    state,
    sum(duration) AS total_r,
    round(
        100 * sum(duration) / (
            SELECT
                sum(duration)
            FROM
                information_schema.profiling
            WHERE
                query_id = @query_id
        ),
        2
    ) AS pct_r,
    count(*) AS calls,
    sum(duration) / count(*) AS "r/call"
FROM
    information_schema.profiling
WHERE
    query_id = @query_id
GROUP BY
    state
ORDER BY
    total_r DESC;

上面的sql 会统计计算查询每一部的次数，消耗时间，占查询的时间比，以及每一步的平均消耗时间，并且按照时间逆序，这样我们就能很方便的知道sql的开销在哪里。

查考
mysql手册
高性能MySQL