INFORMATION_SCHEMA.PROFILING

INFORMATION_SCHEMA PROFILING Table

The PROFILING table provides statement analysis information. Its content corresponds to the information generated by the SHOW PROFILES and SHOW PROFILE statements.

##PAGE_FAULTS_MINOR Page_faults_minorNumber of page faultsSWAPSSwapsHow many swaps have occurredSOURCE_FUNCTIONSource_functionInformation on the location of source code execution analysis statusSOURCE_FILESource_fileInformation on the location of source code execution analysis statusSOURCE_LINESource_lineInformation on the location of source code execution analysis status

INFORMATION_SCHEMA Name	SHOW Name	Notes
QUERY_ID	Query_ID	ID
SEQ		Serial number of display order for rows with the same QUERY_ID value
STATE	Status	Analysis for which row measurements apply STATUS
DURATION	Duration	How long statement execution remains in a given state in seconds
CPU_USER	CPU_user	User CPU usage in seconds
CPU_SYSTEM	CPU_system	System CPU usage in seconds
CONTEXT_VOLUNTARY	Context_voluntary	Voluntary context switch occurs
CONTEXT_INVOLUNTARY	Context_involuntary	Involuntary context switch occurred
BLOCK_OPS_IN	Block_ops_in	Number of input block operations
BLOCK_OPS_OUT	Block_ops_out	Number of output block operations
MESSAGES_SENT	Messages_sent	The number of communication messages sent
MESSAGES_RECEIVED	Messages_received	The number of communication messages received
PAGE_FAULTS_MAJOR	Page_faults_major	Number of main page errors

13.7.5.31 SHOW PROFILES Syntax

SHOW PROFILES

The SHOW PROFILES statement, along with SHOW PROFILE, displays profiling information indicating the resource usage of statements executed during the current session .

13.7.5.30 SHOW PROFILE Syntax

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

Optional type values ​​can be specified to display specific other types of information (corresponding to fields in PROFILING):

type#note##ALLBLOCK IOCONTEXT SWITCHESCPUIPCMEMORYPAGE FAULTSSOURCE SWAPS

SHOW PROFILE和SHOW PROFILES语句显示分析信息，指示在当前会话过程中执行的语句的资源使用情况。

Profiling由Profiling会话变量控制，默认值为0（OFF）。 通过将Profiling设置为1或ON可启用分析：

mysql> SET profiling = 1;

SHOW PROFILES显示发送到服务器的最新语句的列表。 列表的大小由profiling_history_size会话变量控制，该变量的默认值为15.最大值为100.将值设置为0具有禁用性能分析的实际效果。

除SHOW PROFILE和SHOW PROFILES之外，所有语句都进行了概要分析，因此您将不会在配置文件列表中找到这些语句。 对于格式错误的执行语句，例如SHOW PROFILING是一个非法语句，如果您尝试执行该语句，则会出现语法错误，但会显示在概要分析列表中。

SHOW PROFILE显示有关单个语句的详细信息，如果没有追加FOR QUERY n子句，输出与最近执行的语句相关；否则展示特定语句的信息。 n的值对应于SHOW PROFILES显示的Query_ID值。

可以给出LIMIT row_count子句以将输出限制为row_count行。如果给定了LIMIT，则可以添加OFFSET偏移以将输出偏移行开始到整组行。

默认情况下，SHOW PROFILE显示状态和持续时间列。

每个会话启用分析。会话结束时，其分析信息丢失。

说了那么多，上面这些已经被废弃啦！！！！

Note:

这些语句已被逐渐弃用，将在未来的MySQL版本中被删除。

也就是说新版本包括以后的版本对于性能的监控逐渐使用PERFORMANCE_SCHEM代替INFORMATION_SCHEMA -->详见Chapter 25 MySQL Performance Schema

---

Action

已知：

mysql root@127.0.0.1:nt> SELECT * FROM student
+------+--------+-------+-------+|   id | name   |   age | sex   |
|------+--------+-------+-------||    1 | s1     |    12 | m     |
|    2 | s2     |    12 | w     |
|    3 | s3     |    11 | w     |
+------+--------+-------+-------+3 rows in setTime: 0.004s
mysql root@127.0.0.1:nt> SELECT * FROM teacher
+------+--------+|   id | name   |
|------+--------||    1 | Han    |
|    2 | Gou    |
|    3 | Eric   |
+------+--------+3 rows in setTime: 0.002s
mysql root@127.0.0.1:nt> SELECT * FROM course
+------+--------------+----------------+|   id |   teacher_id | name           |
|------+--------------+----------------||    1 |            1 | Advanced Maths |
|    2 |            2 | English        |
|    3 |            3 | Arts           |
|    4 |            1 | Physics        |
|    5 |            3 | Programming    |
+------+--------------+----------------+5 rows in setTime: 0.003s
mysql root@127.0.0.1:nt> SELECT * FROM score
+--------------+-------------+---------+|   student_id |   course_id |   score |
|--------------+-------------+---------||            1 |           1 |      78 |
|            1 |           2 |      56 |
|            1 |           3 |      89 |
|            1 |           4 |      60 |
|            1 |           5 |      92 |
|            2 |           1 |      92 |
|            2 |           2 |      60 |
|            2 |           3 |      78 |
|            2 |           4 |      77 |
|            2 |           5 |      95 |
|            3 |           1 |      66 |
|            3 |           2 |      50 |
|            3 |           3 |      78 |
|            3 |           4 |      67 |
|            3 |           5 |      86 |
+--------------+-------------+---------+15 rows in setTime: 0.003s

