mysql 深入sql分析（ trace 和 show profile）

show profile 分析慢查询

NO.1 使用 profile 分析慢查询

大致步骤：

确定这个 MySQL 版本是否支持 profile；确定 profile 是否关闭；如果关闭开启 profile；在服务器端发送要执行的 SQL；查看执行完 SQL 的 query id；通过 query id 查看 SQL 的每个状态及耗时时间；停止profile；

获取profile 使用 help profile即可

mysql> help profile;

mysql 深入sql分析（ trace 和 show profile）

1.1 确定是否支持 profile

mysql> select @@have_profiling;

mysql 深入sql分析（ trace 和 show profile）

如果结果是YES表示支持。

1.2 查看 profiling 状态

mysql> select @@profiling;

mysql 深入sql分析（ trace 和 show profile）

0表示关闭，1表示开启，默认是关闭的。

使用如下命令开启：mysql> set profiling=1;

1.3 执行要分析的sql语句

mysql> select * from test_table where d=90000;

执行完成SQL后再执行：show profiles；得到profile id。

mysql 深入sql分析（ trace 和 show profile）

1.4 根据profile id查询指定SQL执行详情

通过 show profile for query id 可看到执行过的 SQL 每个状态和消耗时间：

MySQL [test]> show profile for query 1;

mysql 深入sql分析（ trace 和 show profile）

processlist中状态详解：》》》》 https://blog.****.net/qq_40026782/article/details/105773187

通过以上结果，可以确定 SQL 执行过程具体在哪个过程耗时比较久，从而更好地进行 SQL 优化与调整。

注意：“show profiles”已弃用，SHOW PROFILES将来会被Performance Schema替换掉，但是现在还是非常非常实用的，8.0目前还在支持中。

小计：实用show profile 可以直接查看上一条SQL语句的执行开销

MySQL [test]> show profile;

mysql 深入sql分析（ trace 和 show profile）

NOTE：show profile自身不会产生Profiling。

查看指定SQL的CPU开销：MySQL [test]> show profile cpu for query 1;

查询指定SQL的内存开销：MySQL [test]> show profile memory for query 1;

小技巧：给大家分享一条SQL，查询某条SQL开销并且按照耗时倒叙排序

SET @query_id = 1; // 设置要查询的 profile id，然后执行如下SQL即可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;

mysql 深入sql分析（ trace 和 show profile）

注意：Mysql所有的profile都被记录到了information_schema.profiling表。

1.5 关闭profile

mysql> set profiling=off;

trace 分析 SQL 优化器

从前面学到了 explain 可以查看 SQL 执行计划，但是无法知道它为什么做这个决策，如果想确定多种索引方案之间是如何选择的或者排序时选择的是哪种排序模式，有什么好的办法吗？

从 MySQL 5.6 开始，可以使用 trace 查看优化器如何选择执行计划。

通过trace，能够进一步了解为什么优化器选择A执行计划而不是选择B执行计划，或者知道某个排序使用的排序模式，帮助我们更好地理解优化器行为。

如果需要使用，先开启 trace，设置格式为 JSON，再执行需要分析的 SQL，最后查看 trace 分析结果（在 information_schema.OPTIMIZER_TRACE 中）。

mysql 深入sql分析（ trace 和 show profile）

注意：开启该功能，会对 MySQL 性能有所影响，因此只建议分析问题时临时开启。

这里利用我们上篇：MySQL优化：定位慢查询的两种方法以及使用explain分析SQL中创建的数据表test_table;

在test_table中除了d字段，abc字段都有索引。执行如下sql

explain select * from test_table where a=90000 and b=90000 order by a;

mysql 深入sql分析（ trace 和 show profile）

通过上面执行计划中 key 这个字段可以看出，该语句使用的是 b 字段的索引 idx_a。实际表 t1 中，a、b 两个字段都有索引，为什么条件中有这两个索引字段却偏偏选了 a 字段的索引呢？这时就可以使用 trace 进行分析。

MySQL5.6提供了对SQL的跟踪trace，通过trace文件能够进一步了解为什么优化器选择A执行计划而不是选择B执行计划，帮助我们更好地理解优化器行为。

使用方式：首先打开trace，设置格式为JSON，设置trace最大能够使用的内存大小，避免解析过程中因为默认内存过小而不能够完整显示。

mysql> SET OPTIMIZER_TRACE="enabled=on",END_MARKERS_IN_JSON=on;
Query OK, 0 rows affected (0.01 sec)

mysql> SET OPTIMIZER_TRACE_MAX_MEM_SIZE=1000000;
Query OK, 0 rows affected (0.02 sec)
接下来执行想做trace 的SQL语句，例如想了解租赁表rental 中库存编号inventory_id 为4466 的电影拷贝在出租日期rental_date 为

2005-05-25 4：00：00~~5：00：00之间出租的记录。

mysql> select rental_id from rental where 1=1 and rental_date >='2005-05-25 04:00:00'
-> and rental_date <='2005-05-25 05:00:00'and inventory_id=4466;
+-----------+
| rental_id |
+-----------+
| 39 |
+-----------+
1 row in set (0.18 sec)
最后，检查INFORMATION_SCHEMA.OPTIMIZER_TRACE 就可以知道MYSQL是如何执行SQL的：

