【MySQL】Logs - Binary Logs

Posted by 西维蜀黍 on 2021-10-26, Last Modified on 2023-03-29

Binary Logs

The binary log contains “events” that describe database changes such as table creation operations or changes to table data. It also contains events for statements that potentially could have made changes (for example, a DELETE which matched no rows), unless row-based logging is used. The binary log also contains information about how long each statement took that updated data.

Purpose

The binary log has two important purposes:

  • For replication, the binary log on a replication source server provides a record of the data changes to be sent to replicas. The source sends the information contained in its binary log to its replicas, which reproduce those transactions to make the same data changes that were made on the source. See Section 17.2, “Replication Implementation”.
  • Certain data recovery operations require use of the binary log. After a backup has been restored, the events in the binary log that were recorded after the backup was made are re-executed. These events bring databases up to date from the point of the backup. See Section 7.5, “Point-in-Time (Incremental) Recovery”.

The binary log is not used for statements such as SELECT or SHOW that do not modify data.

Impacts to Performance

Running a server with binary logging enabled makes performance slightly slower. However, the benefits of the binary log in enabling you to set up replication and for restore operations generally outweigh this minor performance decrement.

The binary log is resilient to unexpected halts. Only complete events or transactions are logged or read back.

Types of binlog

There are two types of binary logging:

  • Statement-based logging: Events contain SQL statements that produce data changes (inserts, updates, deletes)
  • Row-based logging: Events describe changes to individual rows

Mixed logging uses statement-based logging by default but switches to row-based logging automatically as necessary.

Binary Log Structure and Contents

Binlog 包括两类文件:

  • 二进制日志索引文件(.index):记录所有的二进制文件。
  • 二进制日志文件(HOSTNAME-bin.00000*):记录所有 DDL 和 DML 语句事件。

Config

Binlog 日志功能默认是开启的,线上情况下 Binlog 日志的增长速度是很快的,在 MySQL 的配置文件 my.cnf 中提供一些参数来对 Binlog 进行设置。

Copy设置此参数表示启用binlog功能,并制定二进制日志的存储目录
log-bin=/home/mysql/binlog/

#mysql-bin.*日志文件最大字节(单位:字节)
#设置最大100MB
max_binlog_size=104857600

#设置了只保留7天BINLOG(单位:天)
expire_logs_days = 7

#binlog日志只记录指定库的更新
#binlog-do-db=db_name

#binlog日志不记录指定库的更新
#binlog-ignore-db=db_name

#写缓冲多少次,刷一次磁盘,默认0
sync_binlog=0

需要注意的是:

max_binlog_size :Binlog 最大和默认值是 1G,该设置并不能严格控制 Binlog 的大小,尤其是 Binlog 比较靠近最大值而又遇到一个比较大事务时,为了保证事务的完整性不可能做切换日志的动作,只能将该事务的所有 SQL 都记录进当前日志直到事务结束。所以真实文件有时候会大于 max_binlog_size 设定值。 expire_logs_days :Binlog 过期删除不是服务定时执行,是需要借助事件触发才执行,事件包括:

  • 服务器重启

  • 服务器被更新

  • 日志达到了最大日志长度 max_binlog_size

  • 日志被刷新

  • 二进制日志由配置文件的 log-bin 选项负责启用,MySQL 服务器将在数据根目录创建两个新文件mysql-bin.000001mysql-bin.index,若配置选项没有给出文件名,MySQL 将使用主机名称命名这两个文件,其中 .index 文件包含一份全体日志文件的清单。

sync_binlog:这个参数决定了 Binlog 日志的更新频率。默认 0 ,表示该操作由操作系统根据自身负载自行决定多久写一次磁盘。

  • sync_binlog = 1 表示每一条事务提交都会立刻写盘。sync_binlog=n 表示 n 个事务提交才会写盘。
  • 根据 MySQL 文档,写 Binlog 的时机是:SQL transaction 执行完,但任何相关的 Locks 还未释放或事务还未最终 commit 前。这样保证了 Binlog 记录的操作时序与数据库实际的数据变更顺序一致。

Demo - Read Binlog

检查 Binlog 文件是否已开启:

