Explore log files in MySQL

preface

Log files record various types of activities that affect the MySQL database. Common log files in the MySQL database include error logs, binary logs, slow query logs, and query logs. Here are their introductions.

The error log

Error log files record the startup, running, and shutdown of MySQL.

mysql> show variables like 'log_error';
+---------------+---------------------+
| Variable_name | Value               |
+---------------+---------------------+
| log_error     | /var/log/mysqld.log |
+---------------+---------------------+
1 row in set (0.03 sec)
Copy the code

You can view the path and file name of the error log file. By default, the error file name is the hostname of the server, that is, hostname.err. /var/log/mysqld.log = /etc/my.cnf

# Recommended in standard MySQL setup
sql_mode=NO_ENGINE_SUBSTITUTION,STRICT_TRANS_TABLES

[mysqld_safe]
log-error=/var/log/mysqld.log
pid-file=/var/run/mysqld/mysqld.pid
Copy the code

When the MySQL database fails to start properly, the first file you must look for is the error log file, which records the error information and helps you find the problem.

Slow Query logs

The slow query log is used to record SQL statements whose response time exceeds the threshold, so we can set a threshold to record all SQL statements whose running time exceeds the threshold to the slow query log file. This threshold can be set with the long_query_time parameter, which defaults to 10 seconds.

Start slowly to query logs

By default, the MySQL database does not start slow query logs. You need to manually set this parameter to ON and start the MySQL database

mysql> show variables like "%slow%";
+---------------------------+-------------------------------------------------+
| Variable_name             | Value                                           |
+---------------------------+-------------------------------------------------+
| log_slow_admin_statements | OFF                                             |
| log_slow_slave_statements | OFF                                             |
| slow_launch_time          | 2                                               |
| slow_query_log            | OFF                                             |
| slow_query_log_file       | /var/lib/mysql/iz2zeaf3cg1099kiidi06mz-slow.log |
+---------------------------+-------------------------------------------------+
5 rows in set (0.00 sec)

mysql> set global slow_query_log='ON';
Query OK, 0 rows affected (0.00 sec)


mysql> show variables like "slow_query_log";
+---------------------------+-------------------------------------------------+
| Variable_name             | Value                                           |
+---------------------------+-------------------------------------------------+                                        |
| slow_query_log            | ON                                              |
| slow_query_log_file       | /var/lib/mysql/iz2zeaf3cg1099kiidi06mz-slow.log |
+---------------------------+-------------------------------------------------+
2   rows in set (0.00 sec)

Copy the code

However, using set global slow_query_log=’ON’ to enable slow query logging is valid only for the current database and will be disabled if the MySQL database is restarted. So to make it permanent, modify the configuration file my.cnf (as well as other system variables) as follows:

[mysqld]
slow_query_log=1
Copy the code

Then restart MySQL to enable slow query logging, and the path of the log file is the path of slow_query_log_file.

Set the threshold

mysql> show variables like 'long_query_time'; + -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- - + -- -- -- -- -- -- -- -- -- -- -- + | Variable_name Value | | + -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- - + -- -- -- -- -- -- -- -- -- -- -- + | long_query_time | 10.000000 | + -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- - + -- -- -- -- -- -- -- -- -- -- - + 1 row in the set (0.00 SEC)Copy the code

The default threshold is 10 seconds, we can change the threshold size, for example (this is still valid for the current database) :

mysql> set global long_query_time=0.05;
Query OK, 0 rows affected (0.00 sec)
Copy the code

When the long_QUERy_time threshold is set, the MySQL database records all SQL statements that take longer than this threshold, but not those that take exactly long_query_time. Instead, set long_query_time to 0 to capture all queries

Parameter log_queries_not_using_indexes

Another parameter associated with slow query logs is log_QUERies_NOT_USing_INDEXES. If you run an SQL statement that does not use an index, the MySQL database will also record this SQL statement to the slow query log file. First make sure log_QUERies_NOT_usING_INDEXES is on;

mysql> show variables like 'log_queries_not_using_indexes';
+-------------------------------+-------+
| Variable_name                 | Value |
+-------------------------------+-------+
| log_queries_not_using_indexes | ON    |
+-------------------------------+-------+
1 row in set (0.12 sec)

Copy the code

For example, query without index:

mysql> explain select * from vote_record_memory where vote_id = 323;
+----+-------------+--------------------+------+---------------+------+---------+------+--------+-------------+
| id | select_type | table              | type | possible_keys | key  | key_len | ref  | rows   | Extra       |
+----+-------------+--------------------+------+---------------+------+---------+------+--------+-------------+
|  1 | SIMPLE      | vote_record_memory | ALL  | NULL          | NULL | NULL    | NULL | 149272 | Using where |
+----+-------------+--------------------+------+---------------+------+---------+------+--------+-------------+
1 row in set (1.56 sec)
Copy the code

