# 4. 通过 SHOW PROFILE 分析 SQL MySQL 从 5.0.37 版本开始增加了对 **SHOW PROFILES** 和 **SHOW PROFILE** 语句的支持。 {% hint style="info" %} 通过 **have\_profiling 参数**，能够看到当前 MySQL 是否**支持** profile： ```sql mysql> SELECT @@have_profiling; +------------------+ | @@have_profiling | +------------------+ | YES | +------------------+ 1 row in set, 1 warning (0.00 sec) ``` 通过 **profiling** 参数，可以控制是否启用 profile 功能： ```sql SET PROFILING = 1; SELECT @@profiling; -- 设置列表容量大小 SET profiling_history_size := 100; ``` 注意：如果在 **datagrip** 上使用 profile，如果不设置 **profiling\_history\_size** 扩大列表容量，因为 datagrip 增加一些隐式的 sql 调用，因此会非常快速的耗尽列表容量，导致想要分析的目标 SQL 被挤出去，导致 profile 功能无法正常使用！ {% endhint %} 通过 profile，能够更清楚地了解 SQL 执行的过程。 首先，在一个 innodb 引擎的付款表 payment 上，执行一个 COUNT(\*) 查询： ```sql SELECT count(*) FROM payment; +----------+ | count(*) | +----------+ | 16044 | +----------+ 1 row in set (0.00 sec) ``` 执行完毕后，通过 **SHOW PROFILES** 语句，看到当前 SQL 的 Query ID 为 4： ```sql SHOW PROFILES; +----------+------------+------------------------------+ | Query_ID | Duration | Query | +----------+------------+------------------------------+ | 1 | 0.00023450 | SELECT @@have_profiling | | 2 | 0.00015275 | show warnings | | 3 | 0.00018550 | select @profiling | | 4 | 0.00257575 | SELECT count(*) FROM payment | +----------+------------+------------------------------+ 4 rows in set, 1 warning (0.00 sec) ``` 通过 **SHOW PROFILE FOR QUERY** 语句能够看到执行过程中线程的每个状态和消耗的时间： ```sql SHOW PROFILE FOR QUERY 4; +----------------------+----------+ | Status | Duration | +----------------------+----------+ | starting | 0.000075 | | checking permissions | 0.000006 | | Opening tables | 0.000022 | | init | 0.000010 | | System lock | 0.000006 | | optimizing | 0.000004 | | statistics | 0.000013 | | preparing | 0.000009 | | executing | 0.000001 | | Sending data | 0.002319 | | end | 0.000003 | | query end | 0.000006 | | closing tables | 0.000005 | | freeing items | 0.000086 | | cleaning up | 0.000012 | +----------------------+----------+ 15 rows in set, 1 warning (0.00 sec) ``` {% hint style="info" %} **Sending data** 状态表示 MySQL 线程开始访问数据行并把结果返回给客户端，而不仅仅是返回结果给客户端。**由于在 Sending data 状态下，MySQL 线程往往需要做大量的磁盘读取操作，所以经常是整个查询中耗时最长的状态。** {% endhint %} 为了更清晰地看到排序结果，可以查询 **INFORMATION\_SCHEMA.PROFILING** 表并按照时间做个 DESC 排序： ```sql mysql> SET @query_id := 4; Query OK, 0 rows affected (0.00 sec) mysql> 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(*) AS Calls, -> SUM(DURATION) / COUNT(*) AS "R/Call" -> FROM INFORMATION_SCHEMA.PROFILING -> WHERE QUERY_ID = @query_id -> GROUP BY STATE -> ORDER BY Total_R DESC; +----------------------+----------+-------+-------+--------------+ | STATE | Total_R | Pct_R | Calls | R/Call | +----------------------+----------+-------+-------+--------------+ | Sending data | 0.002319 | 89.99 | 1 | 0.0023190000 | | freeing items | 0.000086 | 3.34 | 1 | 0.0000860000 | | starting | 0.000075 | 2.91 | 1 | 0.0000750000 | | Opening tables | 0.000022 | 0.85 | 1 | 0.0000220000 | | statistics | 0.000013 | 0.50 | 1 | 0.0000130000 | | cleaning up | 0.000012 | 0.47 | 1 | 0.0000120000 | | init | 0.000010 | 0.39 | 1 | 0.0000100000 | | preparing | 0.000009 | 0.35 | 1 | 0.0000090000 | | query end | 0.000006 | 0.23 | 1 | 0.0000060000 | | System lock | 0.000006 | 0.23 | 1 | 0.0000060000 | | checking permissions | 0.000006 | 0.23 | 1 | 0.0000060000 | | closing tables | 0.000005 | 0.19 | 1 | 0.0000050000 | | optimizing | 0.000004 | 0.16 | 1 | 0.0000040000 | | end | 0.000003 | 0.12 | 1 | 0.0000030000 | | executing | 0.000001 | 0.04 | 1 | 0.0000010000 | +----------------------+----------+-------+-------+--------------+ 15 rows in set, 16 warnings (0.00 sec) ``` 在获取到最消耗时间的线程状态后，MySQL 支持进一步选择 **all**、**cpu**、**block io**、**context switch**、**page faults** 等明细类型来查看 MySQL 在使用什么资源上耗费了过高的时间。 ```sql mysql> SHOW PROFILE CPU FOR QUERY 4; +----------------------+----------+----------+------------+ | Status | Duration | CPU_user | CPU_system | +----------------------+----------+----------+------------+ | starting | 0.000075 | 0.000000 | 0.000000 | | checking permissions | 0.000006 | 0.000000 | 0.000000 | | Opening tables | 0.000022 | 0.000000 | 0.000000 | | init | 0.000010 | 0.000000 | 0.000000 | | System lock | 0.000006 | 0.000000 | 0.000000 | | optimizing | 0.000004 | 0.000000 | 0.000000 | | statistics | 0.000013 | 0.000000 | 0.000000 | | preparing | 0.000009 | 0.000000 | 0.000000 | | executing | 0.000001 | 0.000000 | 0.000000 | | Sending data | 0.002319 | 0.000000 | 0.000000 | | end | 0.000003 | 0.000000 | 0.000000 | | query end | 0.000006 | 0.000000 | 0.000000 | | closing tables | 0.000005 | 0.000000 | 0.000000 | | freeing items | 0.000086 | 0.000000 | 0.000000 | | cleaning up | 0.000012 | 0.000000 | 0.000000 | +----------------------+----------+----------+------------+ 15 rows in set, 1 warning (0.00 sec) ``` --- # Agent Instructions: Querying This Documentation If you need additional information that is not directly available in this page, you can query the documentation dynamically by asking a question. Perform an HTTP GET request on the current page URL with the `ask` query parameter: ``` GET https://bohans.gitbook.io/ji-chu/mysql/sql-you-hua/cha-xun-you-hua/you-hua-sql-yu-ju-de-yi-ban-bu-zhou/4.-tong-guo-show-profile-fen-xi-sql.md?ask= ``` The question should be specific, self-contained, and written in natural language. The response will contain a direct answer to the question and relevant excerpts and sources from the documentation. Use this mechanism when the answer is not explicitly present in the current page, you need clarification or additional context, or you want to retrieve related documentation sections.