Use the show profile command to analyze the usage of performance in MySQL (better with explain effect, can be used as an optimization periodic check)

This article mainly introduces the use of the show Profile command in MySQL to analyze the performance of the collation, show profiles is a common command of database performance optimization, the need for friends can refer to the following

Show profile was donated by Jeremy Cole to the MySQL community version. The default is off, but session level can turn on this feature. Opening it allows MySQL to collect the resources that are used when executing the statement. For statistical reporting, set profiling to 1

mysql> SET profiling = 1;

After you run a query

Mysql> SELECT count (DISTINCT actor.first_name) as Cnt_name, COUNT (*) as cnt-> from sakila.film_actor-> INNER JOIN Sakila.actor USING (actor_id), GROUP by sakila.film_actor.film_id-> ORDER by Cnt_name DESC; 997 rows in Set (0.03 sec)

The profiling information for this execution statement is stored in this session. Use show profiles to view.

Mysql> SHOW Profiles\g

1. Row ***************************query_id:1duration:0.02596900query:select COUNT (DISTINCT actor.first_name) as Cnt_ Name,...

You can use the show profile statement to get the profiling data that is already stored. If no parameters are added, the status and the duration of their durations are displayed.

mysql> SHOW profile;

+------------------------+-----------+| Status | Duration |+------------------------+-----------+| (initialization) | 0.000005 | | Opening Tables | 0.000033 | | System Lock | 0.000037 | | Table Lock | 0.000024 | | init | 0.000079 | | Optimizing | 0.000024 | | Statistics | 0.000079 | | Preparing | 0.00003 | | Creating tmp Table | 0.000124 | | Executing | 0.000008 | | Copying to TMP Table | 0.010048 | | Creating Sort Index | 0.004769 | | Copying to Group table | 0.0084880 | | Sorting result | 0.001136 | | Sending Data | 0.000925 | | End | 0.00001 | | removing TMP table | 0.00004 | | End | 0.000005 | | removing TMP table | 0.00001 | | End | 0.000011 | | Query End | 0.00001 | | Freeing items | 0.000025 | | removing TMP table | 0.00001 | | Freeing items | 0.000016 | | Closing Tables | 0.000017 | | Logging Slow Query | 0.000006 |+------------------------+-----------+ 

Each row is the process of changing state and how long they last. The Status column and the state of show full processlist should be consistent.
This value is derived from the Thd->proc_info variable. So the value you're looking at is directly from inside MySQL. Although these values are more straightforward to understand, you can also view the MySQL manual.

You can assign a query_id to show profiles to view the specified statement, and you can add a new column to the output. For example, view user and CPU usage. You can use the following command.

Mysql> SHOW profile CPU for QUERY 1;

Show profile can drill down to see how the server executes the statement. And it can also help you understand how time is spent executing statements. Some limitations are the functionality that it does not implement, the inability to view and parse other connected statements, and the consumption caused by profiling.

Show Profiles displays several statements that were recently sent to the server, the number of which is defined according to the session variable Profiling_history_size, the default is 15, and the maximum value is 100. Set to 0 is equivalent to turning off the analysis function.

Show profile for QUERY N, where n is the query_id that corresponds to the show profiles output.

For example:

Mysql> Show Profiles;

+----------+-------------+---------------------------------------+| query_id | Duration | Query     |+----------+-------------+---------------------------------------+| 1 | 0.00037700 | ALTER TABLE table1 Drop column C3 int | | 2 | 70.37123800 | ALTER TABLE table1 Drop Column C3 | | 3 | 0.00124500 | Show Tables    | | 4 | 0.00569800 | SELECT * FROM table1 where id=2 | | 5 | 0.00068500 | Select COUNT (1) from Tables1  | | 6 | 0.00197900 |  Select COUNT (1) from table1  | | 7 | 0.00105900 | ALTER TABLE TABLES1 DROP C1  | | 8 | 0.00800200 | ALTER TABLE table1 Drop C1  |+----------+-------------+---------------------------------------+8 rows in Set (0.00 sec)

