实际的日常开发工作中可能会遇到某个新功能在测试时需要很久才返回结果,这时就应该分析是不是慢查询导致的,如果确实有慢查询,就需要来学习怎么找到慢查询和怎么分析 SQL 执行效率?
定位慢 SQL 有如下两种解决方案:
定位到慢查询语句后,可以通过 explain、show profile 和 trace 等诊断工具来分析慢查询
如果需要使用慢查询日志,一般分为四步:
开启慢查询日志、设置慢查询阀值、确定慢查询日志路径、确定慢查询日志的文件名;
涉及到的命令如下:
set global slow_query_log = on; set global long_query_time = 1; show global variables like "datadir"; show global variables like "slow_query_log_file";
如果觉得系统自带的慢查询日志不方便查看,也可以使用mysqldumpslow 等工具对慢查询日志进行分析;
mysqldumpslow经常使用的参数:
-s,是order的顺序
----- al 平均锁定时间
-----ar 平均返回记录时间
-----at 平均查询时间(默认)
-----c 计数
-----l 锁定时间
-----r 返回记录
-----t 查询时间
-t,是top n的意思,即为返回前面多少条的数据
-g,后边可以写一个正则匹配模式,大小写不敏感的
基本命令如下:
mysqldumpslow -t 10 -s t -g “left join” slow.log
show processlist 命令判断正在执行的慢查询。show processlist 显示哪些线程正在运行。如果有 PROCESS 权限,则可以看到所有线程。否则,只能看到当前会话的线程;
定位到慢查询语句后,我们就要开始分析 SQL 执行效率了;
简单的数据准备工作:
CREATE DATABASE test; use test; drop table if exists t1; CREATE TABLE `t1` ( `id` int NOT NULL auto_increment, `a` int DEFAULT NULL, `b` int DEFAULT NULL, `create_time` datetime NOT NULL DEFAULT CURRENT_TIMESTAMP COMMENT '记录创建时间', `update_time` datetime NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP COMMENT '记录更新时间', PRIMARY KEY (`id`), KEY `idx_a` (`a`), KEY `idx_b` (`b`) ) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4; drop procedure if exists insert_t1; delimiter ;; create procedure insert_t1() begin declare i int; set i=1; while(i<=1000)do insert into t1(a,b) values(i, i); set i=i+1; end while; end;; delimiter ; call insert_t1(); drop table if exists t2; create table t2 like t1; insert into t2 select * from t1;
explain分析结果:
explain返回结果各字段说明:
列名 | 解释 |
---|---|
id | 查询编号 |
select_type | 查询类型:显示本行是简单还是复杂查询 |
table | 涉及到的表 |
partitions | 匹配的分区:查询将匹配记录所在的分区。仅当使用 partition 关键字时才显示该列。对于非分区表,该值为 NULL。 |
type | 本次查询的表连接类型 |
possible_keys | 可能选择的索引 |
key | 实际选择的索引 |
key_len | 被选择的索引长度:一般用于判断联合索引有多少列被选择了 |
ref | 与索引比较的列 |
rows | 预计需要扫描的行数,对 InnoDB 来说,这个值是估值,并不一定准确 |
filtered | 按条件筛选的行的百分比 |
Extra | 附加信息 |
其中 select_type、type、key、rows、Extra 是重点关注项;
在 MySQL 数据库中,通过 profile,能够更清楚地了解 SQL 执行过程的资源使用情况,如何使用 profile 分析慢查询,大致步骤是:确定这个 MySQL 版本是否支持 profile;确定 profile 是否关闭;开启 profile;执行 SQL(查看执行完 SQL 的 query id;通过 query id 查看 SQL 的每个状态及耗时时间)
具体操作如下:
相关命令:
select @@have_profiling; select @@profiling; set profiling=1;
相关命令:
select * from t1 where b=1000; show profiles; show profile for query 1;
如果需要使用,先开启 trace,设置格式为 JSON,再执行需要分析的 SQL,最后查看 trace 分析结果(在 information_schema.OPTIMIZER_TRACE 中)
开启该功能,会对 MySQL 性能有所影响,因此只建议分析问题时临时开启;
该语句使用的是 b 字段的索引 idx_b。实际表 t1 中,a、b 两个字段都有索引,为什么条件中有这两个索引字段却偏偏选了 b 字段的索引呢?这时就可以使用 trace 进行分析
1 手动开启trace
set session optimizer_trace="enabled=on",end_markers_in_json=on;
2 执行sql查询
select * from t1 where a >900 and b > 910 order by a;
执行结果如下:
------+------+------+---------------------+---------------------+ | id | a | b | create_time | update_time | +------+------+------+---------------------+---------------------+ | 911 | 911 | 911 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 912 | 912 | 912 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 913 | 913 | 913 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 914 | 914 | 914 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 915 | 915 | 915 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 916 | 916 | 916 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 917 | 917 | 917 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 918 | 918 | 918 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 919 | 919 | 919 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 920 | 920 | 920 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 921 | 921 | 921 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 922 | 922 | 922 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 923 | 923 | 923 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 924 | 924 | 924 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 925 | 925 | 925 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 926 | 926 | 926 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 927 | 927 | 927 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 928 | 928 | 928 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 929 | 929 | 929 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 930 | 930 | 930 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 931 | 931 | 931 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 932 | 932 | 932 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 933 | 933 | 933 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 934 | 934 | 934 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 935 | 935 | 935 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 936 | 936 | 936 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 937 | 937 | 937 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 938 | 938 | 938 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 939 | 939 | 939 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 940 | 940 | 940 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 941 | 941 | 941 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 942 | 942 | 942 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 943 | 943 | 943 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 944 | 944 | 944 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 945 | 945 | 945 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 946 | 946 | 946 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 947 | 947 | 947 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 948 | 948 | 948 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 949 | 949 | 949 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 950 | 950 | 950 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 951 | 951 | 951 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 952 | 952 | 952 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 953 | 953 | 953 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 954 | 954 | 954 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 955 | 955 | 955 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 956 | 956 | 956 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 957 | 957 | 957 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 958 | 958 | 958 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 959 | 959 | 959 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 960 | 960 | 960 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 961 | 961 | 961 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 962 | 962 | 962 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 963 | 963 | 963 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 964 | 964 | 964 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 965 | 965 | 965 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 966 | 966 | 966 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 967 | 967 | 967 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 968 | 968 | 968 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 969 | 969 | 969 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 970 | 970 | 970 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 971 | 971 | 971 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 972 | 972 | 972 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 973 | 973 | 973 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 974 | 974 | 974 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 975 | 975 | 975 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 976 | 976 | 976 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 977 | 977 | 977 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 978 | 978 | 978 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 979 | 979 | 979 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 980 | 980 | 980 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 981 | 981 | 981 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 982 | 982 | 982 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 983 | 983 | 983 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 984 | 984 | 984 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 985 | 985 | 985 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 986 | 986 | 986 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 987 | 987 | 987 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 988 | 988 | 988 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 989 | 989 | 989 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 990 | 990 | 990 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 991 | 991 | 991 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 992 | 992 | 992 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 993 | 993 | 993 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 994 | 994 | 994 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 995 | 995 | 995 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 996 | 996 | 996 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 997 | 997 | 997 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 998 | 998 | 998 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 999 | 999 | 999 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | | 1000 | 1000 | 1000 | 2023-06-26 02:16:08 | 2023-06-26 02:16:08 | +------+------+------+---------------------+---------------------+
3 查看 trace 分析结果
SELECT * FROM information_schema.OPTIMIZER_TRACE\G
查询结果如下图所示:
*************************** 1. row *************************** QUERY: select * from t1 where a >900 and b > 910 order by a TRACE: { "steps": [ { "join_preparation": { "select#": 1, "steps": [ { "expanded_query": "/* select#1 */ select `t1`.`id` AS `id`,`t1`.`a` AS `a`,`t1`.`b` AS `b`,`t1`.`create_time` AS `create_time`,`t1`.`update_time` AS `update_time` from `t1` where ((`t1`.`a` > 900) and (`t1`.`b` > 910)) order by `t1`.`a`" } ] /* steps */ } /* join_preparation */ }, { "join_optimization": { "select#": 1, "steps": [ { "condition_processing": { "condition": "WHERE", "original_condition": "((`t1`.`a` > 900) and (`t1`.`b` > 910))", "steps": [ { "transformation": "equality_propagation", "resulting_condition": "((`t1`.`a` > 900) and (`t1`.`b` > 910))" }, { "transformation": "constant_propagation", "resulting_condition": "((`t1`.`a` > 900) and (`t1`.`b` > 910))" }, { "transformation": "trivial_condition_removal", "resulting_condition": "((`t1`.`a` > 900) and (`t1`.`b` > 910))" } ] /* steps */ } /* condition_processing */ }, { "substitute_generated_columns": { } /* substitute_generated_columns */ }, { "table_dependencies": [ { "table": "`t1`", "row_may_be_null": false, "map_bit": 0, "depends_on_map_bits": [ ] /* depends_on_map_bits */ } ] /* table_dependencies */ }, { "ref_optimizer_key_uses": [ ] /* ref_optimizer_key_uses */ }, { "rows_estimation": [ { "table": "`t1`", "range_analysis": { "table_scan": { "rows": 1000, "cost": 103.35 } /* table_scan */, "potential_range_indexes": [ { "index": "PRIMARY", "usable": false, "cause": "not_applicable" }, { "index": "idx_a", "usable": true, "key_parts": [ "a", "id" ] /* key_parts */ }, { "index": "idx_b", "usable": true, "key_parts": [ "b", "id" ] /* key_parts */ } ] /* potential_range_indexes */, "setup_range_conditions": [ ] /* setup_range_conditions */, "group_index_range": { "chosen": false, "cause": "not_group_by_or_distinct" } /* group_index_range */, "skip_scan_range": { "potential_skip_scan_indexes": [ { "index": "idx_a", "usable": false, "cause": "query_references_nonkey_column" }, { "index": "idx_b", "usable": false, "cause": "query_references_nonkey_column" } ] /* potential_skip_scan_indexes */ } /* skip_scan_range */, "analyzing_range_alternatives": { "range_scan_alternatives": [ { "index": "idx_a", "ranges": [ "900 < a" ] /* ranges */, "index_dives_for_eq_ranges": true, "rowid_ordered": false, "using_mrr": false, "index_only": false, "in_memory": 1, "rows": 100, "cost": 35.26, "chosen": true }, { "index": "idx_b", "ranges": [ "910 < b" ] /* ranges */, "index_dives_for_eq_ranges": true, "rowid_ordered": false, "using_mrr": false, "index_only": false, "in_memory": 1, "rows": 90, "cost": 31.76, "chosen": true } ] /* 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": "idx_b", "rows": 90, "ranges": [ "910 < b" ] /* ranges */ } /* range_access_plan */, "rows_for_plan": 90, "cost_for_plan": 31.76, "chosen": true } /* chosen_range_access_summary */ } /* range_analysis */ } ] /* rows_estimation */ }, { "considered_execution_plans": [ { "plan_prefix": [ ] /* plan_prefix */, "table": "`t1`", "best_access_path": { "considered_access_paths": [ { "rows_to_scan": 90, "access_type": "range", "range_details": { "used_index": "idx_b" } /* range_details */, "resulting_rows": 90, "cost": 40.76, "chosen": true, "use_tmp_table": true } ] /* considered_access_paths */ } /* best_access_path */, "condition_filtering_pct": 100, "rows_for_plan": 90, "cost_for_plan": 40.76, "sort_cost": 90, "new_cost_for_plan": 130.76, "chosen": true } ] /* considered_execution_plans */ }, { "attaching_conditions_to_tables": { "original_condition": "((`t1`.`a` > 900) and (`t1`.`b` > 910))", "attached_conditions_computation": [ ] /* attached_conditions_computation */, "attached_conditions_summary": [ { "table": "`t1`", "attached": "((`t1`.`a` > 900) and (`t1`.`b` > 910))" } ] /* attached_conditions_summary */ } /* attaching_conditions_to_tables */ }, { "optimizing_distinct_group_by_order_by": { "simplifying_order_by": { "original_clause": "`t1`.`a`", "items": [ { "item": "`t1`.`a`" } ] /* items */, "resulting_clause_is_simple": true, "resulting_clause": "`t1`.`a`" } /* simplifying_order_by */ } /* optimizing_distinct_group_by_order_by */ }, { "reconsidering_access_paths_for_index_ordering": { "clause": "ORDER BY", "steps": [ ] /* steps */, "index_order_summary": { "table": "`t1`", "index_provides_order": false, "order_direction": "undefined", "index": "idx_b", "plan_changed": false } /* index_order_summary */ } /* reconsidering_access_paths_for_index_ordering */ }, { "finalizing_table_conditions": [ { "table": "`t1`", "original_table_condition": "((`t1`.`a` > 900) and (`t1`.`b` > 910))", "final_table_condition ": "((`t1`.`a` > 900) and (`t1`.`b` > 910))" } ] /* finalizing_table_conditions */ }, { "refine_plan": [ { "table": "`t1`", "pushed_index_condition": "(`t1`.`b` > 910)", "table_condition_attached": "(`t1`.`a` > 900)" } ] /* refine_plan */ }, { "considering_tmp_tables": [ { "adding_sort_to_table": "t1" } /* filesort */ ] /* considering_tmp_tables */ } ] /* steps */ } /* join_optimization */ }, { "join_execution": { "select#": 1, "steps": [ { "sorting_table": "t1", "filesort_information": [ { "direction": "asc", "expression": "`t1`.`a`" } ] /* filesort_information */, "filesort_priority_queue_optimization": { "usable": false, "cause": "not applicable (no LIMIT)" } /* filesort_priority_queue_optimization */, "filesort_execution": [ ] /* filesort_execution */, "filesort_summary": { "memory_available": 262144, "key_size": 9, "row_size": 32, "max_rows_per_buffer": 90, "num_rows_estimate": 90, "num_rows_found": 90, "num_initial_chunks_spilled_to_disk": 0, "peak_memory_used": 33792, "sort_algorithm": "std::sort", "unpacked_addon_fields": "skip_heuristic", "sort_mode": "" } /* filesort_summary */ } ] /* steps */ } /* join_execution */ } ] /* steps */ } MISSING_BYTES_BEYOND_MAX_MEM_SIZE: 0 INSUFFICIENT_PRIVILEGES: 0
4 关闭trace功能
set session optimizer_trace="enabled=off";