SELECT * FROM INFORMATION_SCHEMA.OPTIMIZER_TRACE;
最后会输出一个格式如下的跟踪文件：

-----------------------------+-----------------------------------+-------------------------+
| select rental_id from rental where 1=1 and rental_date >='2005-05-25 04:00:00'
and rental_date <='2005-05-25 05:00:00'and inventory_id=4466 | {
"steps": [
{
"join_preparation": {
"select#": 1,
"steps": [
{
"expanded_query": "/* select#1 */ select `rental`.`rental_id` AS `rental_id` from `rental` where ((1 = 1) and (`rental`.`rental_date` >= '2005-05-25 04:00:00') and (`rental`.`rental_date` <= '2005-05-25 05:00:00') and (`rental`.`inventory_id` = 4466))"
}
] /* steps */
} /* join_preparation */
},
{
"join_optimization": {
"select#": 1,
"steps": [
{
"condition_processing": {
"condition": "WHERE",
"original_condition": "((1 = 1) and (`rental`.`rental_date` >= '2005-05-25 04:00:00') and (`rental`.`rental_date` <= '2005-05-25 05:00:00') and (`rental`.`inventory_id` = 4466))",
"steps": [
{
"transformation": "equality_propagation",
"resulting_condition": "((1 = 1) and (`rental`.`rental_date` >= '2005-05-25 04:00:00') and (`rental`.`rental_date` <= '2005-05-25 05:00:00') and multiple equal(4466, `rental`.`inventory_id`))"
},
{
"transformation": "constant_propagation",
"resulting_condition": "((1 = 1) and (`rental`.`rental_date` >= '2005-05-25 04:00:00') and (`rental`.`rental_date` <= '2005-05-25 05:00:00') and multiple equal(4466, `rental`.`inventory_id`))"
},
{
"transformation": "trivial_condition_removal",
"resulting_condition": "((`rental`.`rental_date` >= '2005-05-25 04:00:00') and (`rental`.`rental_date` <= '2005-05-25 05:00:00') and multiple equal(4466, `rental`.`inventory_id`))"
}
] /* steps */
} /* condition_processing */
},
{
"substitute_generated_columns": {
} /* substitute_generated_columns */
},
{
"table_dependencies": [
{
"table": "`rental`",
"row_may_be_null": false,
"map_bit": 0,
"depends_on_map_bits": [
] /* depends_on_map_bits */
}
] /* table_dependencies */
},
{
"ref_optimizer_key_uses": [
{
"table": "`rental`",
"field": "inventory_id",
"equals": "4466",
"null_rejecting": false
}
] /* ref_optimizer_key_uses */
},
{
"rows_estimation": [
{
"table": "`rental`",
"range_analysis": {
"table_scan": {
"rows": 16008,
"cost": 1667.4
} /* table_scan */,
"potential_range_indexes": [
{
"index": "PRIMARY",
"usable": false,
"cause": "not_applicable"
},
{
"index": "rental_date",
"usable": true,
"key_parts": [
"rental_date",
"inventory_id",
"customer_id"
] /* key_parts */
},
{
"index": "idx_fk_inventory_id",
"usable": true,
"key_parts": [
"inventory_id",
"rental_id"
] /* key_parts */
},
{
"index": "idx_fk_customer_id",
"usable": false,
"cause": "not_applicable"
},
{
"index": "idx_fk_staff_id",
"usable": false,
"cause": "not_applicable"
}
] /* potential_range_indexes */,
"best_covering_index_scan": {
"index": "rental_date",
"cost": 1607.9,
"chosen": true
} /* best_covering_index_scan */,
"setup_range_conditions": [
] /* setup_range_conditions */,
"group_index_range": {
"chosen": false,
"cause": "not_group_by_or_distinct"
} /* group_index_range */,
"analyzing_range_alternatives": {
"range_scan_alternatives": [
{
"index": "rental_date",
"ranges": [
"0x9975b24000 <= rental_date <= 0x9975b25000"
] /* ranges */,
"index_dives_for_eq_ranges": true,
"rowid_ordered": false,
"using_mrr": false,
"index_only": true,
"rows": 10,
"cost": 1.2638,
"chosen": true
},
{
"index": "idx_fk_inventory_id",
"ranges": [
"4466 <= inventory_id <= 4466"
] /* ranges */,
"index_dives_for_eq_ranges": true,
"rowid_ordered": true,
"using_mrr": false,
"index_only": false,
"rows": 5,
"cost": 4.4994,
"chosen": false,
"cause": "cost"
}
] /* range_scan_alternatives */,
"analyzing_roworder_intersect": {
"usable": false,
"cause": "too_few_roworder_scans"
} /* analyzing_roworder_intersect */
} /* analyzing_range_alternatives */,
"chosen_range_access_summary": {
"range_access_plan": {
"type": "range_scan",
"index": "rental_date",
"rows": 10,
"ranges": [
"0x9975b24000 <= rental_date <= 0x9975b25000"
] /* ranges */
} /* range_access_plan */,
"rows_for_plan": 10,
"cost_for_plan": 1.2638,
"chosen": true
} /* chosen_range_access_summary */
} /* range_analysis */
}
] /* rows_estimation */
},
{
"considered_execution_plans": [
{
"plan_prefix": [
] /* plan_prefix */,
"table": "`rental`",
"best_access_path": {
"considered_access_paths": [
{
"access_type": "ref",
"index": "idx_fk_inventory_id",
"rows": 5,
"cost": 3.8245,
"chosen": true
},
{
"rows_to_scan": 10,
"access_type": "range",
"range_details": {
"used_index": "rental_date"
} /* range_details */,
"resulting_rows": 10,
"cost": 2.2638,
"chosen": true
}
] /* considered_access_paths */
} /* best_access_path */,
"condition_filtering_pct": 100,
"rows_for_plan": 10,
"cost_for_plan": 2.2638,
"chosen": true
}
] /* considered_execution_plans */
},
{
"attaching_conditions_to_tables": {
"original_condition": "((`rental`.`inventory_id` = 4466) and (`rental`.`rental_date` >= '2005-05-25 04:00:00') and (`rental`.`rental_date` <= '2005-05-25 05:00:00'))",
"attached_conditions_computation": [
] /* attached_conditions_computation */,
"attached_conditions_summary": [
{
"table": "`rental`",
"attached": "((`rental`.`inventory_id` = 4466) and (`rental`.`rental_date` >= '2005-05-25 04:00:00') and (`rental`.`rental_date` <= '2005-05-25 05:00:00'))"
}
] /* attached_conditions_summary */
} /* attaching_conditions_to_tables */
},
{
"refine_plan": [
{
"table": "`rental`"
}
] /* refine_plan */
}
] /* steps */
} /* join_optimization */
},
{
"join_execution": {
"select#": 1,
"steps": [
] /* steps */
} /* join_execution */
}
] /* steps */
} | 0 | 0 |

