MySQL丨日志2

前言

MySQL 三个核心日志分别是 binlog 、redo log、undo log，其中 binlog 是 server 层的日志，而 redo log 和 undo log 都是引擎层（innodb）的日志，它们位于磁盘结构上，也就说说如果换其他数据引擎，那么就未必有 redo log 和 undo log 了。

Undo Log 日志

Undo：意为撤销或取消，以撤销操作为目的，返回指定某个状态的操作。
Undo Log：数据库事务开始之前，会将要修改的记录存放到 Undo 日志里，当事务回滚时或数据库崩溃时，可以利用 Undo 日志，撤销未提交事务对数据库产生的影响。
产生与销毁：在事务开始前就产生；但事务提交时，并不是立马就删除 Undo log，InnoDB会将该事务对应的 Undo log 放入到删除列表中，后续会通过后台线程 purge thread 进行回收处理。
存储：Undo log 采用段的方式管理和记录。在 InnoDB 数据文件中包含一种 rollback segment（回滚段），每个回滚段中有 1024 个 Undo log segment。InnoDB 最多支持 128 个回滚段，其中 32 个分配给临时表空间。
Undo log 属于逻辑日志，记录一个变化过程。例如执行一个 delete，那么Undo log会记录一个 insert；执行一个 update，那么记录一个相反的 update。

使用以下命令查看：

show variables like '%innodb_undo%';

查询结果：

作用

实现事务的原子性：Undo Log 是为了实现事务的原子性而出现的产物。事务处理过程中，如果出现了错误或者用户执行了 ROLLBACK 语句，MySQL 可以利用 Undo log 中的备份将数据恢复到事务开启之前的状态。
实现多版本并发控制（MVCC）：Undo log 在 MySQL、InnoDB 存储引擎中用来实现多版本并发控制。事务未提交之前，Undo log 保存了未提交之前的版本数据，Undo log 中的数据可作为数据旧版本快照供其他并发事务进行快照读。

Redo Log 日志

Redo：顾名思义就是重做。以恢复操作为目的，在数据库发生意外时重现操作。
Redo Log：指事务中修改的任何数据，将最新的数据备份存储的位置，被称为重做日志。
生成和释放：随着事务操作的执行，就会生成 Redo Log，在事务提交时会产生 Redo Log 写入 Log BUffer，并不是随着事务的提交就立刻写入磁盘文件。等事务操作的脏页写入到磁盘之后，Redo Log 的使命就完成了，它占用的空间就可以重用（被覆盖写入，并不是删除该文件）。
工作原理：Redo Log 是为了实现事务的持久性而出现的产物。防止在发生故障的时间点，尚有脏页未写入表的 IBD 文件中，在重启 MySQL 服务的时候，根据 Redo Log 进行重做，从而达到事务的未入磁盘数据进行持久化这一特性。

Redo Buffer 存储的是 User 修改后的信息，Undo Buffer 存储的是 User 修改前的信息。

写入机制：Redo Log 文件内容是以顺序循环的方式写入文件，写满时则回溯到第一个文件，进行覆盖写入。

如上图所示：

Write Pos 是当前记录的位置，一边写一边往后移，写到最后一个文件末尾后就回到 0 号文件开头；
CheckPoint 是当前要擦除的位置，也是往后推移并且循环的，擦除记录前要把记录更新到数据文件；

Write Pos 和 CheckPoint 之间还空着的部分，可以用来记录新的操作。如果 Write Pos 追上 CheckPoint，表示已经写满了，这时候就不能再执行信的更新，需要停下来先擦除一些记录，把 CheckPoint 推进一下。
相关配置参数：每个 InnoDB 存储引擎至少有 1 个重做日志文件组(group)，每个文件组至少有 2 个重做日志文件，默认为 ib_logfile0 和 ib_logfile1。可以使用以下参数控制 Redo Log 存储：

show variables like '%innodb_log%';

查询结果：

Redo Buffer 持久化到 Redo Log 的策略，可通过参数 Innodb_flush_log_at_trx_commit 设置，查询结果显示：

mysql> show variables like '%Innodb_flush_log_at_trx_commit%';
+--------------------------------+-------+
| Variable_name                  | Value |
+--------------------------------+-------+
| innodb_flush_log_at_trx_commit | 1     |
+--------------------------------+-------+
1 row in set, 1 warning (0.01 sec)

value 的可选值：

