Parse the use of Mysql Profiling

  • 2020-05-24 06:18:40
  • OfStack

profiling is a great tool for analyzing the performance of mysql, so let's try out what profiling can do today. Thanks for loving rose blog:
The main purpose of mysql's sql performance analyzer is to display the usage of various resources throughout the sql execution. Profilers can better illustrate the performance problems of the bad SQL.
The following is an example of how to use MySQL SQL Profiler:
First, turn on 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) the default value of profiling is 0, which means MySQL SQL Profiler is in OFF state, and profiling is 1 when SQL performance analyzer is turned on.
With the help of the sql performance analyzer, we can compare the two execution processes before and after the following statements, which is very helpful for us to understand the detailed execution process of 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)

From the above example, we can clearly see the difference between the two executions of count statement. SHOW PROFILE FOR QUERY 27 shows the execution process of the first count statistics, including Opening tables, Table lock and other operations. While SHOW PROFILE FOR QUERY 28 shows the execution process of the second count statistics, the second count directly returns the count statistics from the query cache. By comparing the total execution time of the two statistics, it is found that the cache read speed is nearly 10 times as fast as the physical read. By using the SQL performance analyzer, we can diagnose some of the SQL that are difficult to determine the performance problem and find the root cause of the problem.

Related articles: