MySQL8.0如何分析TOP SQL
当要对MySQL进行优化时,找到TOP SQL语句通常是第一步。这里介绍的使用不需要另外安装工具的找出需要优化的SQL的方法。
● 从操作系统层监控到的最繁忙线程找出TOP SQL
● 慢查询日志
● 性能视图
● diagnostics()存储过程
● ps_trace_statement_digest()存储过程
● ps_trace_thread()存储过程
1.从操作系统层监控到的最繁忙线程找出TOP SQL
例如使用linux系统中的top加上-H参数可以按查看按繁忙程度排序的线程:
[root@node1 ~]# top -H
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
73631 mysql 20 0 4106520 570080 18932 D 7.3 3.5 0:16.01 connection
3717 root 0 -20 0 0 0 S 6.7 0.0 14:12.32 kworker/0:1H
73229 mysql 20 0 4106520 570080 18932 S 6.0 3.5 0:14.62 ib_log_flush
3755 root 0 -20 0 0 0 S 1.3 0.0 29:10.59 kworker/7:1H
73231 mysql 20 0 4106520 570080 18932 S 1.0 3.5 0:03.90 ib_log_writer
73230 mysql 20 0 4106520 570080 18932 S 0.7 3.5 0:02.95 ib_log_wr_notif
3716 root 0 -20 0 0 0 S 0.3 0.0 0:42.45 kworker/3:1H
3751 root 0 -20 0 0 0 S 0.3 0.0 0:26.52 kworker/5:1H
可以看到最繁忙的线程号是73631,根据线程号可以从performance_schema.threads视图中找到正在执行的SQL语句:
mysql> select * from performance_schema.threads where thread_os_id=73631 \G
root@db 15:38: [(none)]> select * from performance_schema.threads where thread_os_id=73631 \G
*************************** 1. row ***************************
THREAD_ID: 53
NAME: thread/sql/one_connection
TYPE: FOREGROUND
PROCESSLIST_ID: 13
PROCESSLIST_USER: root
PROCESSLIST_HOST: localhost
PROCESSLIST_DB: testdb
PROCESSLIST_COMMAND: Query
PROCESSLIST_TIME: 302
PROCESSLIST_STATE: waiting for handler commit
PROCESSLIST_INFO: insert into t1(a,b) values(i,i)
PARENT_THREAD_ID: NULL
ROLE: NULL
INSTRUMENTED: YES
HISTORY: YES
CONNECTION_TYPE: Socket
THREAD_OS_ID: 73631
RESOURCE_GROUP: USR_default
EXECUTION_ENGINE: PRIMARY
CONTROLLED_MEMORY: 26904
MAX_CONTROLLED_MEMORY: 638800
TOTAL_MEMORY: 750409
MAX_TOTAL_MEMORY: 821441
TELEMETRY_ACTIVE: NO
1 row in set (0.00 sec)
如果有必要,可以使用PROCESSLIST_ID字段指定的线程号杀死这个线程或正在执行的SQL,不能使用THREAD_ID字段值执行kill命令,不然可能会杀错了线程: mysql> kill query 13;
root@db 15:38: [(none)]> show processlist\G
*************************** 1. row ***************************
Id: 5
User: event_scheduler
Host: localhost
db: NULL
Command: Daemon
Time: 15876
State: Waiting on empty queue
Info: NULL
*************************** 2. row ***************************
Id: 13
User: root
Host: localhost
db: testdb
Command: Query
Time: 0
State: waiting for handler commit
Info: insert into t1(a,b) values(i,i)
*************************** 3. row ***************************
Id: 14
User: root
Host: localhost
db: NULL
Command: Query
Time: 0
State: init
Info: show processlist
3 rows in set, 1 warning (0.00 sec)
或者
mysql> kill 13;
2.慢查询日志
long_query_time:响应时间超过这个参数值的SQL语句被定义为慢SQL,默认10秒。 slow_query_log:是否激活慢查询日志,默认为off。
slow_query_log_file:慢速查询日志文件的路径和文件名,默认/var/lib/mysql/localhostslow.log。
log_slow_extra:从MySQL 8.0.14版本开始才有的,当它为true时,将记录与执行的SQL语句相关的额外信息
下面是设置long_query_time = 0时记录的一条SQL语句的默认内容如下:
# Time: 2024-02-20T10:02:07.313451Z
# User@Host: root[root] @ localhost [] Id: 9
# Query_time: 5178.318253 Lock_time: 0.000003 Rows_sent: 0 Rows_examined: 0
SET timestamp=1708423327;
call insert_t1();
当参数log_slow_extra 设置为on时,执行同样的SQL语句,记录的信息如下:
# Time: 2024-02-22T07:32:36.396051Z
# User@Host: root[root] @ localhost [] Id: 13
# Query_time: 100.000276 Lock_time: 0.000000 Rows_sent: 1 Rows_examined: 1 Thread_id: 13 Errno: 0 Killed: 0 Bytes_received: 34 Bytes_sent: 49 Read_first: 0 Read_last: 0 Read_key: 0 Read_next: 0 Read_prev: 0 Read_rnd: 0 Read_rnd_next: 0 Sort_merge_passes: 0 Sort_range_count: 0 Sort_rows: 0 Sort_scan_count: 0 Created_tmp_disk_tables: 0 Created_tmp_tables: 0 Start: 2024-02-22T07:30:56.395775Z End: 2024-02-22T07:32:36.396051Z
SET timestamp=1708587056;
select 1 where 0=sleep(100);
Slow_queries状态参数:在slow_query_log为on时,记录慢查询语句的个数。
vim /etc/my.cnf
.....
slow_query_log=ON
slow_query_log_file=/data/mysql/log/slow_mysql.log
long_query_time=1
#增加log_slow_extra
log_slow_extra=ON
.....
session:
root@db 15:29: [(none)]> select 1 where 0=sleep(100);
+---+
| 1 |
+---+
| 1 |
+---+
1 row in set (11.00 sec)
远程终端执行命令:
[root@node1 ~]# mysqladmin extended-status -uroot -pP@ssw0rd -S /data/mysql/tmp/mysql.sock |grep -i slow_q
mysqladmin: [Warning] Using a password on the command line interface can be insecure.
| Slow_queries | 3
3.性能视图
1).在视图sys.statement_analysis中找出总计执行时间最长的SQL语句:
select * from sys.statement_analysis limit 1\G
root@db 15:44: [(none)]> select * from sys.statement_analysis limit 1\G
*************************** 1. row ***************************
query: CALL `insert_t1` ( )
db: testdb
full_scan:
exec_count: 2
err_count: 2
warn_count: 0
total_latency: 5.67 h
max_latency: 2.86 h
avg_latency: 2.84 h
lock_latency: 13.00 us
cpu_latency: 0 ps
rows_sent: 0
rows_sent_avg: 0
rows_examined: 0
rows_examined_avg: 0
rows_affected: 0
rows_affected_avg: 0
tmp_tables: 0
tmp_disk_tables: 0
rows_sorted: 0
sort_merge_passes: 0
max_controlled_memory: 1.03 MiB
max_total_memory: 1.37 MiB
digest: 6a32a3e132e7b15efde27d53fad0a7bb999b96b9af7d54eaae3efacc399dbc48
first_seen: 2024-02-21 19:52:51.208172
last_seen: 2024-02-22 13:53:03.016830
1 row in set (0.00 sec)
视图sys.statement_analysis已经按照总延迟时间降序排序,因此第一条记录就是总计用时最长的SQL。还可以在视图sys.statements_with_runtimes_in_95th_percentile中可以查询到运行时间最长的5%的语句。
2).下面的SQL语句列出平均执行时间最长的语句,这类SQL语句通常优化的空间最大:
mysql> select * from performance_schema.events_statements_summary_by_digest order by avg_timer_wait desc limit 1\G
root@db 15:44: [(none)]> select * from performance_schema.events_statements_summary_by_digest order by avg_timer_wait desc limit 1\G
*************************** 1. row ***************************
SCHEMA_NAME: testdb
DIGEST: 6a32a3e132e7b15efde27d53fad0a7bb999b96b9af7d54eaae3efacc399dbc48
DIGEST_TEXT: CALL `insert_t1` ( )
COUNT_STAR: 2
SUM_TIMER_WAIT: 20414619269075000
MIN_TIMER_WAIT: 10119106493937000
AVG_TIMER_WAIT: 10207309634537000
MAX_TIMER_WAIT: 10295512775138000
SUM_LOCK_TIME: 13000000
SUM_ERRORS: 2
SUM_WARNINGS: 0
SUM_ROWS_AFFECTED: 0
SUM_ROWS_SENT: 0
SUM_ROWS_EXAMINED: 0
SUM_CREATED_TMP_DISK_TABLES: 0
SUM_CREATED_TMP_TABLES: 0
SUM_SELECT_FULL_JOIN: 0
SUM_SELECT_FULL_RANGE_JOIN: 0
SUM_SELECT_RANGE: 0
SUM_SELECT_RANGE_CHECK: 0
SUM_SELECT_SCAN: 0
SUM_SORT_MERGE_PASSES: 0
SUM_SORT_RANGE: 0
SUM_SORT_ROWS: 0
SUM_SORT_SCAN: 0
SUM_NO_INDEX_USED: 0
SUM_NO_GOOD_INDEX_USED: 0
SUM_CPU_TIME: 0
MAX_CONTROLLED_MEMORY: 1077608
MAX_TOTAL_MEMORY: 1435118
COUNT_SECONDARY: 0
FIRST_SEEN: 2024-02-21 19:52:51.208172
LAST_SEEN: 2024-02-22 13:53:03.016830
QUANTILE_95: 18446744073709551615
QUANTILE_99: 18446744073709551615
QUANTILE_999: 18446744073709551615
QUERY_SAMPLE_TEXT: call insert_t1()
QUERY_SAMPLE_SEEN: 2024-02-22 13:53:03.016830
QUERY_SAMPLE_TIMER_WAIT: 10295512775138000
1 row in set (0.00 sec)
3).下面的SQL语句列出执行次数最多的SQL语句,这类SQL语句通常对整体系统性能影响最大:
mysql> select * from performance_schema.events_statements_summary_by_digest order by count_star desc limit 1\G
root@db 15:46: [(none)]> select * from performance_schema.events_statements_summary_by_digest order by count_star desc limit 1\G
*************************** 1. row ***************************
SCHEMA_NAME: NULL
DIGEST: 070e38632eb4444e50cdcbf0b17474ba801e203add89783a24584951442a2317
DIGEST_TEXT: SHOW GLOBAL STATUS
COUNT_STAR: 8
SUM_TIMER_WAIT: 12423476000
MIN_TIMER_WAIT: 1154599000
AVG_TIMER_WAIT: 1552934000
MAX_TIMER_WAIT: 4260388000
SUM_LOCK_TIME: 16000000
SUM_ERRORS: 0
SUM_WARNINGS: 0
SUM_ROWS_AFFECTED: 0
SUM_ROWS_SENT: 3952
SUM_ROWS_EXAMINED: 3952
SUM_CREATED_TMP_DISK_TABLES: 0
SUM_CREATED_TMP_TABLES: 8
SUM_SELECT_FULL_JOIN: 0
SUM_SELECT_FULL_RANGE_JOIN: 0
SUM_SELECT_RANGE: 0
SUM_SELECT_RANGE_CHECK: 0
SUM_SELECT_SCAN: 16
SUM_SORT_MERGE_PASSES: 0
SUM_SORT_RANGE: 0
SUM_SORT_ROWS: 0
SUM_SORT_SCAN: 0
SUM_NO_INDEX_USED: 8
SUM_NO_GOOD_INDEX_USED: 0
SUM_CPU_TIME: 0
MAX_CONTROLLED_MEMORY: 1123600
MAX_TOTAL_MEMORY: 1290995
COUNT_SECONDARY: 0
FIRST_SEEN: 2024-02-22 15:30:32.758177
LAST_SEEN: 2024-02-22 15:31:13.728917
QUANTILE_95: 4365158322
QUANTILE_99: 4365158322
QUANTILE_999: 4365158322
QUERY_SAMPLE_TEXT: show /*!50002 GLOBAL */ status
QUERY_SAMPLE_SEEN: 2024-02-22 15:30:32.758177
QUERY_SAMPLE_TIMER_WAIT: 4260388000
1 row in set (0.00 sec)
4).下面的SQL语句列出检查行数最多的SQL语句,这类SQL语句通常消耗最多硬盘的读写:
mysql> select * from performance_schema.events_statements_summary_by_digest order by sum_rows_examined desc limit 1\G
root@db 15:47: [(none)]> select * from performance_schema.events_statements_summary_by_digest order by sum_rows_examined desc limit 1\G
*************************** 1. row ***************************
SCHEMA_NAME: NULL
DIGEST: 070e38632eb4444e50cdcbf0b17474ba801e203add89783a24584951442a2317
DIGEST_TEXT: SHOW GLOBAL STATUS
COUNT_STAR: 8
SUM_TIMER_WAIT: 12423476000
MIN_TIMER_WAIT: 1154599000
AVG_TIMER_WAIT: 1552934000
MAX_TIMER_WAIT: 4260388000
SUM_LOCK_TIME: 16000000
SUM_ERRORS: 0
SUM_WARNINGS: 0
SUM_ROWS_AFFECTED: 0
SUM_ROWS_SENT: 3952
SUM_ROWS_EXAMINED: 3952
SUM_CREATED_TMP_DISK_TABLES: 0
SUM_CREATED_TMP_TABLES: 8
SUM_SELECT_FULL_JOIN: 0
SUM_SELECT_FULL_RANGE_JOIN: 0
SUM_SELECT_RANGE: 0
SUM_SELECT_RANGE_CHECK: 0
SUM_SELECT_SCAN: 16
SUM_SORT_MERGE_PASSES: 0
SUM_SORT_RANGE: 0
SUM_SORT_ROWS: 0
SUM_SORT_SCAN: 0
SUM_NO_INDEX_USED: 8
SUM_NO_GOOD_INDEX_USED: 0
SUM_CPU_TIME: 0
MAX_CONTROLLED_MEMORY: 1123600
MAX_TOTAL_MEMORY: 1290995
COUNT_SECONDARY: 0
FIRST_SEEN: 2024-02-22 15:30:32.758177
LAST_SEEN: 2024-02-22 15:31:13.728917
QUANTILE_95: 4365158322
QUANTILE_99: 4365158322
QUANTILE_999: 4365158322
QUERY_SAMPLE_TEXT: show /*!50002 GLOBAL */ status
QUERY_SAMPLE_SEEN: 2024-02-22 15:30:32.758177
QUERY_SAMPLE_TIMER_WAIT: 4260388000
1 row in set (0.00 sec)
5).下面的SQL语句列出返回行数最多的SQL语句,这类SQL语句通常占用最多网络带宽:
mysql> select * from performance_schema.events_statements_summary_by_digest order by sum_rows_sent desc limit 1\G
root@db 15:47: [(none)]> select * from performance_schema.events_statements_summary_by_digest order by sum_rows_sent desc limit 1\G
*************************** 1. row ***************************
SCHEMA_NAME: NULL
DIGEST: 070e38632eb4444e50cdcbf0b17474ba801e203add89783a24584951442a2317
DIGEST_TEXT: SHOW GLOBAL STATUS
COUNT_STAR: 8
SUM_TIMER_WAIT: 12423476000
MIN_TIMER_WAIT: 1154599000
AVG_TIMER_WAIT: 1552934000
MAX_TIMER_WAIT: 4260388000
SUM_LOCK_TIME: 16000000
SUM_ERRORS: 0
SUM_WARNINGS: 0
SUM_ROWS_AFFECTED: 0
SUM_ROWS_SENT: 3952
SUM_ROWS_EXAMINED: 3952
SUM_CREATED_TMP_DISK_TABLES: 0
SUM_CREATED_TMP_TABLES: 8
SUM_SELECT_FULL_JOIN: 0
SUM_SELECT_FULL_RANGE_JOIN: 0
SUM_SELECT_RANGE: 0
SUM_SELECT_RANGE_CHECK: 0
SUM_SELECT_SCAN: 16
SUM_SORT_MERGE_PASSES: 0
SUM_SORT_RANGE: 0
SUM_SORT_ROWS: 0
SUM_SORT_SCAN: 0
SUM_NO_INDEX_USED: 8
SUM_NO_GOOD_INDEX_USED: 0
SUM_CPU_TIME: 0
MAX_CONTROLLED_MEMORY: 1123600
MAX_TOTAL_MEMORY: 1290995
COUNT_SECONDARY: 0
FIRST_SEEN: 2024-02-22 15:30:32.758177
LAST_SEEN: 2024-02-22 15:31:13.728917
QUANTILE_95: 4365158322
QUANTILE_99: 4365158322
QUANTILE_999: 4365158322
QUERY_SAMPLE_TEXT: show /*!50002 GLOBAL */ status
QUERY_SAMPLE_SEEN: 2024-02-22 15:30:32.758177
QUERY_SAMPLE_TIMER_WAIT: 4260388000
1 row in set (0.00 sec)
6).sys.statements_with_runtimes_in_95th_percentile视图中包括了最慢的5%的SQL语句:
mysql> select * from sys.statements_with_runtimes_in_95th_percentile\G
root@db 15:48: [(none)]> select * from sys.statements_with_runtimes_in_95th_percentile\G
*************************** 1. row ***************************
query: CALL `insert_t1` ( )
db: testdb
full_scan:
exec_count: 2
err_count: 2
warn_count: 0
total_latency: 5.67 h
max_latency: 2.86 h
avg_latency: 2.84 h
rows_sent: 0
rows_sent_avg: 0
rows_examined: 0
rows_examined_avg: 0
first_seen: 2024-02-21 19:52:51.208172
last_seen: 2024-02-22 13:53:03.016830
digest: 6a32a3e132e7b15efde27d53fad0a7bb999b96b9af7d54eaae3efacc399dbc48
1 row in set (0.01 sec)
4.diagnostics()存储过程
diagnostics()存储过程会生成一个关于当前MySQL实例整体性能的诊断报告,例如:
mysql> tee diagnostics.log
mysql> call sys.diagnostics(null,null,'current');
mysql> notee;
执行完成后会生成分析日志报告:diagnostics.log
[root@node1 ~]# ll diagnostics.log
-rw-r--r-- 1 root root 903444 Feb 22 15:53 diagnostics.log
5.ps_trace_statement_digest()存储过程
可以根据提供的SQL语句摘要哈希值跟踪收集这些SQL语句的执行过程中的性能诊断信息。
下面的例子是在60秒内跟踪指定的SQL语句,每0.1秒收集一次性能诊断信息:
mysql> call sys.ps_trace_statement_digest(@digest, 60, 0.1, true, true);
root@db 16:02: [(none)]> call sys.ps_trace_statement_digest(@digest, 60, 0.1, true, true);
+-------------------+
| summary |
+-------------------+
| Disabled 1 thread |
+-------------------+
1 row in set (0.00 sec)
+--------------------+
| SUMMARY STATISTICS |
+--------------------+
| SUMMARY STATISTICS |
+--------------------+
1 row in set (59.40 sec)
+------------+-----------+-----------+-----------+---------------+---------------+------------+------------+
| executions | exec_time | lock_time | rows_sent | rows_affected | rows_examined | tmp_tables | full_scans |
+------------+-----------+-----------+-----------+---------------+---------------+------------+------------+
| 0 | NULL | NULL | NULL | NULL | NULL | NULL | NULL |
+------------+-----------+-----------+-----------+---------------+---------------+------------+------------+
1 row in set (59.40 sec)
Empty set (59.40 sec)
+---------------------------+
| LONGEST RUNNING STATEMENT |
+---------------------------+
| LONGEST RUNNING STATEMENT |
+---------------------------+
1 row in set (59.40 sec)
Empty set (59.40 sec)
Empty set (59.40 sec)
+------------------+
| summary |
+------------------+
| Enabled 1 thread |
+------------------+
1 row in set (59.41 sec)
Query OK, 0 rows affected (59.41 sec)
6.ps_trace_thread()存储过程
可以跟踪某个线程的执行过程,把这个线程执行的所有SQL语句的性能信息都记录下来,并输出报告。这个存储过程适合用于执行存储过程或多个SQL语句的线程。
例如:采用当前的配置启动对51号线程的跟踪,跟踪60秒,每1秒收集一次性能信息,生成性能报告文件:
#使用mysql用户能读写的路径,不然就会提示报错:
ERROR 1 (HY000): Can't create/write to file '/tmp/td_23.dot' (OS errno 13 - Permission denied)
mysql> call sys.ps_trace_thread(23,'/data/mysql/data/td_23.dot',null, null, true,false, false);
root@db 16:19: [(none)]> call sys.ps_trace_thread(23,'/data/mysql/data/td_23.dot',null, null, true,false, false);
+--------------------+
| summary |
+--------------------+
| Disabled 0 threads |
+--------------------+
1 row in set (0.01 sec)
+---------------------------------------------+
| Info |
+---------------------------------------------+
| Data collection starting for THREAD_ID = 23 |
+---------------------------------------------+
1 row in set (0.01 sec)
+---------------------------------------------------+
| Info |
+---------------------------------------------------+
| Stack trace written to /data/mysql/data/td_23.dot |
+---------------------------------------------------+
1 row in set (0.01 sec)
+-----------------------------------------------------------+
| Convert to PDF |
+-----------------------------------------------------------+
| dot -Tpdf -o /tmp/stack_23.pdf /data/mysql/data/td_23.dot |
+-----------------------------------------------------------+
1 row in set (0.01 sec)
+-----------------------------------------------------------+
| Convert to PNG |
+-----------------------------------------------------------+
| dot -Tpng -o /tmp/stack_23.png /data/mysql/data/td_23.dot |
+-----------------------------------------------------------+
1 row in set (0.01 sec)
Query OK, 0 rows affected (0.01 sec)