MySQL调优性能监控之show profile

用show profile查询工具指定具体的type

show profile在mysql5.7之后过时

show profile命令用于跟踪执行过的sql语句的资源消耗信息，可以帮助查看sql语句的执行情况，可以在做性能分析或者问题诊断的时候作为参考。在MySQL5.7中， show profile命令已经开始不推荐使用，MySQL使用performance_schema 中系统表的信息来替代show profile命令,这儿主要是研究资源性能监控的思路。

SHOW PROFILE [type [, type] ... ]
    [FOR QUERY n]
    [LIMIT row_count [OFFSET offset]]

type:
    ALL
  | BLOCK IO
  | CONTEXT SWITCHES
  | CPU
  | IPC
  | MEMORY
  | PAGE FAULTS
  | SOURCE
  | SWAPS

此工具默认是禁用的，首先打开show profile跟踪记录SQL执行情况的配置,可以通过服务器变量在会话级别动态的修改:

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

当设置完成之后，在服务器上执行的所有语句，都会测量其耗费的时间和其他一些查询执行状态变更相关的数据。

以下面查询语句举例:

mysql> select * from emp;
+-------+--------+-----------+------+------------+---------+---------+--------+
| empno | ename  | job       | mgr  | hiredate   | sal     | comm    | deptno |
+-------+--------+-----------+------+------------+---------+---------+--------+
|  7369 | SMITH  | CLERK     | 7902 | 1980-12-17 |  800.00 |    NULL |     20 |
|  7499 | ALLEN  | SALESMAN  | 7698 | 1981-02-20 | 1600.00 |  300.00 |     30 |
|  7521 | WARD   | SALESMAN  | 7698 | 1981-02-22 | 1250.00 |  500.00 |     30 |
|  7566 | JONES  | MANAGER   | 7839 | 1981-04-02 | 2975.00 |    NULL |     20 |
|  7654 | MARTIN | SALESMAN  | 7698 | 1981-09-28 | 1250.00 | 1400.00 |     30 |
|  7698 | BLAKE  | MANAGER   | 7839 | 1981-05-01 | 2850.00 |    NULL |     30 |
|  7782 | CLARK  | MANAGER   | 7839 | 1981-06-09 | 2450.00 |    NULL |     10 |
|  7788 | SCOTT  | ANALYST   | 7566 | 1987-07-13 | 3000.00 |    NULL |     20 |
|  7839 | KING   | PRESIDENT | NULL | 1981-11-17 | 5000.00 |    NULL |     10 |
|  7844 | TURNER | SALESMAN  | 7698 | 1981-09-08 | 1500.00 |    0.00 |     30 |
|  7876 | ADAMS  | CLERK     | 7788 | 1987-07-13 | 1100.00 |    NULL |     20 |
|  7900 | JAMES  | CLERK     | 7698 | 1981-12-03 |  950.00 |    NULL |     30 |
|  7902 | FORD   | ANALYST   | 7566 | 1981-12-03 | 3000.00 |    NULL |     20 |
|  7934 | MILLER | CLERK     | 7782 | 1982-01-23 | 1300.00 |    NULL |     10 |
+-------+--------+-----------+------+------------+---------+---------+--------+
14 rows in set (0.01 sec)

在mysql的命令行模式下只能显示两位小数的时间，可以使用如下命令查看具体的执行时间

mysql> show profiles;
+----------+------------+-------------------+
| Query_ID | Duration   | Query             |
+----------+------------+-------------------+
|        1 | 0.00130500 | show databases    |
|        2 | 0.00010250 | SELECT DATABASE() |
|        3 | 0.00027500 | show databases    |
|        4 | 0.00023075 | show tables       |
|        5 | 0.00041800 | show databases    |
|        6 | 0.00018925 | show tables       |
|        7 | 0.00376825 | select * from emp |
+----------+------------+-------------------+
7 rows in set, 1 warning (0.00 sec)

上面一共有7条sql语句操作,执行如下命令可以查看详细的每个步骤的时间,这儿以Query_ID = 1的语句举例子：

mysql> show profile for query 1 ;
+----------------------+----------+
| Status               | Duration |
+----------------------+----------+
| starting             | 0.000089 |
| checking permissions | 0.000025 |
| Opening tables       | 0.000062 |
| init                 | 0.000036 |
| System lock          | 0.000007 |
| optimizing           | 0.000004 |
| statistics           | 0.000023 |
| preparing            | 0.000039 |
| executing            | 0.000910 |
| Sending data         | 0.000019 |
| end                  | 0.000016 |
| query end            | 0.000006 |
| closing tables       | 0.000002 |
| removing tmp table   | 0.000004 |
| closing tables       | 0.000016 |
| freeing items        | 0.000013 |
| cleaning up          | 0.000036 |
+----------------------+----------+
17 rows in set, 1 warning (0.00 sec)