Mysql> SHOW profile for QUERY 2; Analysis of #查看alter table table1 Drop column C3

+------------------------------+-----------+| Status   | Duration |+------------------------------+-----------+| Starting | 0.000183 | |   checking Permissions  | 0.000057 | | checking Permissions  | 0.000059 | | init    | 0.0000 60 | | Opening Tables  | 0.000071 | | System lock   | 0.000062 | | Setup   | 0.000080 | | creating Table  | 0.005052 | | After create   | 0.000220 | | Copy to TMP table  | 0.000244 | | Rename result table  | 70.364027 | | end    | 0.000575 | | Waiting for query Cache lock | 0.000062 | | End    | 0.000075 | | query End   | 0.000057 | | closing Tables  | 0.000061 | | freeing Items  | 0.000080 | | log Ging Slow Query  | 0.000056 | | logging slow Query  | 0.000098 | | cleaning up   | 0.000059 |+------------------- -----------+-----------+20 rows in Set (0.00 sec)

If you do not specify a for QUERY, the information for the most recent statement is output.

The use of the Limit section is consistent with the limit clause in select and does not repeat.

The type is optional, and the range of values can be as follows:

• All Show all performance information
• Block IO shows the number of blocks IO operations
• Context switches shows the number of contextual switches, whether active or passive
• CPU displays user CPU time, System CPU time
• IPC displays the number of messages sent and received
• MEMORY [temporarily not implemented]
• Page faults displays the number of pages errors
• Source shows the name and location of the function in the source code
• SWAPS shows the number of swaps

Cases:

Mysql> Show profile CPU for query 2;

+------------------------------+-----------+----------+------------+| Status | Duration | Cpu_user | Cpu_system |+------------------------------+-----------+----------+------------+| Starting | 0.000183 | 0.000000 | 0.000000 | | Checking Permissions | 0.000057 | 0.000000 | 0.000000 | | Checking Permissions | 0.000059 | 0.000000 | 0.000000 | | init | 0.000060 | 0.000000 | 0.000000 | | Opening Tables | 0.000071 | 0.000000 | 0.000000 | | System Lock | 0.000062 | 0.000000 | 0.000000 | | Setup | 0.000080 | 0.000000 | 0.001000 | | Creating Table | 0.005052 | 0.003000 | 0.001000 | | After Create | 0.000220 | 0.000000 | 0.000000 | | Copy to TMP table | 0.000244 | 0.000000 | 0.000000 | | Rename Result Table | 70.364027 | 7.470864 | 41.612674 | | End | 0.000575 | 0.000000 | 0.001000 | | Waiting for query Cache lock | 0.000062 | 0.000000 | 0.000000 | | End | 0.000075 | 0.000000 | 0.000000 | | Query End | 0.000057 | 0.000000 | 0.000000 | | Closing Tables | 0.000061 | 0.000000 | 0.000000 | | Freeing items | 0.000080 | 0.000000 | 0.000000 | | Logging Slow Query | 0.000056 | 0.000000 | 0.000000 | | Logging Slow Query | 0.000098 | 0.000000 | 0.000000 | | Cleaning Up | 0.000059 | 0.000000 | 0.000000 |+------------------------------+-----------+----------+------------+20 rows in Set (0.00 sec)

Ps:
The information of SHOW profile all for QUERY 2 can also be obtained via the SELECT * from information_schema.profiling WHERE query_id = 2 ORDER by seq;

Function range
This command only works within this session, which means that statements outside of this session cannot be parsed.

When analysis is turned on, all statements in this session are parsed (even the statements that execute the error), except for the show profile and show profiles two sentences themselves.

Application Example: Use show profile to analyze the performance benefits of query cache hits.

Mysql> set profiling=1;

Query OK, 0 rows Affected (0.00 sec)

Mysql> Select COUNT (1) as CNT from tran_excution;

+-------+| CNT |+-------+| 14225 |+-------+1 row in Set (0.00 sec)

Because query caching is enabled, the same query (non-partitioned table) can be hit directly in the query cache.

