MySQL General query log and slow query log analysis

Logs in MySQL include: error log, binary log, General query log, slow query log, and so on. Here is the main introduction of the more commonly used two features: General query log and slow query log.

1) General query log: Records established client connections and executed statements.
2) Slow query log: Log all queries that have been executed for more than long_query_time seconds or queries that do not use an index

(1) General query log

When learning a generic log query, you need to know the common commands in two databases:

1) Show variables like '%version% ';

mysql> show variables like ‘%version%‘;
+-------------------------+------------------------------+
| Variable_name           | Value                        |
+-------------------------+------------------------------+
| innodb_version          | 5.6.37                       |
| protocol_version        | 10                           |
| slave_type_conversions  |                              |
| version                 | 5.6.37-log                   |
| version_comment         | MySQL Community Server (GPL) |
| version_compile_machine | x86_64                       |
| version_compile_os      | Linux                        |
+-------------------------+------------------------------+
7 rows in set (0.00 sec)

The above command shows what is related to the version number in the current database.

1) Show variables like '%general% ';

mysql> show variables like ‘% general%’;
+ ------------------ + ------------------------------ -+
| Variable_name | Value |
+ ------------------ + ------------------------------ -+
| general_log | OFF |
| general_log_file | /var/lib/mysql/nginx-test.log |
+ ------------------ + ------------------------------ -+
2 rows in set (0.00 sec)
You can check whether the current general log query is turned on. If the value of general_log is ON, it is turned on, and it is turned off.

  1) show variables like ‘% log_output%’;

mysql> show variables like ‘% log_output%’;
+ --------------- + ------- +
| Variable_name | Value |
+ --------------- + ------- +
| log_output | FILE |
+ --------------- + ------- +
1 row in set (0.00 sec)

View the format of the current slow query log output, either file (Hostname.log stored in a data file in the database) or table (Mysql.general_log stored in the database)
Question: How do I turn on the MySQL universal query log, and how do I set the common log output format to output?

Enable general log query: set global general_log = on;

Turn off general log query: set global general_log = off;

Set the general log output to table mode: set global log_output = ’TABLE’;

Set the general log output to a file mode: set global log_output = ’FILE’;

Set general log output to table and file mode: set global log_output = ’FILE, TABLE’;

(Note: The above command is only valid for the current, when the MySQL restart fails, if you want to permanently take effect, you need to configure MY.CNF)
The log output is as follows:
The records to the Mysql.general_log table structure are as follows:

mysql> desc general_log;
+--------------+---------------------+------+-----+-------------------+-----------------------------+
| Field        | Type                | Null | Key | Default           | Extra                       |
+--------------+---------------------+------+-----+-------------------+-----------------------------+
| event_time   | timestamp           | NO   |     | CURRENT_TIMESTAMP | on update CURRENT_TIMESTAMP |
| user_host    | mediumtext          | NO   |     | NULL              |                             |
| thread_id    | bigint(21) unsigned | NO   |     | NULL              |                             |
| server_id    | int(10) unsigned    | NO   |     | NULL              |                             |
| command_type | varchar(64)         | NO   |     | NULL              |                             |
| argument     | mediumtext          | NO   |     | NULL              |                             |
+--------------+---------------------+------+-----+-------------------+-----------------------------+
6 rows in set (0.00 sec)

The configuration of the My.cnf file is as follows:

general_log = 1 # 1 means enable general log query, 0 means disable general log query

log_output = FILE, TABLE # Set the output format of the general log to files and tables

(2) Slow query log

MySQL's slow query log is a log record provided by MySQL, used to record in MySQL response time exceeding the threshold of the statement, specifically, the run time exceeds the Long_query_time value of SQL, will be recorded in the Slow query log (log can be written to a file or database table, If the performance requirements are high, it is recommended to write the file). By default, the MySQL database does not turn on the slow query log, the default value of Long_query_time is 10 (that is, 10 seconds, usually set to 1 seconds), that is, the statement running more than 10 seconds is a slow query statement.
In general, slow queries occur in large tables (for example, a table has millions of of the data), and the fields of the query criteria are not indexed, at this point, the field to match the query criteria for a full table scan, time-consuming check long_query_time,
is a slow query statement.
Question: How do I see how the current slow query log is turned on?
In MySQL, enter the command:
Show variables like '%quer% ';

