MySQL performance analysis tool profile tutorial _ MySQL

This article mainly introduces the MySQL performance analysis tool profile tutorial, this article describes how to use MySQLprofile, does not involve specific sample analysis, if you need it, you can refer to the analysis of SQL execution overhead, which is an important means to optimize SQL. In MySQL databases, you can configure the profiling parameter to enable SQL profiling. This parameter can be set at the global and session level. The global level applies to the entire MySQL instance, while the session level closely affects the current session. After this parameter is enabled, subsequent SQL statements record their resource overhead, such as IO, context switching, CPU, and Memory. Based on these overhead, the current SQL bottleneck is further analyzed for optimization and adjustment. This document describes how to use the MySQL profile without a specific sample analysis.

1. profile description

The code is as follows:

-- Current version
Root @ localhost [sakila]> show variables like 'version ';
+ --------------- + ----------------------------------------- +
| Variable_name | Value |
+ --------------- + ----------------------------------------- +
| Version | 5.6.17-enterprise-defined cial-advanced |
+ --------------- + ----------------------------------------- +

-- View profiling system variables
Root @ localhost [sakila]> show variables like '% profil % ';
+ ------------------------ + ------- +
| Variable_name | Value |
+ ------------------------ + ------- +
| Have_profiling | YES | -- Read-only variable, used to control whether profiling is enabled or disabled by system variables
| Profiling | OFF | -- enable SQL statement profiling
| Profiling_history_size | 15 | -- sets the number of reserved profiling. the default value is 15. The range is 0 to 100. if the value is 0, profiling is disabled.
+ ------------------------ + ------- +

Profiling [539]
If set to 0 or OFF (the default), statement profiling is disabled. If set to 1 or ON, statement prof
Is enabled and the show profile and show profiles statements provide access to prof
Information. See Section 13.7.5.32, "show profiles Syntax ".

This variable is deprecated in MySQL 5.6.8 and will be removed in a future MySQL release.
Profiling_history_size [1, 539]
The number of statements for which to maintain profiling information if profiling [0, 539] is
Enabled. The default value is 15. The maximum value is 100. Setting the value to 0 when tively
Disables profiling. See Section 13.7.5.32, "show profiles Syntax ".
This variable is deprecated in MySQL 5.6.8 and will be removed in a future MySQL release.


