mysql log system inventory

MySql log files include error log, slow query log, transaction log, binary log, etc.

Mysql logs can be configured by command

1 show global variables like '%log%'; 

The results of implementation are as follows

"back_log"    "80"
"binlog_cache_size"    "32768"
"binlog_checksum"    "CRC32"
"binlog_direct_non_transactional_updates"    "OFF"
"binlog_error_action"    "ABORT_SERVER"
"binlog_format"    "ROW"
"binlog_group_commit_sync_delay"    "0"
"binlog_group_commit_sync_no_delay_count"    "0"
"binlog_gtid_simple_recovery"    "ON"
"binlog_max_flush_queue_time"    "0"
"binlog_order_commits"    "ON"
"binlog_row_image"    "FULL"
"binlog_rows_query_log_events"    "OFF"
"binlog_stmt_cache_size"    "32768"
"expire_logs_days"    "0"
"general_log"    "OFF"
"general_log_file"    "DESKTOP-VH518HU.log"
"innodb_api_enable_binlog"    "OFF"
"innodb_flush_log_at_timeout"    "1"
"innodb_flush_log_at_trx_commit"    "1"
"innodb_locks_unsafe_for_binlog"    "OFF"
"innodb_log_buffer_size"    "1048576"
"innodb_log_checksums"    "ON"
"innodb_log_compressed_pages"    "ON"
"innodb_log_file_size"    "50331648"
"innodb_log_files_in_group"    "2"
"innodb_log_group_home_dir"    ".\"
"innodb_log_write_ahead_size"    "8192"
"innodb_max_undo_log_size"    "1073741824"
"innodb_online_alter_log_max_size"    "134217728"
"innodb_undo_log_truncate"    "OFF"
"innodb_undo_logs"    "128"
"log_bin"    "OFF"
"log_bin_trust_function_creators"    "OFF"
"log_bin_use_v1_row_events"    "OFF"
"log_builtin_as_identified_by_password"    "OFF"
"log_error"    ".\DESKTOP-VH518HU.err"
"log_error_verbosity"    "3"
"log_output"    "FILE"
"log_queries_not_using_indexes"    "OFF"
"log_slave_updates"    "OFF"
"log_slow_admin_statements"    "OFF"
"log_slow_slave_statements"    "OFF"
"log_statements_unsafe_for_binlog"    "ON"
"log_syslog"    "ON"
"log_throttle_queries_not_using_indexes"    "0"
"log_timestamps"    "UTC"
"log_warnings"    "2"
"max_binlog_cache_size"    "18446744073709547520"
"max_binlog_size"    "1073741824"
"max_binlog_stmt_cache_size"    "18446744073709547520"
"max_relay_log_size"    "0"
"relay_log_basename"    "C:\ProgramData\MySQL\MySQL Server 5.7\Data\DESKTOP-VH518HU-relay-bin"
"relay_log_index"    "C:\ProgramData\MySQL\MySQL Server 5.7\Data\DESKTOP-VH518HU-relay-bin.index"
"relay_log_info_file"    ""
"relay_log_info_repository"    "FILE"
"relay_log_purge"    "ON"
"relay_log_recovery"    "OFF"
"relay_log_space_limit"    "0"
"slow_query_log"    "ON"
"slow_query_log_file"    "DESKTOP-VH518HU-slow.log"
"sql_log_off"    "OFF"
"sync_binlog"    "1"
"sync_relay_log"    "10000"
"sync_relay_log_info"    "10000"

I. Error Log

As in the configuration file of the query above, log_error is the storage location of the configuration error log file, and mysql error log is mandatory to open. Mainly record the details of mysql server every time it starts and closes, as well as all the more serious warning information and error information in the running process. The content format is as follows:

 1 2019-07-28T09:05:15.396749Z 9 [Note] Aborted connection 9 to db: 'unconnected' user: 'root' host: 'localhost' (Got an error reading communication packets)
 2 2019-07-28T10:34:57.643413Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
 3 2019-07-28T10:34:57.646421Z 0 [Warning] 'NO_ZERO_DATE', 'NO_ZERO_IN_DATE' and 'ERROR_FOR_DIVISION_BY_ZERO' sql modes should be used with strict mode. They will be merged with strict mode in a future release.
 4 2019-07-28T10:34:57.660459Z 0 [Note] C:\Program Files\MySQL\MySQL Server 5.7\bin\mysqld.exe (mysqld 5.7.17-log) starting as process 2548 ...
 5 2019-07-28T10:34:57.762731Z 0 [Note] InnoDB: Mutexes and rw_locks use Windows interlocked functions
 6 2019-07-28T10:34:57.764737Z 0 [Note] InnoDB: Uses event mutexes
 7 2019-07-28T10:34:57.774763Z 0 [Note] InnoDB: _mm_lfence() and _mm_sfence() are used for memory barrier
 8 2019-07-28T10:34:57.781781Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.3
 9 2019-07-28T10:34:57.784789Z 0 [Note] InnoDB: Adjusting innodb_buffer_pool_instances from 8 to 1 since innodb_buffer_pool_size is less than 1024 MiB