mysql> show variables like ‘%quer%‘;
+----------------------------------------+-------------------------------+
| Variable_name                          | Value                         |
+----------------------------------------+-------------------------------+
| binlog_rows_query_log_events           | OFF                           |
| ft_query_expansion_limit               | 20                            |
| have_query_cache                       | YES                           |
| log_queries_not_using_indexes          | ON                            |
| log_throttle_queries_not_using_indexes | 0                             |
| long_query_time                        | 10.000000                     |
| query_alloc_block_size                 | 8192                          |
| query_cache_limit                      | 1048576                       |
| query_cache_min_res_unit               | 4096                          |
| query_cache_size                       | 1048576                       |
| query_cache_type                       | OFF                           |
| query_cache_wlock_invalidate           | OFF                           |
| query_prealloc_size                    | 8192                          |
| slow_query_log                         | ON                            |
| slow_query_log_file                    | /var/log/mysql/mysql_slow.log |
+----------------------------------------+-------------------------------+
15 rows in set (0.00 sec)

Master the following several parameters:
(1) The value of Slow_query_log is on to open the slow query log, off is to turn off the slow query log.
(2) The value of Slow_query_log_file is a slow query log to the file (note: The default name is hostname. Log, the slow query log is written to the specified file, you need to specify the output log format of the slow query as a file, the related command is: show variables like ' %log_output% '; To see the format of the output).
(3) Long_query_time Specifies the threshold for a slow query, which is a slow query statement if the time to execute the statement exceeds the threshold, and the default value is 10 seconds.
(4) Log_queries_not_using_indexes If the value is set to ON, all queries that do not utilize the index are logged (note: If you just set log_queries_not_using_indexes to ON, Slow_ Query_log is set to OFF, this setting also does not take effect, that is, the setting takes effect if the value of Slow_query_log is set to ON), which is normally turned on temporarily when performance is tuned.
Question: Does the output log format for MySQL slow query be a file or a table, or both?
By command: Show variables like '%log_output% ';

mysql> show variables like ‘%log_output%‘;
+---------------+------------+
| Variable_name | Value      |
+---------------+------------+
| log_output    | FILE,TABLE |
+---------------+------------+
1 row in set (0.00 sec)

The value of Log_output can be viewed in the format of the output, the value of which is file,table. Of course, we can also set the output format as text, or simultaneously record both the text and the database table, setting the command as follows:

#Slow query log output to the table (ie mysql.slow_log)

set globallog_output = ’TABLE’;

#Slow query log is only output to the text (ie: file specified by slow_query_log_file)

setglobal log_output = ’FILE’;

#Slow query log output to both text and table

setglobal log_output = ’FILE, TABLE’;

Data format analysis for data in a table with a slow query log:
The log records for slow queries are in the Myql.slow_log table, in the following format:

mysql> mysql> select * from mysql.slow_log limit 1;
+---------------------+--------------------------------+------------+-----------+-----------+---------------+------------+----------------+-----------+-----------+----------------------------------------------------------------------------------------+-----------+
| start_time          | user_host                      | query_time | lock_time | rows_sent | rows_examined | db         | last_insert_id | insert_id | server_id | sql_text                                                                               | thread_id |
+---------------------+--------------------------------+------------+-----------+-----------+---------------+------------+----------------+-----------+-----------+----------------------------------------------------------------------------------------+-----------+
| 2018-02-07 11:16:55 | root[root] @  [121.196.203.51] | 00:00:00   | 00:00:00  |        13 |            40 | jp_core_db |              0 |         0 |         0 | select pd.lastAuction from Product pd where pd.status = ‘O‘ and pd.auctionStatus = ‘A‘ |      1621 |
+---------------------+--------------------------------+------------+-----------+-----------+---------------+------------+----------------+-----------+-----------+----------------------------------------------------------------------------------------+-----------+
1 row in set (0.00 sec)

Slow query logging to the Mysql_slow.log file, in the following format:

# Time: 180118 14:58:37
# [email protected]: root[root] @ localhost []  Id:   150
# Query_time: 0.000270  Lock_time: 0.000109 Rows_sent: 0  Rows_examined: 6
SET timestamp=1516258717;
delete from user where User=‘app‘;

As you can see, whether it is a table or a file, it is specifically recorded: That statement causes slow query (Sql_text), the query time (query_time) of the slow query statement, the lock table time (Lock_time), and the number of scanned rows (rows_examined) and other information.
Question: How do I query the number of statements for the current slow query?
There is a variable in MySQL that specifically records the number of current slow query statements:
Input command: Show global status like '%slow% ';

mysql> show global status like ‘%slow%‘;
+---------------------+-------+
| Variable_name       | Value |
+---------------------+-------+
| Slow_launch_threads | 132   |
| Slow_queries        | 1772  |
+---------------------+-------+
2 rows in set (0.00 sec)

(Note: All of the above commands, if the parameters are set through the MySQL shell, if you restart MySQL, all the set parameters will be invalidated, if you want to take effect permanently, you need to write the configuration parameters in the My.cnf file).
Supplemental knowledge Points: How do I use the Slow query log analysis tool from MySQL to Mysqldumpslow analysis logs?