0：每秒提交 Redo Buffer -> OS cache -> flush cache to disk，可能丢失一秒内的事务数据。由后台 Master 线程每隔 1 秒执行一次操作。
1（默认值）：每次事务提交执行 Redo Buffer -> OS cache -> flush cache to disk，最安全，但是也是性能最差的方式。
2：每次事务提交执行 Redo Buffer -> OS cache，然后由后台 Master 线程再每隔 1 秒执行 OS cache -> flush cache to disk 的操作。

一般来说，建议选择取值 2，因为 MySQL 挂了数据没有损失，整个服务器挂了才会损失 1 秒的事务提交数据。

Binlog 日志

Redo Log 是属于 InnoDB 引擎所特有的日志，而 MySQL 也有自己的逻辑日志，并且它由 Server 层进行记录，使用任何存储引擎的 MySQL 数据库都会记录。Binary log（二进制日志），简称 Binlog，这个文件记录了所有数据库表结构变更以及表数据修改的二进制日志，不会记录 select 和 show 此类操作。Binlog 日志是以事件形式记录，还包含语句所执行的消耗时间。
通过 Binlog 日志，我们可以做数据恢复和主从复制等操作。
Binlog 文件名默认为“主机名_binlog-序列号”格式，例如“abc_binlog-001”，也可以在配置文件中指定名称。

记录模式

Binlog 文件记录模式有 STATEMENT、ROW 和 MIXED 三种，具体含义如下。

STATEMENT(statement-based replication, SBR)：每一条被修改数据的 SQL 都会记录到 master 的 Binlog 中，slave 在复制的时候 SQL 进程会解析成和原来 master 端执行过的相同的 SQL 再次执行。简称 SQL 语句复制。
优点：日志量小，减少磁盘 IO，提升存储和恢复速度。缺点：但是在主从复制的情况下，不推荐使用这种模式，因为 SQL 语句中可能存在一些会变化的参数（随机生成的 uuid、当前时间、用户id），主库和从库的数据未必一致，所以存在风险。
ROW(row-based replication, RBR)：日志中会记录每一行数据修改的情况，然后在 slave 端对相同的数据进行修改。
优点：因为会记录每一行的数据的修改细节，可以完全实现主从数据同步和数据的恢复；缺点：虽然可靠，但是日志可能会暴涨，消耗空间巨大。
MIXED(mixed-based replication, MBR)：以上两种模式的混合使用，一般会使用 STATEMENT 模式保存 binlog，对于 STATEMENT 模式无法复制的操作使用 ROW 模式保存，MySQL 会根据执行的 SQL 语句选择写入模式。

文件结构

MySQL 的 Binlog 文件中记录的是对数据库的各种修改操作，用来表示修改操作的数据结构是 Log event。不同的修改操作对应的不同的 log event。比较常用的 log event 有：Query event、Row event、Xid event等。
Binlog 文件的内容就是各种 Log event 的集合。Log event 的结构如下所示：

写入机制

根据记录模式和操作触发 event 事件生成 log event；
将事务执行过程中产生的 log event 写入缓冲区，每一个事务线程都有一个缓冲区；
log event 保存在一个叫 binlog_cache_mngr 的数据结构中，在该数据结构中有两个缓冲区，一个叫 stmt_cache，用于存放不支持事务的信息；另外一个叫 trx_cache，用于存放支持事务的信息。
事务在提交阶段会将产生的 log event 写入到外部的 binlog 文件中。
不同的事务以串行方式将 log event 写入 binlog 文件中，所以一个事务包含的 log event 信息在 binlog 文件中是连续的，中间不会插入其他事务的 log event。binlog 是引擎插件上层的功能，事件提交第一个就会调用 binlog 功能接口，然后再调用其他存储引擎的功能接口。因此，先写 binlog，再执行 Innodb 的 Redo log/ undo log 和脏页刷新操作。

文件操作

binlog 状态查看：

mysql> show variables like '%log_bin%';
+---------------------------------+-------+
| Variable_name                   | Value |
+---------------------------------+-------+
| log_bin                         | OFF   |
| log_bin_basename                |       |
| log_bin_index                   |       |
| log_bin_trust_function_creators | OFF   |
| log_bin_use_v1_row_events       | OFF   |
| sql_log_bin                     | ON    |
+---------------------------------+-------+
6 rows in set, 1 warning (0.01 sec)

可以看到 “log_bin” 是关闭的。