Mysql> Select COUNT (1) as CNT from tran_excution;

Let's take a closer look at the analysis of the two identical statements.

mysql> show profile source for query 1; 
 

+--------------------------------+----------+-----------------------+---------------+-------------+| Status | Duration | source_function | Source_file | Source_line |+--------------------------------+----------+-----------------------+---------------+------------- +| Starting | 0.000048 | NULL | NULL | NULL | | Waiting for query Cache lock | 0.000013 | Try_lock |  sql_cache.cc | 454 | | Checking query cache for Query | 0.000040 | send_result_to_client | sql_cache.cc | 1561 | | Checking Permissions | 0.000023 | check_access | sql_parse.cc | 4751 | | Opening Tables | 0.000040 | Open_tables | sql_base.cc | 4831 | | System Lock | 0.000020 | Mysql_lock_tables |  lock.cc | 299 | | Waiting for query Cache lock | 0.000037 | Try_lock |  sql_cache.cc | 454 | | init | 0.000020 | Mysql_select | sql_select.cc | 2579 | | Optimizing | 0.000015 | Optimize |  sql_select.cc | 865 | | Statistics | 0.000017 | Optimize | sql_select.cc | 1056 | | Preparing | 0.000016 | Optimize | Sql_select.cc | 1078 | | Executing | 0.000015 | exec | sql_select.cc | 1836 | | Sending Data | 0.003875 | exec | sql_select.cc | 2380 | | End | 0.000018 | Mysql_select | sql_select.cc | 2615 | | Query End | 0.000015 | Mysql_execute_command | sql_parse.cc | 4440 | | Closing Tables | 0.000016 | Mysql_execute_command | sql_parse.cc | 4492 | | Freeing items | 0.000016 | Mysql_parse | sql_parse.cc | 5640 | | Waiting for query Cache lock | 0.000012 | Try_lock |  sql_cache.cc | 454 | | Freeing items | 0.000032 | NULL | NULL | NULL | | Waiting for query Cache lock | 0.000017 | Try_lock |  sql_cache.cc | 454 | | Freeing items | 0.000016 | NULL | NULL | NULL | | Storing result in query cache | 0.000017 | End_of_result | sql_cache.cc | 1020 | | Logging Slow Query | 0.000018 | log_slow_statement | sql_parse.cc | 1461 | | Logging Slow Query | 0.000050 | log_slow_statement | sql_parse.cc | 1470 | | Cleaning Up | 0.000018 | Dispatch_command | sql_parse.cc | 1417 |+--------------------------------+----------+-----------------------+---------------+-------------+25 rows in Set (0.00 sec) 

Mysql> Show profile source for query 2;

+--------------------------------+----------+-----------------------+--------------+-------------+| Status | Duration | source_function | Source_file | Source_line |+--------------------------------+----------+-----------------------+--------------+-------------+ | Starting | 0.000051 | NULL | NULL | NULL | | Waiting for query Cache lock | 0.000014 | Try_lock |  sql_cache.cc | 454 | | Checking query cache for Query | 0.000016 | send_result_to_client | sql_cache.cc | 1561 | | Checking privileges on Cached | 0.000013 | send_result_to_client | sql_cache.cc | 1652 | | Checking Permissions | 0.000015 | check_access | sql_parse.cc | 4751 | | Sending cached result to Clien | 0.000036 | send_result_to_client | sql_cache.cc | 1749 | | Logging Slow Query | 0.000017 | log_slow_statement | sql_parse.cc | 1461 | | Cleaning Up | 0.000018 | Dispatch_command | sql_parse.cc | 1417 |+--------------------------------+----------+-----------------------+--------------+-------------+8 rows in Set (0.00 sec) 

You can clearly see the cache in the hit, greatly saving the overhead of the background. Of course, the use of the cache also needs to be based on a variety of scenarios (table data size, update frequency, etc.) to investigate, not to enable caching will certainly improve query efficiency. This is only an example of an application for show profile.

Use the show profile command to analyze the usage of performance in MySQL (better with explain effect, can be used as an optimization periodic check)