解：高数比美术分数高的学生信息

SELECT S.* 
FROM (SELECT SC1.STUDENT_ID,SC1.COURSE_ID,SC1.SCORE FROM score SC1) A,
     (SELECT SC2.STUDENT_ID,SC2.COURSE_ID,SC2.SCORE FROM score SC2) B, 
     student S 
WHERE A.STUDENT_ID=B.STUDENT_ID 
AND   A.COURSE_ID=1 
AND   B.COURSE_ID=3 
AND   A.SCORE>B.SCORE 
AND   A.STUDENT_ID=S.ID;

mysql root@127.0.0.1:nt> SELECT @@profiling
+---------------+
|   @@profiling |
|---------------|
|             0 |
+---------------+
1 row in set
Time: 0.002s
mysql root@127.0.0.1:nt> SET profiling = 1
Query OK, 0 rows affected
Time: 0.001s
mysql root@127.0.0.1:nt> SELECT S.*
                      -> FROM (SELECT SC1.STUDENT_ID,SC1.COURSE_ID,SC1.SCORE FROM score SC1) A,
                      ->      (SELECT SC2.STUDENT_ID,SC2.COURSE_ID,SC2.SCORE FROM score SC2) B,
                      ->      student S
                      -> WHERE A.STUDENT_ID=B.STUDENT_ID
                      -> AND   A.COURSE_ID=1
                      -> AND   B.COURSE_ID=3
                      -> AND   A.SCORE>B.SCORE
                      -> AND   A.STUDENT_ID=S.ID;
+------+--------+-------+-------+
|   id | name   |   age | sex   |
|------+--------+-------+-------|
|    2 | s2     |    12 | w     |
+------+--------+-------+-------+
1 row in set
Time: 0.007s
mysql root@127.0.0.1:nt> SHOW PROFILES
+------------+------------+---------------+
|   Query_ID |   Duration | Query         |
|------------+------------+---------------|
|          1 |   4.5e-05  | SHOW WARNINGS |
|          2 |   0.000603 | SELECT S.*
FROM (SELECT SC1.STUDENT_ID,SC1.COURSE_ID,SC1.SCORE FROM score SC1) A,
     (SELECT SC2.STUDENT_ID,SC2.COURSE_ID,SC2.SCORE FROM score SC2) B,
     student S
WHERE A.STUDENT_ID=B.STUDENT_ID
AND   A.COURSE_ID=1
AND   B.COURSE_ID=3
AND   A.SCORE>B.SCORE
AND   A.STUDENT_ID=S.ID               |
+------------+------------+---------------+
2 rows in set
Time: 0.002s
mysql root@127.0.0.1:nt> SHOW PROFILE FOR QUERY 2
+----------------------+------------+
| Status               |   Duration |
|----------------------+------------|
| starting             |   0.000134 |
| checking permissions |   1.1e-05  |
| checking permissions |   4e-06    |
| checking permissions |   7e-06    |
| Opening tables       |   2.4e-05  |
| init                 |   5.2e-05  |
| System lock          |   1.1e-05  |
| optimizing           |   1.5e-05  |
| statistics           |   0.000161 |
| preparing            |   2.7e-05  |
| executing            |   4e-06    |
| Sending data         |   6.4e-05  |
| end                  |   6e-06    |
| query end            |   7e-06    |
| closing tables       |   8e-06    |
| freeing items        |   5.4e-05  |
| cleaning up          |   1.4e-05  |
+----------------------+------------+
17 rows in set
Time: 0.005s

上面的结果太丑

mysql root@127.0.0.1:nt> set @query_id=2
Query OK, 0 rows affected
Time: 0.001s

使用下面的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(*) CALLS,
    SUM(DURATION)/COUNT(*) AS "R/CALL"
FROM information_schema.PROFILING
WHERE QUERY_ID=@query_id
GROUP BY STATE
ORDER BY TOTAL_R DESC;

mycli执行上面的sql：