mysql> show variables like '%log_bin%';
+---------------------------------+-----------------------------+
| Variable_name                   | Value                       |
+---------------------------------+-----------------------------+
| log_bin                         | ON                          |
| log_bin_basename                | /var/lib/mysql/binlog       |
| log_bin_index                   | /var/lib/mysql/binlog.index |
| log_bin_trust_function_creators | OFF                         |
| log_bin_use_v1_row_events       | OFF                         |
| sql_log_bin                     | ON                          |
+---------------------------------+-----------------------------+
6 rows in set (0.01 sec)

MySQL 会把用户对所有数据库的内容和结构的修改情况记入 mysql-bin.n 文件,而不会记录 SELECT 和没有实际更新的 UPDATE 语句。

如果你不知道现在有哪些 Binlog 文件,可以使用如下命令:

# 查看binlog列表
mysql> show binary logs; 
+---------------+-----------+-----------+
| Log_name      | File_size | Encrypted |
+---------------+-----------+-----------+
...
| binlog.000215 |       179 | No        |
| binlog.000216 |       156 | No        |
| binlog.000217 |      2263 | No        |
+---------------+-----------+-----------+
34 rows in set (0.01 sec)

# 查看当前 binlog 的状态信息,即正在写入的二进制文件,及当前position
mysql> show master status; 
+---------------+----------+--------------+------------------+-------------------+
| File          | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set |
+---------------+----------+--------------+------------------+-------------------+
| binlog.000217 |     2263 |              |                  |                   |
+---------------+----------+--------------+------------------+-------------------+
1 row in set (0.00 sec)

Binlog 文件是二进制文件,强行打开看到的必然是乱码。

MySQL 提供了命令行的方式来展示 Binlog 日志:

  • mysqlbinlog是mysql官方提供的一个binlog查看工具
  • 也可使用–read-from-remote-server从远程服务器读取二进制日志
  • 还可使用–start-position –stop-position、–start-time= –stop-time精确解析binlog日志

mysqlbinlog

mysqlbinlog Ref

$ mysqlbinlog --base64-output=decode-rows --verbose mysql-bin.000004
...
# at 2791 // 事件的起点
#211031 14:25:15 server id 1  end_log_pos 2878 CRC32 0x40469654 	Query	thread_id=10	exec_time=5	error_code=0
SET TIMESTAMP=1635661515/*!*/;
BEGIN
/*!*/;
# at 2878
#211031 14:25:15 server id 1  end_log_pos 2941 CRC32 0x682a49d0 	Table_map: `sw_test`.`user` mapped to number 90
# at 2941
#211031 14:25:15 server id 1  end_log_pos 3015 CRC32 0xb2ae016f 	Update_rows: table id 90 flags: STMT_END_F
### UPDATE `sw_test`.`user`
### WHERE
###   @1=2
###   @2='bb'
###   @3=10
###   @4='sdsd'
### SET
###   @1=2
###   @2='bb'
###   @3=30
###   @4='sdsd'
# at 3015
...

show binlog events

看起来凌乱其实也有迹可循。Binlog 通过事件的方式来管理日志信息,可以通过 show binlog events in 的语法来查看当前 Binlog 文件对应的详细事件信息。