除了query n指定Query_ID外,还可以设置Type查看MYSQL语句执行的其他信息,type主要参数如下:

all：显示所有性能信息

block io：显示块io操作的次数

context switches：显示上下文切换次数，被动和主动

cpu：显示用户cpu时间、系统cpu时间

IPC：显示发送和接受的消息数量

Memory：暂未实现

page faults：显示页错误数量

source：显示源码中的函数名称与位置

swaps：显示swap的次数

##all显示内容太宽,这儿暂不显示
mysql> show profile all for query 7;

block io

# block io
mysql> mysql> show  profile block io fo 7;
+----------------------+----------+--------------+---------------+
| Status               | Duration | Block_ops_in | Block_ops_out |
+----------------------+----------+--------------+---------------+
| starting             | 0.000053 |            0 |             0 |
| checking permissions | 0.000006 |            0 |             0 |
| Opening tables       | 0.000014 |            0 |             0 |
| init                 | 0.000056 |            0 |             0 |
| System lock          | 0.000055 |            0 |             0 |
| optimizing           | 0.000006 |            0 |             0 |
| statistics           | 0.000008 |            0 |             0 |
| preparing            | 0.000007 |            0 |             0 |
| executing            | 0.000002 |            0 |             0 |
| Sending data         | 0.003099 |            0 |             0 |
| end                  | 0.000006 |            0 |             0 |
| query end            | 0.000007 |            0 |             0 |
| closing tables       | 0.000006 |            0 |             0 |
| freeing items        | 0.000396 |            0 |             0 |
| cleaning up          | 0.000050 |            0 |             0 |
+----------------------+----------+--------------+---------------+
15 rows in set, 1 warning (0.00 sec)

context switches

#context switches
mysql> show profile context switches for query 1;
+----------------------+----------+-------------------+---------------------+
| Status               | Duration | Context_voluntary | Context_involuntary |
+----------------------+----------+-------------------+---------------------+
| starting             | 0.000089 |                 0 |                   0 |
| checking permissions | 0.000025 |                 0 |                   0 |
| Opening tables       | 0.000062 |                 0 |                   0 |
| init                 | 0.000036 |                 0 |                   0 |
| System lock          | 0.000007 |                 0 |                   0 |
| optimizing           | 0.000004 |                 0 |                   0 |
| statistics           | 0.000023 |                 0 |                   0 |
| preparing            | 0.000039 |                 0 |                   0 |
| executing            | 0.000910 |                 0 |                   0 |
| Sending data         | 0.000019 |                 0 |                   0 |
| end                  | 0.000016 |                 0 |                   0 |
| query end            | 0.000006 |                 0 |                   0 |
| closing tables       | 0.000002 |                 0 |                   0 |
| removing tmp table   | 0.000004 |                 0 |                   0 |
| closing tables       | 0.000016 |                 0 |                   0 |
| freeing items        | 0.000013 |                 0 |                   0 |
| cleaning up          | 0.000036 |                 0 |                   0 |
+----------------------+----------+-------------------+---------------------+
17 rows in set, 1 warning (0.00 sec)

cpu

#cpu
mysql> show profile cpu for query 7;
+----------------------+----------+----------+------------+
| Status               | Duration | CPU_user | CPU_system |
+----------------------+----------+----------+------------+
| starting             | 0.000053 | 0.000000 |   0.000000 |
| checking permissions | 0.000006 | 0.000000 |   0.000000 |
| Opening tables       | 0.000014 | 0.000000 |   0.000000 |
| init                 | 0.000056 | 0.000000 |   0.000000 |
| System lock          | 0.000055 | 0.000000 |   0.000000 |
| optimizing           | 0.000006 | 0.000000 |   0.000000 |
| statistics           | 0.000008 | 0.000000 |   0.000000 |
| preparing            | 0.000007 | 0.000000 |   0.000000 |
| executing            | 0.000002 | 0.000000 |   0.000000 |
| Sending data         | 0.003099 | 0.002000 |   0.000000 |
| end                  | 0.000006 | 0.000000 |   0.000000 |
| query end            | 0.000007 | 0.000000 |   0.000000 |
| closing tables       | 0.000006 | 0.000000 |   0.000000 |
| freeing items        | 0.000396 | 0.001000 |   0.000000 |
| cleaning up          | 0.000050 | 0.000000 |   0.000000 |
+----------------------+----------+----------+------------+
15 rows in set, 1 warning (0.00 sec)

ipc