10 2019-07-28T10:34:57.810859Z 0 [Note] InnoDB: Number of pools: 1
11 2019-07-28T10:34:57.823893Z 0 [Note] InnoDB: Not using CPU crc32 instructions
12 2019-07-28T10:34:57.834922Z 0 [Note] InnoDB: Initializing buffer pool, total size = 8M, instances = 1, chunk size = 8M
13 2019-07-28T10:34:57.840938Z 0 [Note] InnoDB: Completed initialization of buffer pool
14 2019-07-28T10:34:57.902190Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
15 2019-07-28T10:34:57.910212Z 0 [Note] InnoDB: Log scan progressed past the checkpoint lsn 172728817
16 2019-07-28T10:34:57.910212Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 172728826
17 2019-07-28T10:34:57.912216Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 172728826
18 2019-07-28T10:34:57.912216Z 0 [Note] InnoDB: Database was not shutdown normally!
19 2019-07-28T10:34:57.913219Z 0 [Note] InnoDB: Starting crash recovery.
20 2019-07-28T10:34:58.941953Z 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
21 2019-07-28T10:34:58.941953Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
22 2019-07-28T10:34:58.942956Z 0 [Note] InnoDB: Setting file '.\ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
23 2019-07-28T10:34:59.177579Z 0 [Note] InnoDB: File '.\ibtmp1' size is now 12 MB.
24 2019-07-28T10:34:59.181591Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
25 2019-07-28T10:34:59.182593Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
26 2019-07-28T10:34:59.182593Z 0 [Note] InnoDB: Waiting for purge to start
27 2019-07-28T10:34:59.239188Z 0 [Note] InnoDB: 5.7.17 started; log sequence number 172728826
28 2019-07-28T10:34:59.245204Z 0 [Note] InnoDB: Loading buffer pool(s) from C:\ProgramData\MySQL\MySQL Server 5.7\Data\ib_buffer_pool
29 2019-07-28T10:34:59.253225Z 0 [Note] Plugin 'FEDERATED' is disabled.
30 2019-07-28T10:34:59.331405Z 0 [Note] InnoDB: Buffer pool(s) load completed at 190728 18:34:59
31 2019-07-28T10:34:59.331405Z 0 [Warning] Failed to set up SSL because of the following SSL library error: SSL context is not usable without certificate and private key
32 2019-07-28T10:34:59.332409Z 0 [Note] Server hostname (bind-address): '*'; port: 3306
33 2019-07-28T10:34:59.378531Z 0 [Note] IPv6 is available.
34 2019-07-28T10:34:59.378531Z 0 [Note]   - '::' resolves to '::';
35 2019-07-28T10:34:59.379534Z 0 [Note] Server socket created on IP: '::'.
36 2019-07-28T10:34:59.643220Z 0 [Note] Event Scheduler: Loaded 0 events
37 2019-07-28T10:34:59.644222Z 0 [Note] Executing 'SELECT * FROM INFORMATION_SCHEMA.TABLES;' to get a list of tables using the deprecated partition engine. You may use the startup option '--disable-partition-engine-check' to skip this check. 
38 2019-07-28T10:34:59.645225Z 0 [Note] Beginning of list of non-natively partitioned tables
39 2019-07-28T10:34:59.920058Z 0 [Note] End of list of non-natively partitioned tables
40 2019-07-28T10:34:59.921060Z 0 [Note] C:\Program Files\MySQL\MySQL Server 5.7\bin\mysqld.exe: ready for connections.
41 Version: '5.7.17-log'  socket: ''  port: 3306  MySQL Community Server (GPL)

2. Slow Query Log

Slow query logs mainly record sql that takes longer to execute in mysql. The default threshold is 10 seconds, and sql statements that execute more than 10 seconds will be recorded in slow query logs. The configuration of slow query logs can be configured in MySQL configuration files.

slow-query-log=1  // 0 Represents closing; 1 indicates opening
slow_query_log_file="DESKTOP-VH518HU-slow.log" //Storage Location of Slow Query Log Files
long_query_time=10 //Slow query time in seconds. Slow query time is calculated in 10 seconds by default.


Slow query is a series of processes from the beginning of sql statement to the end of statement, including acquiring lock, retrieving data and returning data. If a very simple sql statement needs to acquire a lock during execution, and the lock is occupied by another transaction, it may also be recorded by slow queries.


III. Transaction Log

InnoDB transaction log includes redo log and undo log.

Redo log is a redo log that provides roll-forward operations, usually physical logs, that record physical changes to data pages, rather than changes to one or more rows, to restore the physical data pages submitted.