mysql> show binlog events in "binlog.000217";
+---------------+------+----------------+-----------+-------------+--------------------------------------+
| Log_name      | Pos  | Event_type     | Server_id | End_log_pos | Info                                 |
+---------------+------+----------------+-----------+-------------+--------------------------------------+
| binlog.000217 |    4 | Format_desc    |         1 |         125 | Server ver: 8.0.26, Binlog ver: 4    |
| binlog.000217 |  125 | Previous_gtids |         1 |         156 |                                      |
| binlog.000217 |  156 | Anonymous_Gtid |         1 |         235 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' |
| binlog.000217 |  235 | Query          |         1 |         329 | BEGIN                                |
| binlog.000217 |  329 | Table_map      |         1 |         410 | table_id: 94 (entry_task2_db.users)  |
| binlog.000217 |  410 | Update_rows    |         1 |         714 | table_id: 94 flags: STMT_END_F       |
| binlog.000217 |  714 | Xid            |         1 |         745 | COMMIT /* xid=34 */                  |
| binlog.000217 |  745 | Anonymous_Gtid |         1 |         824 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' |
| binlog.000217 |  824 | Query          |         1 |         918 | BEGIN                                |
| binlog.000217 |  918 | Table_map      |         1 |         999 | table_id: 94 (entry_task2_db.users)  |
| binlog.000217 |  999 | Update_rows    |         1 |        1300 | table_id: 94 flags: STMT_END_F       |
| binlog.000217 | 1300 | Xid            |         1 |        1331 | COMMIT /* xid=37 */                  |
| binlog.000217 | 1331 | Anonymous_Gtid |         1 |        1410 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' |
| binlog.000217 | 1410 | Query          |         1 |        1504 | BEGIN                                |
| binlog.000217 | 1504 | Table_map      |         1 |        1585 | table_id: 94 (entry_task2_db.users)  |
| binlog.000217 | 1585 | Update_rows    |         1 |        1891 | table_id: 94 flags: STMT_END_F       |
| binlog.000217 | 1891 | Xid            |         1 |        1922 | COMMIT /* xid=44 */                  |
| binlog.000217 | 1922 | Anonymous_Gtid |         1 |        2001 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' |
| binlog.000217 | 2001 | Query          |         1 |        2086 | BEGIN                                |
| binlog.000217 | 2086 | Table_map      |         1 |        2167 | table_id: 94 (entry_task2_db.users)  |
| binlog.000217 | 2167 | Write_rows     |         1 |        2232 | table_id: 94 flags: STMT_END_F       |
| binlog.000217 | 2232 | Xid            |         1 |        2263 | COMMIT /* xid=66 */                  |
+---------------+------+----------------+-----------+-------------+--------------------------------------+
22 rows in set (0.00 sec)

这是加入一条数据之后的 Binlog 事件。

我们对 event 查询的数据行关键字段来解释一下:

  • Pos:当前事件的开始位置,每个事件都占用固定的字节大小,结束位置(End_log_position)减去Pos,就是这个事件占用的字节数。
  • 上面的日志中我们能看到,第一个事件位置并不是从 0 开始,而是从 4。MySQL 通过文件中的前 4 个字节,来判断这是不是一个 Binlog 文件。这种方式很常见,很多格式的文件,如 pdf、doc、jpg等,都会通常前几个特定字符判断是否是合法文件。
  • Event_type:表示事件的类型
  • Server_id:表示产生这个事件的 MySQL server_id,通过设置 my.cnf 中的 server-id 选项进行配置
  • End_log_position:下一个事件的开始位置
  • Info:包含事件的具体信息

Binlog Modes

查询当前 Binlog 日志使用格式:

mysql> show global variables like '%binlog_format%';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| binlog_format | ROW   |
+---------------+-------+
1 row in set (0.00 sec)

MySQL binlog 有三种模式:

  1. Statement
  2. Row
  3. Mixed

Statement 模式(Statement-based Binary Logging)

保存每一条修改数据的SQL。

该模式只保存一条普通的SQL语句,不涉及到执行的上下文信息。

因为每台 MySQL 数据库的本地环境可能不一样,那么对于依赖到本地环境的函数或者上下文处理的逻辑 SQL 去处理的时候可能同样的语句在不同的机器上执行出来的效果不一致。

比如像 sleep()函数,last_insert_id()函数,等等,这些都跟特定时间的本地环境有关。

Row 模式(Row-Based Binary Logging)

MySQL V5.1.5 版本开始支持Row模式的 Binlog,它与 Statement 模式的区别在于它不保存具体的 SQL 语句,而是记录具体被修改的信息。

比如一条 update 语句更新10条数据,如果是 Statement 模式那就保存一条 SQL 就够,但是 Row 模式会保存每一行分别更新了什么,因而有10条数据。

Row 模式的优缺点就很明显了:

  • 保存每一个更改的详细信息必然会带来存储空间的快速膨胀。即能非常清晰的记录下每行数据的修改细节,不需要记录上下文相关信息,因此不会发生某些特定情况下的procedure、function、及trigger的调用触发无法被正确复制的问题,任何情况都可以被复制,且能加快从库重放日志的效率,保证从库数据的一致性
  • 由于所有的执行的语句在日志中都将以每行记录的修改细节来记录,因此,可能会产生大量的日志内容,干扰内容也较多;比如一条update语句,如修改多条记录,则binlog中每一条修改都会有记录,这样造成binlog日志量会很大,特别是当执行alter table之类的语句的时候,由于表结构修改,每条记录都发生改变,那么该表每一条记录都会记录到日志中,实际等于重建了表。

