14, SQL optimization tool
1. Slow query log
MySQL's slow query log is a kind of log record provided by mysql. It is used to record the statements whose response time exceeds the threshold in MySQL. Specifically, it refers to the statements whose running time exceeds long_ query_ SQL with time value will be recorded in the slow query log. long_ query_ The default value of time is 10. SQL statements that run for more than 10 seconds will be recorded. The slow query log is used to check which SQL exceeds our maximum endurance time. For example, if an SQL is executed for more than 5 seconds, we will be slow. We hope to collect SQL for more than 5 seconds and conduct a comprehensive analysis in combination with explain.
1.1 enable slow query log
By default, MySQL database does not enable slow query log, so we need to set this parameter manually. If it is not necessary for tuning, it is generally not recommended to turn on this parameter, because turning on the slow query log will more or less have a certain performance impact.
First, check whether the slow query log of mysql is enabled by the following command:
SHOW VARIABLES LIKE '%slow_query_log%';
slow_query_log OFF indicates that the slow query log is turned OFF, slow_query_log_file indicates the storage location of the log.
Start the slow query log with the following command:
SET GLOBAL slow_query_log = 1;
Using this method, the slow query log is enabled. It only takes effect for the current database. If MySQL is restarted, it will become invalid. If you want to take effect permanently, you must modify the configuration file my cnf. Modify the following position:
[mysqld] slow_query_log =1 slow_query_log_file=/var/lib/mysql/Heygo-slow.log
1.2 modify parameters
After the slow query log is enabled, what kind of SQL will be recorded in the slow query? This is determined by the parameter long_query_time control, long by default_ query_ The value of time is 10 seconds. Use the following command to view the threshold of slow SQL records:
SHOW VARIABLES LIKE 'long_query_time%';
In addition, the running time is exactly equal to long_query_time is not recorded.
This threshold can be modified manually and temporarily through the command (my.cnf needs to be modified for permanent modification):
SET GLOBAL long_query_time = 5;
After execution, you need to reconnect or open a new client connection to see the modified value.
1.3 viewing logs
Now, execute the following statement, and it will be recorded by slow log:
SELECT sleep(6);
The slow query log file is under / var/lib/mysql / by default, and the suffix is - slow Log, check:
cat 68926f356828-slow.log mysqld, Version: 5.7.37 (MySQL Community Server (GPL)). started with: Tcp port: 3306 Unix socket: /var/run/mysqld/mysqld.sock Time Id Command Argument # Time: 2022-01-28T10:57:27.035023Z # User@Host: root[root] @ [192.168.142.3] Id: 7 # Query_time: 6.000578 Lock_time: 0.000000 Rows_sent: 1 Rows_examined: 0 SET timestamp=1643367447; SELECT sleep(6);
Query the number of slow query records in the current system:
SHOW GLOBAL STATUS LIKE '%Slow_queries%';
1.4 log analysis command
In the production environment, if you want to manually analyze logs, find and analyze SQL, it is obviously an individual effort. MySQL provides a log analysis tool mysqldumpslow.
# View help: mysqldumpslow --help
Usage: mysqldumpslow [ OPTS... ] [ LOGS... ]
Parse and summarize the MySQL slow query log. Options are
--verbose verbose
--debug debug
--help write this text to standard output
-v verbose
-d debug
-s ORDER what to sort by (al, at, ar, c, l, r, t), 'at' is default # Indicates how to sort. The default is at
al: average lock time # By average lock time
ar: average rows sent # Return records by average
at: average query time # By average query time
c: count # By visits
l: lock time # Press lock time
r: rows sent # Press to return to the record
t: query time # By query time
-r reverse the sort order (largest last instead of first)
-t NUM just show the top n queries # Only the first N queries are displayed
-a don't abstract all numbers to N and strings to 'S'
-n NUM abstract numbers with at least n digits within names
-g PATTERN grep: only consider stmts that include this string # Matches the specified string
-h HOSTNAME hostname of db server for *-slow.log filename (can be wildcard),
default is '*', i.e. match all
-i NAME name of server instance (if using mysql.server startup script)
-l don't subtract lock time from total time
Common usage examples:
# Get up to 10 SQL statements that return recordsets mysqldumpslow -s r -t 10 /var/lib/mysql/68926f356828-slow.log # Get the top 10 SQL queries accessed mysqldumpslow -s c -t 10 /var/lib/mysql/68926f356828-slow.log # Get the first 10 query statements with left connection in chronological order mysqldumpslow -s t -t 10 -g "left join" /var/lib/mysql/68926f356828-slow.log # Use these commands in combination with | and more, because if the log is large, you may swipe the screen mysqldumpslow -s r -t 10 /var/lib/mysql/68926f356828-slow.log | more
2 Show Profile
Show Profile is provided by mysql, which can be used to analyze the resource consumption of statement execution in the current session, and can be used for SQL tuning measurement. By default, the parameters are turned off and the results of the last 15 runs are saved.
2.1 enable Show Profile
To check whether Show Profile is enabled, use the following command:
SHOW VARIABLES LIKE 'profiling%';
Open Show Profile:
SET profiling = ON;
2.2 using Show Profile
Here are some SQL statements to try:
# Common sql select * from tbl_emp; select * from tbl_emp e inner join tbl_dept d on e.deptId = d.id; select * from tbl_emp e left join tbl_dept d on e.deptId = d.id; # Slow sql select * from emp group by id%10 limit 150000; select * from emp group by id%10 limit 150000; select * from emp group by id%20 order by 5;
View results:
mysql> SHOW PROFILES; +----------+------------+----------------------------------------------------------------------+ | Query_ID | Duration | Query | +----------+------------+----------------------------------------------------------------------+ | 1 | 0.00052700 | show variables like 'profiling%' | | 2 | 0.00030300 | select * from tbl_emp | | 3 | 0.00010650 | select * from tbl_emp e inner join tbl_dept d on e.'deptId' = d.'id' | | 4 | 0.00031625 | select * from tbl_emp e inner join tbl_dept d on e.deptId = d.id | | 5 | 0.00042100 | select * from tbl_emp e left join tbl_dept d on e.deptId = d.id | | 6 | 0.38621875 | select * from emp group by id%20 limit 150000 | | 7 | 0.00014900 | select * from emp group by id%20 order by 150000 | | 8 | 0.38649000 | select * from emp group by id%20 order by 5 | | 9 | 0.06782700 | select COUNT(*) from emp | | 10 | 0.35434400 | select * from emp group by id%10 limit 150000 | +----------+------------+----------------------------------------------------------------------+
2.3 diagnostic SQL
View the specific process of SQL statement execution and the time spent in each step:
SHOW PROFILE cpu,block io FOR QUERY SQL number; # Query parameter explanation: # ALL: displays ALL overhead information # BLOCK IO: displays the BLOCK IO related overhead # CONTEXT SWITCHES: context switching related overhead # CPU: displays CPU related overhead information # IPC: displays the cost information related to sending and receiving # MEMORY: displays MEMORY related overhead information # PAGE FAULTS: displays overhead information related to page errors # SOURCE: display and Source_function，Source_file，Source_line related overhead information # Swap: displays information about the cost associated with the number of exchanges
Example:
mysql> SHOW PROFILE cpu,block io FOR QUERY 2; +----------------------+----------+----------+------------+--------------+---------------+ | Status | Duration | CPU_user | CPU_system | Block_ops_in | Block_ops_out | +----------------------+----------+----------+------------+--------------+---------------+ | starting | 0.000055 | 0.000000 | 0.000000 | 0 | 0 | | checking permissions | 0.000007 | 0.000000 | 0.000000 | 0 | 0 | | Opening tables | 0.000011 | 0.000000 | 0.000000 | 0 | 0 | | init | 0.000024 | 0.000000 | 0.000000 | 0 | 0 | | System lock | 0.000046 | 0.000000 | 0.000000 | 0 | 0 | | optimizing | 0.000018 | 0.000000 | 0.000000 | 0 | 0 | | statistics | 0.000008 | 0.000000 | 0.000000 | 0 | 0 | | preparing | 0.000019 | 0.000000 | 0.000000 | 0 | 0 | | executing | 0.000003 | 0.000000 | 0.000000 | 0 | 0 | | Sending data | 0.000089 | 0.000000 | 0.000000 | 0 | 0 | | end | 0.000004 | 0.000000 | 0.000000 | 0 | 0 | | query end | 0.000003 | 0.000000 | 0.000000 | 0 | 0 | | closing tables | 0.000005 | 0.000000 | 0.000000 | 0 | 0 | | freeing items | 0.000006 | 0.000000 | 0.000000 | 0 | 0 | | cleaning up | 0.000006 | 0.000000 | 0.000000 | 0 | 0 | +----------------------+----------+----------+------------+--------------+---------------+
If you use Navicat software, you can also view these data in the analysis.
If the status status appears in the following ways, you need to be vigilant:
- converting HEAP to MyISAM: the query result is too large and there is not enough memory. It is moved to disk.
- Creating tmp table: create a temporary table. mysql copies the data to the temporary table first, and then deletes the temporary table after it is used up
- Copying to tmp table on disk: copy temporary tables in memory to disk
- Locked: locked table
3 SQL optimization ideas
Coordinate with slow query log and Show Profile to sort out the optimization ideas of SQL. When the whole sql server slows down, you can analyze it as follows:
-
Enable slow query and capture slow sql
-
Use explain to analyze the sql in the slow query log
-
Use show profile to query the execution details and life cycle of sql in mysql server
-
Optimize the parameters of sql database server