#ipc
mysql> show profile ipc for query 1;
+----------------------+----------+---------------+-------------------+
| Status               | Duration | Messages_sent | Messages_received |
+----------------------+----------+---------------+-------------------+
| starting             | 0.000089 |             0 |                 0 |
| checking permissions | 0.000025 |             0 |                 0 |
| Opening tables       | 0.000062 |             0 |                 0 |
| init                 | 0.000036 |             0 |                 0 |
| System lock          | 0.000007 |             0 |                 0 |
| optimizing           | 0.000004 |             0 |                 0 |
| statistics           | 0.000023 |             0 |                 0 |
| preparing            | 0.000039 |             0 |                 0 |
| executing            | 0.000910 |             0 |                 0 |
| Sending data         | 0.000019 |             0 |                 0 |
| end                  | 0.000016 |             0 |                 0 |
| query end            | 0.000006 |             0 |                 0 |
| closing tables       | 0.000002 |             0 |                 0 |
| removing tmp table   | 0.000004 |             0 |                 0 |
| closing tables       | 0.000016 |             0 |                 0 |
| freeing items        | 0.000013 |             0 |                 0 |
| cleaning up          | 0.000036 |             0 |                 0 |
+----------------------+----------+---------------+-------------------+
17 rows in set, 1 warning (0.00 sec)

page faults

# page faults
mysql> show profile page faults for query 1;
+----------------------+----------+-------------------+-------------------+
| Status               | Duration | Page_faults_major | Page_faults_minor |
+----------------------+----------+-------------------+-------------------+
| starting             | 0.000089 |                 0 |                 0 |
| checking permissions | 0.000025 |                 0 |                 0 |
| Opening tables       | 0.000062 |                 0 |                 0 |
| init                 | 0.000036 |                 0 |                 0 |
| System lock          | 0.000007 |                 0 |                 0 |
| optimizing           | 0.000004 |                 0 |                 0 |
| statistics           | 0.000023 |                 0 |                 0 |
| preparing            | 0.000039 |                 0 |                 0 |
| executing            | 0.000910 |                 0 |                 1 |
| Sending data         | 0.000019 |                 0 |                 0 |
| end                  | 0.000016 |                 0 |                 0 |
| query end            | 0.000006 |                 0 |                 0 |
| closing tables       | 0.000002 |                 0 |                 0 |
| removing tmp table   | 0.000004 |                 0 |                 0 |
| closing tables       | 0.000016 |                 0 |                 0 |
| freeing items        | 0.000013 |                 0 |                 0 |
| cleaning up          | 0.000036 |                 0 |                 0 |
+----------------------+----------+-------------------+-------------------+
17 rows in set, 1 warning (0.00 sec)

source

swaps

# swaps
mysql> show profile swaps for query 7;
+----------------------+----------+-------+
| Status               | Duration | Swaps |
+----------------------+----------+-------+
| starting             | 0.000053 |     0 |
| checking permissions | 0.000006 |     0 |
| Opening tables       | 0.000014 |     0 |
| init                 | 0.000056 |     0 |
| System lock          | 0.000055 |     0 |
| optimizing           | 0.000006 |     0 |
| statistics           | 0.000008 |     0 |
| preparing            | 0.000007 |     0 |
| executing            | 0.000002 |     0 |
| Sending data         | 0.003099 |     0 |
| end                  | 0.000006 |     0 |
| query end            | 0.000007 |     0 |
| closing tables       | 0.000006 |     0 |
| freeing items        | 0.000396 |     0 |
| cleaning up          | 0.000050 |     0 |
+----------------------+----------+-------+
15 rows in set, 1 warning (0.00 sec)

__EOF__

本文作者：等不到的口琴
本文链接：https://www.cnblogs.com/Courage129/p/14187808.html
关于博主：评论和私信会在第一时间回复。或者直接私信我。
版权声明：本博客所有文章除特别声明外，均采用 BY-NC-SA 许可协议。转载请注明出处！
声援博主：如果您觉得文章对您有帮助，可以点击文章右下角【推荐】一下。您的鼓励是博主的最大动力！
posted @   等不到的口琴  阅读(507)  评论(0)  编辑  收藏  举报
编辑推荐：
· 基于Microsoft.Extensions.AI核心库实现RAG应用
· Linux系列：如何用heaptrack跟踪.NET程序的非托管内存泄露
· 开发者必知的日志记录最佳实践
· SQL Server 2025 AI相关能力初探
· Linux系列：如何用 C#调用 C方法造成内存泄露
阅读排行：
· 震惊！C++程序真的从main开始吗？99%的程序员都答错了
· 【硬核科普】Trae如何「偷看」你的代码？零基础破解AI编程运行原理
· 单元测试从入门到精通
· 上周热点回顾（3.3-3.9）
· Vue3状态管理终极指南：Pinia保姆级教程
点击右上角即可分享
微信分享提示
AI IDE Trae