-- Get profile Help
Root @ localhost [sakila]> help profile;
Name: 'Show PROFILE'
Description:
Syntax:
Show profile [type [, type]...]
[For query n]
[LIMIT row_count [OFFSET offset]

Type:
ALL -- display ALL overhead information
| Block io -- Display block io-related overhead
| Context switches -- CONTEXT switching overhead
| CPU -- displays CPU-related overhead information
| IPC -- display sending and receiving expenses
| MEMORY -- display MEMORY-related overhead information
| Page faults -- display overhead information related to PAGE errors
| SOURCE -- displays overhead information related to Source_function, Source_file, and Source_line.
| SWAPS -- display overhead information related to the number of exchanges

The show profile and show profiles statements display profiling
Information that indicates resource usage for statements executed
During the course of the current session.

* Note *: These statements are deprecated as of MySQL 5.6.7 and will be
Removed in a future MySQL release. Use the Performance Schema instead;
See http://dev.mysql.com/doc/refman/5.6/en/performance-schema.html.
-- The command will be removed from 5.6.7 and replaced with Performance Schema instead.
-- In Oracle databases, autotrace is used to analyze a single SQL statement and obtain real execution plans and overhead information.

2. enable porfiling

The code is as follows:

-- Enable session-level profiling
Root @ localhost [sakila]> set profiling = 1;
Query OK, 0 rows affected, 1 warning (0.00 sec)

-- Verify the modified result
Root @ localhost [sakila]> show variables like '% profil % ';
+ ------------------------ + ------- +
| Variable_name | Value |
+ ------------------------ + ------- +
| Have_profiling | YES |
| Profiling | ON |
| Profiling_history_size | 15 |
+ ------------------------ + ------- +

-- Publish SQL queries
Root @ localhost [sakila]> select count (*) from customer;
+ ---------- +
| Count (*) |
+ ---------- +
| 1, 599 |
+ ---------- +

-- View all generated profiles of the current session
Root @ localhost [sakila]> show profiles;
+ ---------- + ------------ + -------------------------------- +
| Query_ID | Duration | Query |
+ ---------- + ------------ + -------------------------------- +
| 1 | 0.00253600 | show variables like '% profil %' |
| 2 | 0.00138150 | select count (*) from customer |
+ ---------- + ------------ + -------------------------------- +
2 rows in set, 1 warning (0.01 sec)

-- We can see that there are two warning, the previous one, now one
Root @ localhost [sakila]> show warnings; -- The following result indicates that show profiles will be replaced by Performance Schema in the future.
+ --------- + ------ + Response +
| Level | Code | Message |
+ --------- + ------ + Response +
| Warning | 1287 | 'show profiles' is deprecated and will be removed in a future release. Please use Performance Schema instead |
+ --------- + ------ + Response +

3. obtain overhead information of SQL statements

The code is as follows:

-- You can directly use show profile to view the overhead information of the previous SQL statement.
-- Note: Statements such as show profile will not be profiling, that is, they will not generate Profiling
-- The show profile below shows the corresponding overhead generated by show warnings.
Root @ localhost [sakila]> show profile;
+ ---------------- + ---------- +
| Status | Duration |
+ ---------------- + ---------- +
| Startling | 0.000141 |
| Query end | 0.000058 |
| Closing tables | 0.000014 |
| Freeing items | 0.001802 |
| Cleaningup | 0.000272 |
+ ---------------- + ---------- +

-- The following query show warnings is added to profiles.
Root @ localhost [sakila]> show profiles;
+ ---------- + ------------ + -------------------------------- +
| Query_ID | Duration | Query |
+ ---------- + ------------ + -------------------------------- +
| 1 | 0.00253600 | show variables like '% profil %' |
| 2 | 0.00138150 | select count (*) from customer |
| 3 | 0.00228600 | show warnings |
+ ---------- + ------------ + -------------------------------- +

-- Get the overhead of the specified query
Root @ localhost [sakila]> show profile for query 2;
+ ---------------------- + ---------- +
| Status | Duration |
+ ---------------------- + ---------- +
| Startling | 0.000148 |
| Check permissions | 0.000014 |
| Opening tables | 0.000047 |
| Init | 1, 0.000023 |
| System lock | 0.000035 |
| Optimizing | 0.000012 |
| Statistics | 0.000019 |
| Preparing | 0.000014 |
| Executing | 0.000006 |
| Sendingdata | 0.000990 |
| End| 0.000010 |
| Query end | 0.000011 |
| Closing tables | 0.000010 |
| Freeing items | 0.000016 |
| Cleaningup | 0.000029 |
+ ---------------------- + ---------- +

-- View the overhead of a specific part. The following figure shows the overhead of the CPU part.
Root @ localhost [sakila]> show profile cpu for query 2;
+ ---------------------- + ---------- + ------------ +
| Status | Duration | CPU_user | CPU_system |
+ ---------------------- + ---------- + ------------ +
| Starting | 0.000148 | 0.000000 | 0.000000 |
| Checking permissions | 0.000014 | 0.000000 | 0.000000 |
| Opening tables | 0.000047 | 0.000000 | 0.000000 |
| Init | 0.000023 | 0.000000 | 0.000000 |
| System lock | 0.000035 | 0.000000 | 0.000000 |
| Optimizing | 0.000012 | 0.000000 | 0.000000 |
| Statistics | 0.000019 | 0.000000 | 0.000000 |
| Preparing | 0.000014 | 0.000000 | 0.000000 |
| Executing | 0.000006 | 0.000000 | 0.000000 |
| Sending data | 0.000990 | 0.001000 | 0.000000 |
| End | 0.000010 | 0.000000 | 0.000000 |
| Query end | 0.000011 | 0.000000 | 0.000000 |
| Closing tables | 0.000010 | 0.000000 | 0.000000 |
| Freeing items | 0.000016 | 0.000000 | 0.000000 |
| Cleaning up | 0.000029 | 0.000000 | 0.000000 |
+ ---------------------- + ---------- + ------------ +

-- The following is the MEMORY overhead.
Root @ localhost [sakila]> show profile memory for query 2;
+ ---------------------- + ---------- +
| Status | Duration |
+ ---------------------- + ---------- +
| Startling | 0.000148 |
| Check permissions | 0.000014 |
| Opening tables | 0.000047 |
| Init | 1, 0.000023 |
| System lock | 0.000035 |
| Optimizing | 0.000012 |
| Statistics | 0.000019 |
| Preparing | 0.000014 |
| Executing | 0.000006 |
| Sendingdata | 0.000990 |
| End| 0.000010 |
| Query end | 0.000011 |
| Closing tables | 0.000010 |
| Freeing items | 0.000016 |
| Cleaningup | 0.000029 |
+ ---------------------- + ---------- +

-- View different resource overhead at the same time
Root @ localhost [sakila]> show profile block io, cpu for query 2;
+ ---------------------- + ---------- + ------------ + -------------- + --------------- +
| Status | Duration | CPU_user | CPU_system | Block_ops_in | Block_ops_out |
+ ---------------------- + ---------- + ------------ + -------------- + --------------- +
| Starting | 0.000148 | 0.000000 | 0.000000 | 0 | 0 |
| Checking permissions | 0.000014 | 0.000000 | 0.000000 | 0 | 0 |
| Opening tables | 0.000047 | 0.000000 | 0.000000 | 0 | 0 |
| Init | 0.000023 | 0.000000 | 0.000000 | 0 | 0 |
| System lock | 0.000035 | 0.000000 | 0.000000 | 0 | 0 |
| Optimizing | 0.000012 | 0.000000 | 0.000000 | 0 | 0 |
| Statistics | 0.000019 | 0.000000 | 0.000000 | 0 | 0 |
| Preparing | 0.000014 | 0.000000 | 0.000000 | 0 | 0 |
| Executing | 0.000006 | 0.000000 | 0.000000 | 0 | 0 |
| Sending data | 0.000990 | 0.001000 | 0.000000 | 0 | 0 |
| End | 0.000010 | 0.000000 | 0.000000 | 0 | 0 |
| Query end | 0.000011 | 0.000000 | 0.000000 | 0 | 0 |
| Closing tables | 0.000010 | 0.000000 | 0.000000 | 0 | 0 |
| Freeing items | 0.000016 | 0.000000 | 0.000000 | 0 | 0 |
| Cleaning up | 0.000029 | 0.000000 | 0.000000 | 0 | 0 |
+ ---------------------- + ---------- + ------------ + -------------- + --------------- +


-- The following SQL statement is used to query the SQL overhead of query_id 2, which is sorted in descending order by the maximum consumption time
Root @ localhost [sakila]> set @ query_id = 2;

Root @ localhost [sakila]> 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 cils,
-> 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 | CILS | R/Call |
+ ---------------------- + ---------- + ------- + -------------- +
| Sending data | 0.000990 | 71.53 | 1 | 0.0009900000 | -- the maximum consumption time is sent data.
| Starting | 0.000148 | 10.69 | 1 | 0.0001480000 |
| Opening tables | 0.000047 | 3.40 | 1 | 0.0000470000 |
| System lock | 0.000035 | 2.53 | 1 | 0.0000350000 |
| Cleaning up | 0.000029 | 2.10 | 1 | 0.0000290000 |
| Init | 0.000023 | 1.66 | 1 | 0.0000230000 |
| Statistics | 0.000019 | 1.37 | 1 | 0.0000190000 |
| Freeing items | 0.000016 | 1.16 | 1 | 0.0000160000 |
| Preparing | 0.000014 | 1.01 | 1 | 0.0000140000 |
| Checking permissions | 0.000014 | 1.01 | 1 | 0.0000140000 |
| Optimizing | 0.000012 | 0.87 | 1 | 0.0000120000 |
| Query end | 0.000011 | 0.79 | 1 | 0.0000110000 |
| End | 0.000010 | 0.72 | 1 | 0.0000100000 |
| Closing tables | 0.000010 | 0.72 | 1 | 0.0000100000 |
| Executing | 0.000006 | 0.43 | 1 | 0.0000060000 |
+ ---------------------- + ---------- + ------- + -------------- +

-- After profiling is enabled, we can view the overhead information in the information_schema.profiling table by using show profile and other methods.
-- The following query is omitted.
Profiling
Root @ localhost [information_schema]> select * from profiling limit 3 \ G;
* *************************** 1. row ***************************
QUERY_ID: 1
SEQ: 5
STATE: init
DURATION: 0.000020
CPU _ User: 0.000000
CPU_SYSTEM: 0.000000
CONTEXT_VOLUNTARY: 0
CONTEXT_INVOLUNTARY: 0
BLOCK_OPS_IN: 0
BLOCK_OPS_OUT: 0
MESSAGES_SENT: 0
MESSAGES_RECEIVED: 0
PAGE_FAULTS_MAJOR: 0
PAGE_FAULTS_MINOR: 0
SWAPS: 0
SOURCE_FUNCTION: mysql_prepare_select
SOURCE_FILE: SQL _select.cc
SOURCE_LINE: 1050

-- Stop profile. you can set the profiling parameter, or after the session exits, profiling will be automatically disabled.
Root @ localhost [sakila]> set profiling = off;
Query OK, 0 rows affected, 1 warning (0.00 sec)