You can see that a full table scan is performed; Then go to the log file to see that this SQL has been marked as slow because it does not use an index.

# Time: 180817 11:42:59
# User@Host: root[root] @[117.136.86.151] Id: 2625
# Query_time: 0.016542 Lock_time: 0.000112 Rows_sent: 142 Rows_examined: 149272
SET timestamp=1534477379;
select * from vote_record_memory where vote_id = 323;

Copy the code

Put log records into tables

Starting with MySQL5.1, you can put slow query log records into a table, under the mysql database, named slow_log

| slow_log | CREATE TABLE `slow_log` (
  `start_time` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP,
  `user_host` mediumtext NOT NULL,
  `query_time` time NOT NULL,
  `lock_time` time NOT NULL,
  `rows_sent` int(11) NOT NULL,
  `rows_examined` int(11) NOT NULL,
  `db` varchar(512) NOT NULL,
  `last_insert_id` int(11) NOT NULL,
  `insert_id` int(11) NOT NULL,
  `server_id` int(10) unsigned NOT NULL,
  `sql_text` mediumtext NOT NULL,
  `thread_id` bigint(21) unsigned NOT NULL
) ENGINE=CSV DEFAULT CHARSET=utf8 COMMENT='Slow log' |
Copy the code

The log_output parameter specifies the format of the slow query output, which defaults to file and can be set to table, which will be changed to slow_log above

mysql> show variables like "log_output";
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| log_output    | FILE  |
+---------------+-------+
1 row in set (0.19 sec)
Copy the code

Not only does this have a significant impact on performance, but MySQL 5.1 already supports microsecond information when logging slow queries to files. However, logging slow queries to tables degrades the time granularity to the second level. Slow query logs at the second level don’t make much sense

Slowly query the log analysis tool

Mysqldumpslow command

As more and more SQL queries are logged to slow query log files, it is not easy to view the log files directly. MySQL provides the mysqldumpslow command to solve this problem:

[root@iz2zeaf3cg1099kiidi06mz mysql]# mysqldumpslow iz2zeaf3cg1099kiidi06mz-slow.log Reading mysql slow query log from iz2zeaf3cg1099kiidi06mz-slow.log Count: 1 Time= 602s (60s) Lock=0.00s (0s) Rows=149272.0 (149272), Root [root]@[117.136.86.151] select * from vote_record_memory Count 1 row =0 (0), root[root]@[117.136.86.151] CALL add_vote_memory(N) Count: 0 (0) row =0 (0), root[root]@[117.136.86.151] CALL add_vote_memory(N) Count: 0 (0) 1 Time= 0s (1s) Lock=0 s (0s) Rows=0 (0), Root [root]@[117.136.86.151] INSERT into vote_record SELECT * from vote_record memory Count: 1 Time= 0s (0s) Lock= 0s (0s) Rows=142.0 (140), Root [root]@[117.136.86.151] select * from vote_record_memory where vote_id = NCopy the code

For more information about the mysqlDumpslow command, see mysqlDumpslow’s Argument Explanation and basic usage

Pt – query – digest tools

Pt-query-digest is the most powerful tool to analyze MySQL query logs. It can analyze binlog, Generallog, slowlog, and slowlog. It can also be analyzed using show ProcessList or tcpdump fetching MySQL protocol data, which is more specific and complete than mysqlDumpslow. Here is an example using pt-query-digest:

Pt-query-digest slow.log > slow_report.logCopy the code

The tool query analysis report can be printed, can analyze the results output to a file, the analysis process is to first to parameterized query conditions, and for grouping parameterized queries after statistics, the statistics of each query execution time, number, proportion and so on, can use the results of the analysis to find problem is optimized. For more information about installation and use of PT-Query-Digest, see www.ywnds.com/?p=8179

Query log

The view log records information about all requests to the MySQL database, whether or not they were executed correctly. The default host name is.log

mysql> show variables like "general_log%";
+------------------+--------------------------------------------+
| Variable_name    | Value                                      |
+------------------+--------------------------------------------+
| general_log      | OFF                                        |
| general_log_file | /var/lib/mysql/iz2zeaf3cg1099kiidi06mz.log |
+------------------+--------------------------------------------+
2 rows in set (0.24 sec)   
Copy the code

By default, log query is not enabled. You must enable log query first.

mysql> set global general_log='ON';
Query OK, 0 rows affected (0.05 sec)

mysql> show variables like "general_log%";
+------------------+--------------------------------------------+
| Variable_name    | Value                                      |
+------------------+--------------------------------------------+
| general_log      | ON                                         |
| general_log_file | /var/lib/mysql/iz2zeaf3cg1099kiidi06mz.log |
+------------------+--------------------------------------------+
2 rows in set (0.11 sec)
Copy the code