MySQL V5.X 默认是不开启 Binlog 的。需要修改 my.cnf 或者 my.ini 配置文件，在 [mysqld] 标签下面增加 log_bin=mysqlbinlog，再重启 MySQL 服务。可以看到 my.ini 配置文件在 C:\ProgramData\MySQL\MySQL Server 5.7\ 这个路径中。

mysql> select @@datadir;
+---------------------------------------------+
| @@datadir                                   |
+---------------------------------------------+
| C:\ProgramData\MySQL\MySQL Server 5.7\Data\ |
+---------------------------------------------+
1 row in set (0.00 sec)

重启：如果是 mysql8.0 的话, 把 mysql57 改为 mysql80。

C:\WINDOWS\system32>net stop mysql57
MYSQL57 服务正在停止.
MYSQL57 服务已成功停止。

C:\WINDOWS\system32>net start mysql57
MYSQL57 服务正在启动 .
MYSQL57 服务已经启动成功。

再次检查是否开启：

mysql> show variables like '%log_bin%';
+---------------------------------+--------------------------------------------------------------+
| Variable_name                   | Value                                                        |
+---------------------------------+--------------------------------------------------------------+
| log_bin                         | ON                                                           |
| log_bin_basename                | C:\ProgramData\MySQL\MySQL Server 5.7\Data\mysqlbinlog       |
| log_bin_index                   | C:\ProgramData\MySQL\MySQL Server 5.7\Data\mysqlbinlog.index |
| log_bin_trust_function_creators | OFF                                                          |
| log_bin_use_v1_row_events       | OFF                                                          |
| sql_log_bin                     | ON                                                           |
+---------------------------------+--------------------------------------------------------------+
6 rows in set, 1 warning (0.01 sec)

其中，sql_log_bin 处于开启状态，这表示一旦执行数据库恢复数据这类操作，那么恢复数据这个过程也会记录到 binlog 文件中，不仅浪费资源，那么增加了磁盘的容量，还没有必要（特别是利用二进制恢复数据库的时候）所以一般恢复的时候会选择关闭它。

mysql> show binary logs; // 等价于 show master logs;
+--------------------+-----------+
| Log_name           | File_size |
+--------------------+-----------+
| mysqlbinlog.000001 |       154 |
+--------------------+-----------+
1 row in set (0.00 sec)

mysql> show master status;
+--------------------+----------+--------------+------------------+-------------------+
| File               | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set |
+--------------------+----------+--------------+------------------+-------------------+
| mysqlbinlog.000001 |      154 |              |                  |                   |
+--------------------+----------+--------------+------------------+-------------------+
1 row in set (0.00 sec)

mysql> show binlog events;
+--------------------+-----+----------------+-----------+-------------+---------------------------------------+
| Log_name           | Pos | Event_type     | Server_id | End_log_pos | Info                                  |
+--------------------+-----+----------------+-----------+-------------+---------------------------------------+
| mysqlbinlog.000001 |   4 | Format_desc    |         1 |         123 | Server ver: 5.7.34-log, Binlog ver: 4 |
| mysqlbinlog.000001 | 123 | Previous_gtids |         1 |         154 |                                       |
+--------------------+-----+----------------+-----------+-------------+---------------------------------------+
2 rows in set (0.01 sec)

mysql> show binlog events in 'mysqlbinlog.000001';
+--------------------+-----+----------------+-----------+-------------+---------------------------------------+
| Log_name           | Pos | Event_type     | Server_id | End_log_pos | Info                                  |
+--------------------+-----+----------------+-----------+-------------+---------------------------------------+
| mysqlbinlog.000001 |   4 | Format_desc    |         1 |         123 | Server ver: 5.7.34-log, Binlog ver: 4 |
| mysqlbinlog.000001 | 123 | Previous_gtids |         1 |         154 |                                       |
+--------------------+-----+----------------+-----------+-------------+---------------------------------------+
2 rows in set (0.00 sec)

使用 mysqlbinlog 命令可以看到详细信息，例如时间、server id、事件的起始点与终止点等信息。

C:\WINDOWS\system32>cd C:\ProgramData\MySQL\MySQL Server 5.7\Data\