+----------------------+-----------+---------+---------+------------+
| STATE                |   TOTAL_R |   PCT_R |   CALLS |     R/CALL |
|----------------------+-----------+---------+---------+------------|
| statistics           |  0.000161 |   26.7  |       1 | 0.000161   |
| starting             |  0.000134 |   22.22 |       1 | 0.000134   |
| Sending data         |  6.4e-05  |   10.61 |       1 | 6.4e-05    |
| freeing items        |  5.4e-05  |    8.96 |       1 | 5.4e-05    |
| init                 |  5.2e-05  |    8.62 |       1 | 5.2e-05    |
| preparing            |  2.7e-05  |    4.48 |       1 | 2.7e-05    |
| Opening tables       |  2.4e-05  |    3.98 |       1 | 2.4e-05    |
| checking permissions |  2.2e-05  |    3.65 |       3 | 7.3333e-06 |
| optimizing           |  1.5e-05  |    2.49 |       1 | 1.5e-05    |
| cleaning up          |  1.4e-05  |    2.32 |       1 | 1.4e-05    |
| System lock          |  1.1e-05  |    1.82 |       1 | 1.1e-05    |
| closing tables       |  8e-06    |    1.33 |       1 | 8e-06      |
| query end            |  7e-06    |    1.16 |       1 | 7e-06      |
| end                  |  6e-06    |    1    |       1 | 6e-06      |
| executing            |  4e-06    |    0.66 |       1 | 4e-06      |
+----------------------+-----------+---------+---------+------------+
15 rows in set
Time: 0.018s

可以看出来，时间消耗占比最高依次：

1. statistics：服务器正在计算统计信息以开发查询执行计划。如果一个线程长时间处于这种状态，服务器可能是磁盘绑定的，执行其他工作

2. starting

3. Sending data：线程正在读取和处理SELECT语句的行，并向客户端发送数据。由于在此状态期间发生的操作往往执行大量的磁盘访问（读取），所以在给定查询的整个生命周期内通常是最长的运行状态

4. freeing items：线程已经执行了一个命令。在这种状态下完成的项目的一些释放涉及查询缓存。这种状态通常是清理

5. init：这发生在ALTER TABLE，DELETE，INSERT，SELECT或UPDATE语句的初始化之前。处于此状态的服务器采取的操作包括刷新二进制日志，InnoDB日志和一些查询缓存清理操作。

对于最终状态，可能会发生以下操作：

• 在表中的数据更改后删除查询缓存条目

• 将事件写入二进制日志

• 释放内存缓冲区，包括Blob

下面看看记录2对应的CPU信息

mysql root@127.0.0.1:nt> SHOW PROFILE CPU FOR QUERY 2
+----------------------+------------+------------+--------------+
| Status               |   Duration |   CPU_user |   CPU_system |
|----------------------+------------+------------+--------------|
| starting             |   0.000134 |   0.000126 |      8e-06   |
| checking permissions |   1.1e-05  |   4e-06    |      6e-06   |
| checking permissions |   4e-06    |   2e-06    |      3e-06   |
| checking permissions |   7e-06    |   4e-06    |      2e-06   |
| Opening tables       |   2.4e-05  |   2.3e-05  |      2e-06   |
| init                 |   5.2e-05  |   4.8e-05  |      3e-06   |
| System lock          |   1.1e-05  |   8e-06    |      2e-06   |
| optimizing           |   1.5e-05  |   1.4e-05  |      2e-06   |
| statistics           |   0.000161 |   0.000113 |      5.3e-05 |
| preparing            |   2.7e-05  |   1.9e-05  |      3e-06   |
| executing            |   4e-06    |   2e-06    |      3e-06   |
| Sending data         |   6.4e-05  |   6.3e-05  |      1e-06   |
| end                  |   6e-06    |   3e-06    |      3e-06   |
| query end            |   7e-06    |   5e-06    |      1e-06   |
| closing tables       |   8e-06    |   7e-06    |      1e-06   |
| freeing items        |   5.4e-05  |   1.3e-05  |      4.2e-05 |
| cleaning up          |   1.4e-05  |   1.2e-05  |      2e-06   |
+----------------------+------------+------------+--------------+
17 rows in set
Time: 0.009s

---

Qs:为什么show profiles结果中的duration和直接执行的时间差距那么大？

Show all information
Displays the count of block input and output operations
Displays the count of voluntary and involuntary context switches
Displays user and system CPU usage time
Displays the count of sent and received messages
Currently not implemented
Display the count of homepage and subpage errors
Displays the name of the function from the source code and the name and line number of the file where the function occurs
Show swap count

The above is the detailed content of INFORMATION_SCHEMA.PROFILING. For more information, please follow other related articles on the PHP Chinese website!