Mixed 模式

Mixed 模式即以上两种模式的综合体。既然上面两种模式分别走了极简和一丝不苟的极端,那是否可以区分使用场景的情况下将这两种模式综合起来呢?

在 Mixed 模式中,一般的更新语句使用 Statement 模式来保存 Binlog,但是遇到一些函数操作,可能会影响数据准确性的操作则使用 Row 模式来保存。这种方式需要根据每一条具体的 SQL 语句来区分选择哪种模式。

MySQL 从 V5.1.8 开始提供 Mixed 模式,V5.7.7 之前的版本默认是Statement 模式,之后默认使用Row模式, 但是在 8.0 以上版本已经默认使用 Mixed 模式了。

Binlog 事件类型

上面我们说到了 Binlog 日志中的事件,不同的操作会对应着不同的事件类型,且不同的 Binlog 日志模式同一个操作的事件类型也不同,下面我们一起看看常见的事件类型。

Ref

FORMAT_DESCRIPTION_EVENT

FORMAT_DESCRIPTION_EVENT 是 Binlog V4 中为了取代之前版本中的 START_EVENT_V3 事件而引入的。它是 Binlog 文件中的第一个事件,而且,该事件只会在 Binlog 中出现一次。MySQL 根据 FORMAT_DESCRIPTION_EVENT 的定义来解析其它事件。

它通常指定了 MySQL 的版本,Binlog 的版本,该 Binlog 文件的创建时间。

QUERY_EVENT

QUERY_EVENT 类型的事件通常在以下几种情况下使用:

  • 事务开始时,执行的 BEGIN 操作
  • STATEMENT 格式中的 DML 操作
  • ROW 格式中的 DDL 操作

比如上文我们插入一条数据之后的 Binlog 日志:

mysql> show binlog events in 'mysql-bin.000002';
+------------------+-----+----------------+-----------+-------------+-------------------------------------------------------------------------+
| Log_name         | Pos | Event_type     | Server_id | End_log_pos | Info                                                                    |
+------------------+-----+----------------+-----------+-------------+-------------------------------------------------------------------------+
| mysql-bin.000002 |   4 | Format_desc    |         1 |         125 | Server ver: 8.0.21, Binlog ver: 4                                       |
| mysql-bin.000002 | 125 | Previous_gtids |         1 |         156 |                                                                         |
| mysql-bin.000002 | 156 | Anonymous_Gtid |         1 |         235 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS'                                    |
| mysql-bin.000002 | 235 | Query          |         1 |         323 | BEGIN                                                                   |
| mysql-bin.000002 | 323 | Intvar         |         1 |         355 | INSERT_ID=13                                                            |
| mysql-bin.000002 | 355 | Query          |         1 |         494 | use `test_db`; INSERT INTO `test_db`.`test_db`(`name`) VALUES ('xdfdf') |
| mysql-bin.000002 | 494 | Xid            |         1 |         525 | COMMIT /* xid=192 */                                                    |
+------------------+-----+----------------+-----------+-------------+-------------------------------------------------------------------------+
7 rows in set (0.00 sec)

XID_EVENT

在事务提交时,不管是 STATEMENT 还 是ROW 格式的 Binlog,都会在末尾添加一个 XID_EVENT 事件代表事务的结束。该事件记录了该事务的 ID,在 MySQL 进行崩溃恢复时,根据事务在 Binlog 中的提交情况来决定是否提交存储引擎中状态为 prepared 的事务。

ROWS_EVENT

对于 ROW 格式的 Binlog,所有的 DML 语句都是记录在 ROWS_EVENT 中。

ROWS_EVENT分为三种:

  • WRITE_ROWS_EVENT
  • UPDATE_ROWS_EVENT
  • DELETE_ROWS_EVENT

分别对应 insert,update 和 delete 操作。

对于 insert 操作,WRITE_ROWS_EVENT 包含了要插入的数据。

对于 update 操作,UPDATE_ROWS_EVENT 不仅包含了修改后的数据,还包含了修改前的值。

对于 delete 操作,仅仅需要指定删除的主键(在没有主键的情况下,会给定所有列)。

Reference