// 语句别加分号，即可显示内容
C:\ProgramData\MySQL\MySQL Server 5.7\Data>mysqlbinlog "mysqlbinlog.000001"
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#210911 20:11:25 server id 1  end_log_pos 123 CRC32 0x380be512  Start: binlog v 4, server v 5.7.34-log created 210911 20:11:25 at startup
# Warning: this binlog is either in use or was not closed properly.
ROLLBACK/*!*/;
BINLOG '
7Zw8YQ8BAAAAdwAAAHsAAAABAAQANS43LjM0LWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAADtnDxhEzgNAAgAEgAEBAQEEgAAXwAEGggAAAAICAgCAAAACgoKKioAEjQA
ARLlCzg=
'/*!*/;
# at 123
#210911 20:11:25 server id 1  end_log_pos 154 CRC32 0xdcc409e3  Previous-GTIDs
# [empty]
SET @@SESSION.GTID_NEXT= 'AUTOMATIC' /* added by mysqlbinlog */ /*!*/;
DELIMITER ;
# End of log file
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;

// 将它转换为一个指定名字的 SQL 文件（结尾别加分号），转换的文件在 C:\ProgramData\MySQL\MySQL Server 5.7\Data\ 下
C:\ProgramData\MySQL\MySQL Server 5.7\Data>mysqlbinlog "mysqlbinlog.000001" > "20210911test.sql"

可以看到，这一个事件的发生时间为 210911 20:11:25，即 2021年09月11日的 20点11分25秒，起始点为 4，终止点为 123 等详细数据。

使用 binlog 恢复数据：

// 按照指定时间恢复
mysqlbinlog --start-datetime="210911 20:11:25" --stop-datetime="210911 20:11:25" mysqlbinlog.000001 | mysql -uroot -p123456

// 按照事件位置号恢复
mysqlbinlog --start-position=4 --stop-position=123 mysqlbinlog.000001 | mysql -uroot -p123456

删除 binlog 文件：

// 指定一个文件名删除文件
purge binary logs to 'mysqlbinlog.0000001';
// 指定删除一个时间节点之前的文件
purge binary logs before '20210911 22:15:07';
// 全部删除
reset master;

还可以设置文件的有效期，过了有效期就自动清理。先查看有效期参数：

mysql> show variables like '%expire_logs_days%';
+------------------+-------+
| Variable_name    | Value |
+------------------+-------+
| expire_logs_days | 0     |
+------------------+-------+
1 row in set, 1 warning (0.00 sec)

可以看到查询结果为 0，这表示还没启用该功能。

恢复数据实践

binlog 日志中记录了用户对数据库更改的所有操作，如 INSERT 语句、UPDATE 语句、CREATE 语句等。如果数据库因为操作不当或其它原因丢失了数据，可以通过二进制日志来查看在一定时间段内用户的操作，结合数据库备份来还原数据库。
先新建一个数据库，数据表，插入一些数据：

mysql> create database sakila;
Query OK, 1 row affected (0.01 sec)

mysql> use sakila;
Database changed

mysql> create table user(id int primary key, name varchar(20)) engine=innodb charset=utf8;
Query OK, 0 rows affected (0.03 sec)

mysql> insert into user values(1, 'tom');
Query OK, 1 row affected (0.01 sec)

mysql> insert into user values(2, 'jake');
Query OK, 1 row affected (0.01 sec)

mysql> select * from user;
+----+------+
| id | name |
+----+------+
|  1 | tom  |
|  2 | jake |
+----+------+
2 rows in set (0.01 sec)

mysql> update user set name='Tom' where id = 1;
Query OK, 1 row affected (0.01 sec)
Rows matched: 1  Changed: 1  Warnings: 0

mysql> select * from user;
+----+------+
| id | name |
+----+------+
|  1 | Tom  |
|  2 | jake |
+----+------+
2 rows in set (0.00 sec)

// 删除数据库
mysql> drop database sakila;
Query OK, 1 row affected (0.01 sec)

mysql> select * from user;
ERROR 1046 (3D000): No database selected

恢复步骤：

// 先查看当前的 binlog 文件
mysql> show master logs;
+--------------------+-----------+
| Log_name           | File_size |
+--------------------+-----------+
| mysqlbinlog.000001 |      1516 |
+--------------------+-----------+
1 row in set (0.00 sec)