Mysqldumpslow–s c–t Slow-query.log

The specific parameters are set as follows:
-S means the sort by how, C, T, L, R are in accordance with the number of records, time, query time, the number of records returned to sort, AC, at, AL, AR, indicating the corresponding flashbacks;
-T is the meaning of top, followed by the data to return the first number of bars;
-G can write regular expression matching, case insensitive.

[[email protected] /var/log/mysql]# mysqldumpslow -s c -t 2 /var/log/mysql/mysql_slow.log 

Reading mysql slow query log from /var/log/mysql/mysql_slow.log
Count: 125448  Time=0.00s (131s)  Lock=0.00s (3s)  Rows=2.2 (272835), [email protected]
  select productauc0_.productAuctionId as productA1_12_, productauc0_.auctionIndex as auctionI2_12_, productauc0_.bidCoins as bidCoins3_12_, productauc0_.bidPrice as bidPrice4_12_, productauc0_.bidStep as bidStep5_12_, productauc0_.bidTime as bidTime6_12_, productauc0_.bidder as bidder7_12_, productauc0_.buyFlag as buyFlag8_12_, productauc0_.categoryCode as category9_12_, productauc0_.createTime as createT10_12_, productauc0_.currentAuctionDetailId as current11_12_, productauc0_.currentBidPrice as current12_12_, productauc0_.currentBidTime as current13_12_, productauc0_.currentBidder as current14_12_, productauc0_.effectCoin as effectC15_12_, productauc0_.effetcPoint as effetcP16_12_, productauc0_.endTime as endTime17_12_, productauc0_.newUserFlag as newUser18_12_, productauc0_.productCode as product19_12_, productauc0_.productCost as product20_12_, productauc0_.productName as product21_12_, productauc0_.productPrice as product22_12_, productauc0_.refundRate as refundR23_12_, productauc0_.startPrice as startPr24_12_, productauc0_.startTime as startTi25_12_, productauc0_.status as status26_12_, productauc0_.updateTime as updateT27_12_ from ProductAuction productauc0_ where productauc0_.status=‘S‘

Count: 66216  Time=0.00s (127s)  Lock=0.00s (2s)  Rows=1.7 (115074), root[root]@[121.196.203.51]
  select productauc0_.productAuctionId as productA1_12_, productauc0_.auctionIndex as auctionI2_12_, productauc0_.bidCoins as bidCoins3_12_, productauc0_.bidPrice as bidPrice4_12_, productauc0_.bidStep as bidStep5_12_, productauc0_.bidTime as bidTime6_12_, productauc0_.bidder as bidder7_12_, productauc0_.buyFlag as buyFlag8_12_, productauc0_.categoryCode as category9_12_, productauc0_.createTime as createT10_12_, productauc0_.currentAuctionDetailId as current11_12_, productauc0_.currentBidPrice as current12_12_, productauc0_.currentBidTime as current13_12_, productauc0_.currentBidder as current14_12_, productauc0_.effectCoin as effectC15_12_, productauc0_.effetcPoint as effetcP16_12_, productauc0_.endTime as endTime17_12_, productauc0_.firstBidTime as firstBi18_12_, productauc0_.newUserFlag as newUser19_12_, productauc0_.noviceReturnFlag as noviceR20_12_, productauc0_.productCode as product21_12_, productauc0_.productCost as product22_12_, productauc0_.productName as product23_12_, productauc0_.productPrice as product24_12_, productauc0_.refundRate as refundR25_12_, productauc0_.startPrice as startPr26_12_, productauc0_.startTime as startTi27_12_, productauc0_.status as status28_12_, productauc0_.updateTime as updateT29_12_ from ProductAuction productauc0_ where productauc0_.status=‘S‘

The parameters in the above have the following meanings:

Count: 125448 The statement appears 125448 times;

Time = 0.00s (131s) The maximum execution time is 0.00s, and the total accumulated time is 131s;

Lock = 0.0s (3s) The longest waiting time for a lock is 0s, and the accumulated waiting time for a lock is 3s;

Rows = 2.2 (272835) The maximum number of rows sent to the client is 2.2, and the cumulative function sent to the client is 272835 

http://blog.csdn.net/a600423444/article/details/6854289
(Note: The Mysqldumpslow script is written in Perl, the use of specific mysqldumpslow later)
Question: In the course of learning, how to know the slow query is valid?
Very simply, we can manually generate a slow query statement, for example, if our slow query Log_query_time value is set to 1, then we can execute the following statement:
Select Sleep (1);
The statement is a slow query and can then be used to see if there is a statement in the corresponding log output file or table.

MySQL General query log and slow query log analysis