解析Mysql Profiling的使用
程序员文章站
2024-02-24 13:57:04
profiling是个很好用的mysql性能分析工具,今儿就来试验下profiling的功能。感谢 有爱玫瑰的博文:mysql 的 sql 性能分析器主要用途是显示 sql...
profiling是个很好用的mysql性能分析工具,今儿就来试验下profiling的功能。感谢 有爱玫瑰的博文:
mysql 的 sql 性能分析器主要用途是显示 sql 执行的整个过程中各项资源的使用情况。分析器可以更好的展示出不良 sql 的性能问题所在。
下面我们举例介绍一下mysql sql profiler的使用方法:
首先,开启 mysql sql profiler
mysql> select @@profiling;
+-------------+
| @@profiling |
+-------------+
| 0 |
+-------------+
1 row in set (0.00 sec)
mysql> set profiling = 1;
query ok, 0 rows affected (0.00 sec)
mysql> select @@profiling;
+-------------+
| @@profiling |
+-------------+
| 1 |
+-------------+
1 row in set (0.00 sec)默认情况下 profiling 的值为 0 表示 mysql sql profiler 处于 off 状态,开启 sql 性能分析器后 profiling 的值为 1.
通过 sql 性能分析器,我们来对比一下 下列语句前后 2 次执行过程的差异,对我们了解 sql 的详细执行过程是非常有帮助的。
mysql> create table t_engines select * from t_engines1;
query ok, 57344 rows affected (0.10 sec)
records: 57344 duplicates: 0 warnings: 0
mysql> select count(*) from t_engines;
+----------+
| count(*) |
+----------+
| 57344 |
+----------+
1 row in set (0.00 sec)
mysql> select count(*) from t_engines;
+----------+
| count(*) |
+----------+
| 57344 |
+----------+
1 row in set (0.00 sec)
mysql> show profiles;
+----------+------------+-------------------------------------------------+
| query_id | duration | query |
+----------+------------+-------------------------------------------------+
| 26 | 0.10213775 | create table t_engines select * from t_engines1 |
| 27 | 0.00032775 | select count(*) from t_engines |
| 28 | 0.00003850 | select count(*) from t_engines |
+----------+------------+-------------------------------------------------+
15 rows in set (0.01 sec)
mysql> show profile for query 27;
+--------------------------------+------------+
| status | duration |
+--------------------------------+------------+
| (initialization) | 0.00000425 |
| checking query cache for query | 0.00004050 |
| checking permissions | 0.00001050 |
| opening tables | 0.00018250 |
| system lock | 0.00000450 |
| table lock | 0.00001775 |
| init | 0.00001075 |
| optimizing | 0.00000550 |
| executing | 0.00002775 |
| end | 0.00000450 |
| query end | 0.00000325 |
| storing result in query cache | 0.00000400 |
| freeing items | 0.00000400 |
| closing tables | 0.00000500 |
| logging slow query | 0.00000300 |
+--------------------------------+------------+
15 rows in set (0.00 sec)
mysql> show profile for query 28;
+-------------------------------------+------------+
| status | duration |
+-------------------------------------+------------+
| (initialization) | 0.00000350 |
| checking query cache for query | 0.00000750 |
| checking privileges on cached query | 0.00000500 |
| checking permissions | 0.00000525 |
| sending cached result to client | 0.00001275 |
| logging slow query | 0.00000450 |
+-------------------------------------+------------+
6 rows in set (0.00 sec) mysql> select sum( format(duration, 6)) as duration from information_schema.profiling where query_id =27 order by seq;
+----------+
| duration |
+----------+
| 0.000326 |
+----------+
1 row in set (0.00 sec) mysql> select sum( format(duration, 6)) as duration from information_schema.profiling where query_id =28 order by seq;
+----------+
| duration |
+----------+
| 0.000039 |
+----------+
1 row in set (0.00 sec)
从上面的例子中我们可以清晰的看出 2 次执行 count 语句的差别, show profile for query 27 展现的是第一次 count 统计的执行过程,包含了 opening tables 、 table lock 等操作 。而 show profile for query 28 展示了第二次 count 统计的执行过程 , 第二次 count 直接从查询缓存中返回 count 统计结果,通过对比 2 次统计的总执行时间发现,缓存读的速度接近物理读的 10 倍。通过使用 sql 性能分析器可以帮助我们对一些比较难以确定性能问题的 sql 进行诊断,找出问题根源。
mysql 的 sql 性能分析器主要用途是显示 sql 执行的整个过程中各项资源的使用情况。分析器可以更好的展示出不良 sql 的性能问题所在。
下面我们举例介绍一下mysql sql profiler的使用方法:
首先,开启 mysql sql profiler
复制代码 代码如下:
mysql> select @@profiling;
+-------------+
| @@profiling |
+-------------+
| 0 |
+-------------+
1 row in set (0.00 sec)
mysql> set profiling = 1;
query ok, 0 rows affected (0.00 sec)
mysql> select @@profiling;
+-------------+
| @@profiling |
+-------------+
| 1 |
+-------------+
1 row in set (0.00 sec)默认情况下 profiling 的值为 0 表示 mysql sql profiler 处于 off 状态,开启 sql 性能分析器后 profiling 的值为 1.
通过 sql 性能分析器,我们来对比一下 下列语句前后 2 次执行过程的差异,对我们了解 sql 的详细执行过程是非常有帮助的。
复制代码 代码如下:
mysql> create table t_engines select * from t_engines1;
query ok, 57344 rows affected (0.10 sec)
records: 57344 duplicates: 0 warnings: 0
mysql> select count(*) from t_engines;
+----------+
| count(*) |
+----------+
| 57344 |
+----------+
1 row in set (0.00 sec)
mysql> select count(*) from t_engines;
+----------+
| count(*) |
+----------+
| 57344 |
+----------+
1 row in set (0.00 sec)
mysql> show profiles;
+----------+------------+-------------------------------------------------+
| query_id | duration | query |
+----------+------------+-------------------------------------------------+
| 26 | 0.10213775 | create table t_engines select * from t_engines1 |
| 27 | 0.00032775 | select count(*) from t_engines |
| 28 | 0.00003850 | select count(*) from t_engines |
+----------+------------+-------------------------------------------------+
15 rows in set (0.01 sec)
mysql> show profile for query 27;
+--------------------------------+------------+
| status | duration |
+--------------------------------+------------+
| (initialization) | 0.00000425 |
| checking query cache for query | 0.00004050 |
| checking permissions | 0.00001050 |
| opening tables | 0.00018250 |
| system lock | 0.00000450 |
| table lock | 0.00001775 |
| init | 0.00001075 |
| optimizing | 0.00000550 |
| executing | 0.00002775 |
| end | 0.00000450 |
| query end | 0.00000325 |
| storing result in query cache | 0.00000400 |
| freeing items | 0.00000400 |
| closing tables | 0.00000500 |
| logging slow query | 0.00000300 |
+--------------------------------+------------+
15 rows in set (0.00 sec)
mysql> show profile for query 28;
+-------------------------------------+------------+
| status | duration |
+-------------------------------------+------------+
| (initialization) | 0.00000350 |
| checking query cache for query | 0.00000750 |
| checking privileges on cached query | 0.00000500 |
| checking permissions | 0.00000525 |
| sending cached result to client | 0.00001275 |
| logging slow query | 0.00000450 |
+-------------------------------------+------------+
6 rows in set (0.00 sec) mysql> select sum( format(duration, 6)) as duration from information_schema.profiling where query_id =27 order by seq;
+----------+
| duration |
+----------+
| 0.000326 |
+----------+
1 row in set (0.00 sec) mysql> select sum( format(duration, 6)) as duration from information_schema.profiling where query_id =28 order by seq;
+----------+
| duration |
+----------+
| 0.000039 |
+----------+
1 row in set (0.00 sec)
从上面的例子中我们可以清晰的看出 2 次执行 count 语句的差别, show profile for query 27 展现的是第一次 count 统计的执行过程,包含了 opening tables 、 table lock 等操作 。而 show profile for query 28 展示了第二次 count 统计的执行过程 , 第二次 count 直接从查询缓存中返回 count 统计结果,通过对比 2 次统计的总执行时间发现,缓存读的速度接近物理读的 10 倍。通过使用 sql 性能分析器可以帮助我们对一些比较难以确定性能问题的 sql 进行诊断,找出问题根源。