Binary log

Binary logs record all changes made to the database, except for select and show operations, which do not modify the data itself. If you want to record select and show operations, you have to use query logs, not binary logs.

In addition, binary contains information such as the time and execution time of the database change operation. Binary logs provide the following functions:

• Recovery (recovery): Some data recovery requires binary logs. For example, when a database is fully recovered, binary logs can be usedpoint-in-timeThe recovery of
• Replication: A remote MySQL database (usually slave or standby) can be synchronized with a MySQL database (usually master or primary) in real time by copying and executing binary logs
• Audit: Users can audit binary logs to determine whether database injection attacks occur

Enabling binary Logs

The log-bin[=name] parameter enables binary logging. If name is not specified, the default binary log file name is the host name and the extension is the serial number of the binary log file

[mysqld]
log-bin
Copy the code

mysql> show variables like 'datadir'; +---------------+-----------------+ | Variable_name | Value | +---------------+-----------------+ | datadir | The/var/lib/mysql / | + -- -- -- -- -- -- -- -- -- -- -- -- -- -- - + -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- + 1 row in the set (0.00 SEC)Copy the code

Mysqld-bin.000001 is a binary log file, and mysqld-bin.index is a binary index file. To manage all binlog files, MySQL creates an index file, which records all binlog files used by MySQL in sequence. If you want to customize the name of the index file, you can set the log_bin_index=file parameter.

-rw-rw---- 1 mysql mysql      120 Aug 21 16:42 mysqld-bin.000001
-rw-rw---- 1 mysql mysql       20 Aug 21 16:42 mysqld-bin.index
Copy the code

View the binary log file

For binary log files, unlike error log files and slow query log files, which can be viewed with cat, head, tail, etc., it requires the utility mysqlbinlog provided by MySQL. Such as:

[root@iz2zeaf3cg1099kiidi06mz mysql]# mysqlbinlog mysqld-bin.000001 /*! 50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/; / *! 40019 SET @@session.max_insert_delayed_threads=0*/; / *! 50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/; DELIMITER /*! * /. # at 4 #180821 16:42:53 server id 1 end_log_pos 120 CRC32 0x3e55be40 Start: Binlog V 4, server V 5.6.39-log created 180821 16:42:53 at startup # Warning: this binlog is either in use or was not closed properly. ROLLBACK/*! * /. BINLOG ' jdB7Ww8BAAAAdAAAAHgAAAABAAQANS42LjM5LWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA AAAAAAAAAAAAAAAAAACN0HtbEzgNAAgAEgAEBAQEEgAAXAAEGggAAAAICAgCAAAACgoKGRkAAUC+ VT4= '/*! * /. DELIMITER ; # End of log file ROLLBACK /* added by mysqlbinlog */; / *! 50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/; / *! 50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;Copy the code

Binary log file configuration parameters

The following briefly describes some important configuration parameters of binary log files

max_binlog_size

You can limit the size of a single binlog file with the max_binlog_size parameter (default: 1G)

binlog_cache_size

When a transactional table storage engine (such as InnoDB storage engine) is used, all uncommitted binary logs are recorded to a buffer, and then the committed binary logs are written to the binary log file. The size of the buffer is determined by binlog_cache_size, and the default size is 32K. In addition, binlog_cache_size is session-based, and MySQL automatically allocates a binlog_cache_size cache for each thread that initiates a transaction

mysql> show variables like 'binlog_cache_size';
+-------------------+-------+
| Variable_name     | Value |
+-------------------+-------+
| binlog_cache_size | 32768 |
+-------------------+-------+
1 row in set (0.00 sec)

Copy the code

sync_binlog

By default, binary logs are not synchronized to disk every time they are written. The sync_binlog = [N] parameter indicates how many times the buffer is written to disk. If N is set to 1, that is, sync_binlog = 1 indicates that binary logs are written to disk synchronously, then the write operation does not need to write binary logs to the operating system buffer as described above

binlog_format

The binlog_format parameter is important because it affects the format in which binary logs are recorded. There are three formats:

• Statement: Records logical SQL statements in logs
• Row: Records row changes to a table
• Mixed: In this format, mysql uses the statement format by default to record binary log files. However, in some cases, mysql uses the ROW format.

1) The storage engine of the table is NDB. In this case, DML operations on the table are recorded in ROW format. 2) Use UUID(), USER(), CURRENT_USER(), FOUND_ROW(), ROW_COUNT() and other indeterminate functions. 3) INSERT DELAY statement was used. 4) User-defined functions (UDFs) are used. 5) Temporary tables are used.Copy the code

References & acknowledgements

• www.ywnds.com/?p=12839#co…
• InnoDB Storage Engine (Version 2)
• High performance mysql version 3