// 查看操作事件
mysql> show binlog events in 'mysqlbinlog.000001';
+--------------------+------+----------------+-----------+-------------+--------------------------------------------------------------------------------------------------+
| Log_name           | Pos  | Event_type     | Server_id | End_log_pos | Info                                                                                             |
+--------------------+------+----------------+-----------+-------------+--------------------------------------------------------------------------------------------------+
| mysqlbinlog.000001 |    4 | Format_desc    |         1 |         123 | Server ver: 5.7.34-log, Binlog ver: 4                                                            |
| mysqlbinlog.000001 |  123 | Previous_gtids |         1 |         154 |                                                                                                  |
| mysqlbinlog.000001 |  154 | Anonymous_Gtid |         1 |         219 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS'                                                             |
| mysqlbinlog.000001 |  219 | Query          |         1 |         319 | create database sakila                                                                           |
| mysqlbinlog.000001 |  319 | Anonymous_Gtid |         1 |         384 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS'                                                             |
| mysqlbinlog.000001 |  384 | Query          |         1 |         544 | use `sakila`; create table user(id int primary key, name varchar(20)) engine=innodb charset=utf8 |
| mysqlbinlog.000001 |  544 | Anonymous_Gtid |         1 |         609 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS'                                                             |
| mysqlbinlog.000001 |  609 | Query          |         1 |         683 | BEGIN                                                                                            |
| mysqlbinlog.000001 |  683 | Table_map      |         1 |         735 | table_id: 108 (sakila.user)                                                                      |
| mysqlbinlog.000001 |  735 | Write_rows     |         1 |         779 | table_id: 108 flags: STMT_END_F                                                                  |
| mysqlbinlog.000001 |  779 | Xid            |         1 |         810 | COMMIT /* xid=31 */                                                                              |
| mysqlbinlog.000001 |  810 | Anonymous_Gtid |         1 |         875 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS'                                                             |
| mysqlbinlog.000001 |  875 | Query          |         1 |         949 | BEGIN                                                                                            |
| mysqlbinlog.000001 |  949 | Table_map      |         1 |        1001 | table_id: 108 (sakila.user)                                                                      |
| mysqlbinlog.000001 | 1001 | Write_rows     |         1 |        1046 | table_id: 108 flags: STMT_END_F                                                                  |
| mysqlbinlog.000001 | 1046 | Xid            |         1 |        1077 | COMMIT /* xid=32 */                                                                              |
| mysqlbinlog.000001 | 1077 | Anonymous_Gtid |         1 |        1142 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS'                                                             |
| mysqlbinlog.000001 | 1142 | Query          |         1 |        1216 | BEGIN                                                                                            |
| mysqlbinlog.000001 | 1216 | Table_map      |         1 |        1268 | table_id: 108 (sakila.user)                                                                      |
| mysqlbinlog.000001 | 1268 | Update_rows    |         1 |        1322 | table_id: 108 flags: STMT_END_F                                                                  |
| mysqlbinlog.000001 | 1322 | Xid            |         1 |        1353 | COMMIT /* xid=34 */                                                                              |
| mysqlbinlog.000001 | 1353 | Anonymous_Gtid |         1 |        1418 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS'                                                             |
| mysqlbinlog.000001 | 1418 | Query          |         1 |        1516 | drop database sakila                                                                             |
+--------------------+------+----------------+-----------+-------------+--------------------------------------------------------------------------------------------------+
23 rows in set (0.00 sec)

可以看到起始号为“创建数据库”前的 pos，也就是 154；结束号为“删除数据库”之前的 pos，也就是 1353。那么可以按照事件位置号恢复。
打开 CMD，执行以下操作：

C:\WINDOWS\system32>cd C:\ProgramData\MySQL\MySQL Server 5.7\Data

// 不要在 -p 后面直接写密码，明文不安全
C:\ProgramData\MySQL\MySQL Server 5.7\Data>mysqlbinlog --start-position=154 --stop-position=1353 mysqlbinlog.000001 | mysql -uroot -p
Enter password: ******

C:\ProgramData\MySQL\MySQL Server 5.7\Data>

Redo Log 与 Binlog 的区别

所属层面不同：Redo Log 属于 InnoDB 引擎的功能；而 Binlog 属于 MySQL server层自带的功能（不管什么引擎都能用），并且是以二进制记录的。
记录内容不同：Redo Log 是物理日志，记录该数据页更新状态内容；而 Binlog 是逻辑日志，记录更新过程。
写入方式不同：Redo Log 日志是循环写，日志空间大小是固定的；而 Binlog 是追加写入，不会出现覆盖使用。
用途不同：Redo Log 作为服务器异常宕机后事务数据自动恢复使用；而 Binlog 可以做为主从复制和数据恢复使用，没有自动 crash-safe 能力。

参考

MySQL 5.7 官方文档
 知乎
 脚本之家
 CSDN