重庆思庄Oracle、Redhat认证学习论坛

标题: MySQL中使用PROFILING来查看SQL执行流程 [打印本页]

作者: jiawang 时间: 2024-7-31 14:10
标题: MySQL中使用PROFILING来查看SQL执行流程
本帖最后由 jiawang 于 2024-7-31 14:12 编辑

在MySQL中，PROFILING功能提供了一种方式来分析sql语句执行时间，包括查询执行的各个阶段，如发送、解析、优化、执行等。
使用PROFILING来查看SQL执行流程。以下是如何开启和使用PROFILING的步骤

1、开启Profiling

1.1、本次测试的环境
mysql> show variables like 'profiling';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| profiling    | OFF |
+---------------+-------+
1 row in set (0.01 sec)

mysql> SET profiling =1;
Query OK, 0 rows affected, 1 warning (0.00 sec)

mysql>  show variables like 'profiling';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| profiling    | ON |
+---------------+-------+
1 row in set (0.00 sec)

执行要分析的SQL查询。

mysql> show tables
-> ;
+----------------+
| Tables_in_test |
+----------------+
| my_table    |
| tmp          |
| tmp_table    |
+----------------+
3 rows in set (0.00 sec)

mysql> select * from my_table;
+----+-------+-----+
| id | name  | age |
+----+-------+-----+
|  1 | Tom |  25 |
|  2 | Tom |  25 |
|  3 | Jerry |  30 |
|  4 | Alice |  28 |
+----+-------+-----+
4 rows in set (0.00 sec)

执行查询后，你可以通过以下命令查看所有查询的Profile
mysql>  show profiles;
+----------+------------+---------------------------------+
| Query_ID | Duration | Query                         |
+----------+------------+---------------------------------+
|       1 | 0.00116575 | show variables like 'profiling' |
|       2 | 0.00084675 | show tables                   |
|       3 | 0.00038900 | select * from my_table       |
+----------+------------+---------------------------------+
3 rows in set, 1 warning (0.00 sec)
这将列出所有已执行的查询及其查询编号（Query_ID）。
mysql>

选择你想要查看详细Profile的查询编号，然后使用以下命令：
mysql> select * from tmp_table;
Empty set (0.00 sec)

mysql>  show profiles;
+----------+------------+---------------------------------+
| Query_ID | Duration | Query                         |
+----------+------------+---------------------------------+
|       1 | 0.00116575 | show variables like 'profiling' |
|       2 | 0.00084675 | show tables                   |
|       3 | 0.00038900 | select * from my_table       |
|       4 | 0.00034225 | select * from tmp_table       |
+----------+------------+---------------------------------+
4 rows in set, 1 warning (0.00 sec)

mysql> show profile for query 4;
+--------------------------------+----------+
| Status                      | Duration |
+--------------------------------+----------+
| starting                      | 0.000074 |
| Executing hook on transaction  | 0.000004 |
| starting                      | 0.000007 |
| checking permissions          | 0.000005 |
| Opening tables                | 0.000029 |
| init                         | 0.000005 |
| System lock                   | 0.000007 |
| optimizing                   | 0.000003 |
| statistics                   | 0.000012 |
| preparing                   | 0.000014 |
| executing                   | 0.000061 |
| end                         | 0.000005 |
| query end                   | 0.000002 |
| waiting for handler commit    | 0.000007 |
| closing tables                | 0.000008 |
| freeing items                | 0.000014 |
| cleaning up                   | 0.000087 |
+--------------------------------+----------+
17 rows in set, 1 warning (0.00 sec)

或者，你可以查看该查询的特定方面，如CPU_TIME、CONTEXT_SWITCHES等：
mysql> SHOW PROFILE CPU, BLOCK IO FOR QUERY 4;
+--------------------------------+----------+----------+------------+--------------+---------------+
| Status                      | Duration | CPU_user | CPU_system | Block_ops_in | Block_ops_out |
+--------------------------------+----------+----------+------------+--------------+---------------+
| starting                      | 0.000074 | 0.000073 | 0.000000 |          0 |          0 |
| Executing hook on transaction  | 0.000004 | 0.000003 | 0.000000 |          0 |          0 |
| starting                      | 0.000007 | 0.000007 | 0.000000 |          0 |          0 |
| checking permissions          | 0.000005 | 0.000005 | 0.000000 |          0 |          0 |
| Opening tables                | 0.000029 | 0.000029 | 0.000000 |          0 |          0 |
| init                         | 0.000005 | 0.000005 | 0.000000 |          0 |          0 |
| System lock                   | 0.000007 | 0.000006 | 0.000000 |          0 |          0 |
| optimizing                   | 0.000003 | 0.000003 | 0.000000 |          0 |          0 |
| statistics                   | 0.000012 | 0.000012 | 0.000000 |          0 |          0 |
| preparing                   | 0.000014 | 0.000014 | 0.000000 |          0 |          0 |
| executing                   | 0.000061 | 0.000062 | 0.000000 |          0 |          0 |
| end                         | 0.000005 | 0.000004 | 0.000000 |          0 |          0 |
| query end                   | 0.000002 | 0.000003 | 0.000000 |          0 |          0 |
| waiting for handler commit    | 0.000007 | 0.000007 | 0.000000 |          0 |          0 |
| closing tables                | 0.000008 | 0.000008 | 0.000000 |          0 |          0 |
| freeing items                | 0.000014 | 0.000014 | 0.000000 |          0 |          0 |
| cleaning up                   | 0.000087 | 0.000088 | 0.000000 |          0 |          0 |
+--------------------------------+----------+----------+------------+--------------+---------------+
17 rows in set, 1 warning (0.00 sec)

查看 profiling 系统变量

root@localhost [wjq]>show variables like '%profil%';
+------------------------+-------+
| Variable_name       | Value |
+------------------------+-------+
| have_profiling       | YES |
| profiling             | OFF |
| profiling_history_size | 15 |
+------------------------+-------+
3 rows in set (0.00 sec)

参数说明：

have_profiling:只读变量，用于控制是否有系统变量开启或关闭 profiling

profiling：开启或关系 SQ L语句剖析功能

profiling_history_size：设置保留 profiling 的数据，默认是 15，范围为 0~100，0 表示将禁用 profiling

获取 profiling 的帮助信息

root@localhost [wjq]>help profile
Name: 'SHOW PROFILE'
Description:
Syntax:
SHOW PROFILE [type [, type] ... ]
[FOR QUERY n]
[LIMIT row_count [OFFSET offset]]

type:
ALL                #显示所有的开销信息
  | BLOCK IO          #显示块IO的开销信息
  | CONTEXT SWITCHES #上下文切换开销信息
  | CPU                #显示CPU相关开销信息
  | IPC                #显示发送和接受相关开销信息
  | MEMORY             #显示内存相关开销信息
  | PAGE FAULTS       #显示页面错误相关开销信息
  | SOURCE             #显示和source_funcation、source_file、source_line相关的开销信息
  | SWAPS             #显示交换次数相关开销信息

The SHOW PROFILE and SHOW PROFILES statements display profiling
information that indicates resource usage for statements executed
during the course of the current session.

欢迎光临重庆思庄Oracle、Redhat认证学习论坛 (http://bbs.cqsztech.com/)