undo log is a value rollback log that provides rollback operations to roll back records to a version, usually logical logs, based on each row of records

3.1, redo log (redo log)

The redo log consists of three parts:

redo log buffer: innodb's buffer, mysql's InnoDB is running in the user space of the operating system. When a transaction is committed, the redo log is first written to memory, that is, the memory of user space.

os buffer: the buffer of the kernel space, redo log needs to brush the disk into the log file eventually, it needs to save the log to the disk through the kernel space, so it needs to write the redo log buffer of the user space to the os buffer of the kernel space first.

Redo log file: redo log file on disk, which is equivalent to the completion of redo log persistence when it is down

So the persistence steps of redo log are as follows:

First, the redo log buffer in user space is written to os buffer in kernel space, and then the data in kernel space is written to redo log file in disk by fsync method

There are three ways to redo log brush disk. It can be configured by configuring innodb_flush_log_at_trx_commit, which indicates how to refresh log buffer to disk after transaction commit. The default value is 1.

When the value is 0: when a transaction commits, the redo log buffer is not written to os buffer, but to os buffer every second, and fsync () is called to write os buffer to redo log file.

When the value is 1: when a transaction is committed, redo log buffer is written to os buffer, and fsync () is called to write os buffer to redo log file (default configuration, system failure will not lose data, but IO performance is poor).

When the value is 2: When a transaction commits, redo log buffer is written to os buffer, but fsync () is not executed immediately, instead, fsync () is executed once a second to write os buffer to redo log file.

By default, the configuration with a value of 1 is used to ensure that the data will not be lost, while in the other two cases, the performance is similar and much better than that in the case of 1, but in extreme cases, one second of data will be lost, and in high concurrency cases, the amount of data in one second is also very large.


Format of redo log

innodb stores data in pages, so redo logs are also recorded in page-based format. By default, the size of innodb pages is 16K, while redo logs are composed of many redo block s, each of which is 512 bytes. A page can store many log block s.

The log block records changes in data pages in the following format:

redo_log_type: takes 1 byte to represent the log type of redo log

Space: Represents the ID of the table space, which may take up less than 4 bytes when compressed

page_no: Represents the offset of the page, which is also compressed

redo_log_body: The data part of the redo log


3.2, undo log (rollback log)

undo log can provide rollback and multiple line version control (MVCC)

When a transaction commits, it not only needs to keep the redo log, but also records the undo log. If the transaction fails or rolls back, it needs to be rolled back through the undo log.

Undo log records a logical log, such as a delete statement when a transaction is committed, then the corresponding insert statement is recorded in undo log, which is equivalent to the opposite operation of transaction sql.

When the rollback is executed, the corresponding content can be read from the logical record in the undo log and rolled back. Sometimes when applied to line version control, it is also achieved through undo log: when a read row is locked by other transactions, it can analyze the previous data of the row record from the undo log, thus providing the version information of the row, so that users can achieve non-lock consistent reading.

In addition, undo log also generates redo log


4. Binary Log

The bin log log is used to record the update operation of the database (insert, update, delete). It is mainly used for the recovery and master-slave synchronization of mysql database. The master-slave synchronization of mysql is to send the bin log to the slave node through the master node, and the slave node updates the data through the bin log file to achieve data consistency effect.

The configuration of bin log can be queried by the command show variables like'% log_bin%', which is turned off by default.

The format of bin log is mainly controlled by the parameter binlog_format. There are mainly three kinds of statement s, row and mixed.

When the value is state: specific sql statements executed are stored in bin log, such as insert, update, delete, etc., but data inconsistency may occur. For example, when real-time functions such as NOW(), SLEEP() are used in sql statements, the results of each execution will be different.

When the value is row: the bin log stores the latest data of all updated rows, which solves the problem of data inconsistency, but the log file will be larger. For example, in the first scheme, each sql will only produce a log, while in the row mode, an update operation may affect more than one record, resulting in more than one day. Zhi,

If the whole table is updated, the data of the whole table will be recorded in the log. Obviously, this method also has a lot of drawbacks.

When the value is mixed: bin log will use the first or second method according to the specific sql statement, which is equivalent to combining the advantages of the two methods.


Recording time of bin log

The bin log log is written after the transaction commits, or it can be asynchronous. By configuring the sync_binlog parameter, when sync_binlog=n, it means executing n sql statements to write once. If the value is set to 1, it means that every sql transaction commit will be written to disk synchronously.

It's actually written to os buffer, which, like redo log, determines when to brush the disk by configuring innodb_flush_log_at_trx_commit


innodb guarantees data persistence, consistency and atomicity by recording redo log, undo log and bin log, and restores database according to redo log when database restores

Tags: PHP MySQL SQL Database SSL

Posted on Sun, 28 Jul 2019 05:40:09 -0700 by scuzzo84