大致步骤如下：

开启trace分析器执行要查询的sql查看分析结果关闭trace分析器

NO.1 开启trace分析器

MySQL [test]> set session optimizer_trace="enabled=on";

NO.2 执行要查询的SQL

MySQL [test]> select * from test_table where a=90000 and b=90000 order by a;

NO.3 查询分析结果

MySQL [test]> SELECT * FROM information_schema.OPTIMIZER_TRACE\G

注意：在返回的steps数组中可以查看详细mysql都干了什么。

不好意思，因为排版导致内容太长大家可以百度一下参数含义。

NO.4 关闭trace分析器

mysql> set session optimizer_trace="enabled=off";

TRACE 字段中整个文本大致分为三个过程

准备阶段：对应文本中的 join_preparation优化阶段：对应文本中的 join_optimization执行阶段：对应文本中的 join_execution

使用时，重点关注优化阶段和执行阶段。

知识点拓展：

知识点一：MySQL 常见排序模式：

< sort_key, rowid >双路排序（又叫回表排序模式）：是首先根据相应的条件取出相应的排序字段和可以直接定位行数据的行 ID，然后在 sort buffer 中进行排序，排序完后需要再次取回其它需要的字段；< sort_key, additional_fields >单路排序：是一次性取出满足条件行的所有字段，然后在sort buffer中进行排序；< sort_key, packed_additional_fields >打包数据排序模式：将 char 和 varchar 字段存到 sort buffer 中时，更加紧缩。

三种排序模式比较：

第二种模式相对第一种模式，避免了二次回表，可以理解为用空间换时间。由于 sort buffer 有限，如果需要查询的数据比较大的话，会增加磁盘排序时间，效率可能比第一种方式更低。MySQL 提供了一个参数：max_length_for_sort_data，当“排序的键值对大小” > max_length_for_sort_data 时，MySQL 认为磁盘外部排序的 IO 效率不如回表的效率，会选择第一种排序模式；否则，会选择第二种模式。第三种模式主要解决变长字符数据存储空间浪费的问题。知识点二：优化器在估计符合条件的行数时有两个选择：

index diver：dive 到 index 中利用索引完成元组数的估算；特点是速度慢，但可以得到精确的值；

index statistics：使用索引的统计数值，进行估算；特点是速度快，但是值不一定准确。

总结

今天我们分享了 show profile 和 trace 的使用方法，我们来对比一下三种分析 SQL 方法的特点：

explain：获取 MySQL 中 SQL 语句的执行计划，比如语句是否使用了关联查询、是否使用了索引、扫描行数等；

profile：可以清楚了解到SQL到底慢在哪个环节；

trace：查看优化器如何选择执行计划，获取每个可能的索引选择的代价。

三种方法各有其适用场景，如果你有其它分析 SQL 的工具，欢迎在留言区分享。

最后推荐大家一款小米开源的sql分析工具：soar-web

你们的支持是我写优质文章最大的动力，如果喜欢请关注我。谢谢

mysql 深入sql分析 （ trace 和 show profile）

相关推荐

mysql 深入sql分析（ trace 和 show profile）