binlog 在 MySQL 的各种高可用方案上扮演了重要角色。以下内容可以说是所有 MySQL 高可用方案的基础。在这之上演化出了诸如多节点、半同步、MySQL group replication 等相对复杂的方案。
1.主备的基本原理
- 在状态 1 中,客户端的读写都直接访问节点 A,而节点 B 是 A 的备库,只是将 A 的更新都同步过来,到本地执行。这样可以保持节点 B 和 A 的数据是相同的。
- 需要切换的时候,就切成状态 2。这时候客户端读写访问的都是节点 B,而节点 A 是 B 的备库。
- 在状态 1 中,虽然节点 B 没有被直接访问,但是依然建议你把节点 B(也就是备库)设置成只读(readonly)模式。这样做,有以下几个考虑:
1)有时候一些运营类的查询语句会被放到备库上去查,设置为只读可以防止误操作;
2)防止切换逻辑有 bug,比如切换过程中出现双写,造成主备不一致;
3)可以用 readonly 状态,来判断节点的角色。
readonly 设置对超级 (super) 权限用户是无效的,而用于同步更新的线程,就拥有超级权限。
一个update 语句在节点 A 执行,然后同步到节点 B 的完整流程图。
备库 B 跟主库 A 之间维持了一个长连接。主库 A 内部有一个线程,专门用于服务备库 B 的这个长连接。一个事务日志同步的完整过程是这样的:
- step1. 在备库 B 上通过 change master 命令,设置主库 A 的 IP、端口、用户名、密码,以及要从哪个位置开始请求 binlog,这个位置包含文件名和日志偏移量。
- step2. 在备库 B 上执行 start slave 命令,这时候备库会启动两个线程,就是图中的 io_thread 和sql_thread。其中 io_thread 负责与主库建立连接。
- step3. 主库 A 校验完用户名、密码后,开始按照备库 B 传过来的位置,从本地读取 binlog,发给B。
- step4. 备库 B 拿到 binlog 后,写到本地文件,称为中转日志(relay log)。
- step5. sql_thread 读取中转日志,解析出日志里的命令,并执行。后来由于多线程复制方案的引入,sql_thread 演化成为了多个线程。
2.binlog 的三种格式对比
- 一种是 statement
- 一种是 row
- 第三种格式叫作 mixed,其实它就是前两种格式的混合
CREATE TABLE `test_24` (
`id` int(11) NOT NULL,
`a` int(11) DEFAULT NULL,
`t_modified` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP,
PRIMARY KEY (`id`),
KEY `a` (`a`),
KEY `t_modified`(`t_modified`)
) ENGINE=InnoDB;
insert into test_24 values(1,1,'2018-11-13');
insert into test_24 values(2,2,'2018-11-12');
insert into test_24 values(3,3,'2018-11-11');
insert into test_24 values(4,4,'2018-11-10');
insert into test_24 values(5,5,'2018-11-09');
2.1 statement格式下执行情况
delete from test_24 /*comment*/ where a>=4 and t_modified<='2018-11-10' limit 1;
查看binlog如下(show binlog events):
| mysql-bin.000001 | 479 | Anonymous_Gtid | 1 | 544 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' |
| mysql-bin.000001 | 544 | Query | 1 | 639 | BEGIN |
| mysql-bin.000001 | 639 | Query | 1 | 797 | use `sqllearn`; delete from test_24 where a>=4 and t_modified<='2018-11-10' limit 1 |
| mysql-bin.000001 | 797 | Xid | 1 | 828 | COMMIT /* xid=71 */
- 第一行 SET @@SESSION.GTID_NEXT='ANONYMOUS’在介绍主备切换的时候再分析;
- 第二行是一个 BEGIN,跟第四行的 commit 对应,表示中间是一个事务;
- 第三行就是真实执行的语句了。可以看到,在真实执行的 delete 命令之前,还有一个use
sqllearn
命令。这条命令不是我们主动执行的,而是 MySQL 根据当前要操作的表所在的数据库,自行添加的。这样做可以保证日志传到备库去执行的时候,不论当前的工作线程在哪个库里,都能够正确地更新到 test 库的表 test_24。
usesqllearn
命令之后的 delete 语句,就是我们输入的 SQL 原文了。可以看到,binlog“忠实”地记录了 SQL 命令。 - 最后一行是一个 COMMIT。你可以看到里面写着 xid=71。
关于xid:
- redo log 和 binlog 是怎么关联起来的?
- 回答:它们有一个共同的数据字段,叫 XID。崩溃恢复的时候,会按顺序扫描 redo log:
1)如果碰到既有 prepare、又有 commit 的 redo log,就直接提交;
2)如果碰到只有 parepare、而没有 commit 的 redo log,就拿着 XID 去 binlog 找对应的事务。
看一下这条 delete 命令的执行效果图:
mysql> delete from test_24 /*comment*/ where a>=4 and t_modified<='2018-11-10' limit 1;
Query OK, 1 row affected, 1 warning (0.01 sec)
mysql> show warnings;
+-------+------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Level | Code | Message |
+-------+------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Note | 1592 | Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. The statement is unsafe because it uses a LIMIT clause. This is unsafe because the set of rows included cannot be predicted. |
+-------+------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
1 row in set (0.00 sec)
可以看到,运行这条 delete 命令产生了一个 warning,原因是当前 binlog 设置的是statement 格式,并且语句中有 limit,所以这个命令可能是 unsafe 的。
为什么这么说呢?这是因为 delete 带 limit,很可能会出现主备数据不一致的情况。比如上面这个例子:
- step1. 如果 delete 语句使用的是索引 a,那么会根据索引 a 找到第一个满足条件的行,也就是说删除的是 a=4 这一行;
- step2. 但如果使用的是索引 t_modified,那么删除的就是 t_modified='2018-11-09’也就是a=5 这一行。
由于 statement 格式下,记录到 binlog 里的是语句原文,因此可能会出现这样一种情况:在主库执行这条 SQL 语句的时候,用的是索引 a;而在备库执行这条 SQL 语句的时候,却使用了索引 t_modified。因此,MySQL 认为这样写是有风险的。
2.2 row格式下执行情况
修改/etc/my.cnf 的binlog_format=row并重启systemctl restart mysqld。
查看是否修改成功:
mysql> show variables like 'binlog%';
+--------------------------------------------+--------------+
| Variable_name | Value |
+--------------------------------------------+--------------+
| 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 |
| binlog_transaction_dependency_history_size | 25000 |
| binlog_transaction_dependency_tracking | COMMIT_ORDER |
+--------------------------------------------+--------------+
执行delete语句:
| mysql-bin.000002 | 724 | Anonymous_Gtid | 1 | 789 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' |
| mysql-bin.000002 | 789 | Query | 1 | 873 | BEGIN |
| mysql-bin.000002 | 873 | Table_map | 1 | 930 | table_id: 124 (sqllearn.test_24) |
| mysql-bin.000002 | 930 | Delete_rows | 1 | 978 | table_id: 124 flags: STMT_END_F |
| mysql-bin.000002 | 978 | Xid | 1 | 1009 | COMMIT /* xid=54 */
与 statement 格式的 binlog 相比,前后的 BEGIN 和 COMMIT 是一样的。但是,row 格式的 binlog 里没有了 SQL 语句的原文,而是替换成了两个 event:Table_map 和Delete_rows。
- 1)Table_map event,用于说明接下来要操作的表是 test 库的表 t;
- 2)Delete_rows event,用于定义删除的行为。
详细信息需要借助 mysqlbinlog 工具,这个事务的 binlog 是从724这个位置开始的,所以可以用 start-position 参数来指定从这个位置的日志开始解析。
log-bin = /var/log/mysql-bin.log
binlog_format=row
expire-logs-days = 14
max-binlog-size = 500M
server-id = 1
mysqlbinlog -vv /var/log/mysql-bin.000002 --start-position=724;
[root@izbp15dzsx0qokz9qdqojkz log]# mysqlbinlog -vv /var/log/mysql-bin.000002 --start-position=724;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#190816 9:05:01 server id 1 end_log_pos 123 CRC32 0x3c06338a Start: binlog v 4, server v 5.7.24-log created 190816 9:05:01 at startup
# Warning: this binlog is either in use or was not closed properly.
ROLLBACK/*!*/;
BINLOG '
PQFWXQ8BAAAAdwAAAHsAAAABAAQANS43LjI0LWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAA9AVZdEzgNAAgAEgAEBAQEEgAAXwAEGggAAAAICAgCAAAACgoKKioAEjQA
AYozBjw=
'/*!*/;
# at 724
#190816 9:09:00 server id 1 end_log_pos 789 CRC32 0x27deacc9 Anonymous_GTID last_committed=2 sequence_number=3 rbr_only=yes
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 789
#190816 9:09:00 server id 1 end_log_pos 873 CRC32 0xf74de073 Query thread_id=2 exec_time=0 error_code=0
SET TIMESTAMP=1565917740/*!*/;
SET @@session.pseudo_thread_id=2/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=1436549152/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8 *//*!*/;
SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=8/*!*/;
SET @@session.time_zone='SYSTEM'/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
BEGIN
/*!*/;
# at 873
#190816 9:09:00 server id 1 end_log_pos 930 CRC32 0x31dd725a Table_map: `sqllearn`.`test_24` mapped to number 124
# at 930
#190816 9:09:00 server id 1 end_log_pos 978 CRC32 0x1fd11aef Delete_rows: table id 124 flags: STMT_END_F
BINLOG '
LAJWXRMBAAAAOQAAAKIDAAAAAHwAAAAAAAEACHNxbGxlYXJuAAd0ZXN0XzI0AAMDAxEBAAJact0x
LAJWXSABAAAAMAAAANIDAAAAAHwAAAAAAAEAAgAD//gFAAAABQAAAFvkXYDvGtEf
'/*!*/;
### DELETE FROM `sqllearn`.`test_24`
### WHERE
### @1=5 /* INT meta=0 nullable=0 is_null=0 */
### @2=5 /* INT meta=0 nullable=1 is_null=0 */
### @3=1541692800 /* TIMESTAMP(0) meta=0 nullable=0 is_null=0 */
# at 978
#190816 9:09:00 server id 1 end_log_pos 1009 CRC32 0x3f9ff1df Xid = 54
COMMIT/*!*/;
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*/;
可以看到以下几个信息:
- server id 1,表示这个事务是在 server_id=1 的这个库上执行的。
- 每个 event 都有 CRC32 的值,这是因为把参数 binlog_checksum 设置成了 CRC32。
- Table_map event 显示了接下来要打开的表,map 到数字 124,与上面显示相同。
现在这条 SQL 语句只操作了一张表,如果要操作多张表呢?每个表都有一个对应的Table_map event、都会 map 到一个单独的数字,用于区分对不同表的操作。 - 在 mysqlbinlog 的命令中,使用了 -vv 参数是为了把内容都解析出来,所以从结果里面可以看到各个字段的值(比如,@1=5、 @2=5 这些值)。
- binlog_row_image 的默认配置是 FULL,因此 Delete_event 里面,包含了删掉的行的所有字段的值。如果把 binlog_row_image 设置为 MINIMAL,则只会记录必要的信息,在这个例子里,就是只会记录 id=5 这个信息。
- 最后的 Xid event,用于表示事务被正确地提交了。
可以看到,当 binlog_format 使用 row 格式的时候,binlog 里面记录了真实删除行的主键id,这样 binlog 传到备库去的时候,就肯定会删除 id=5 的行,不会有主备删除不同行的问题。
3.为什么会有 mixed 格式的 binlog?
- 因为有些 statement 格式的 binlog 可能会导致主备不一致,所以要使用 row 格式。
- 但 row 格式的缺点是,很占空间。比如你用一个 delete 语句删掉 10 万行数据,用statement 的话就是一个 SQL 语句被记录到 binlog 中,占用几十个字节的空间。但如果用row 格式的 binlog,就要把这 10 万条记录都写到 binlog 中。这样做,不仅会占用更大的空间,同时写 binlog 也要耗费 IO 资源,影响执行速度。
- 所以,MySQL 就取了个折中方案,也就是有了 mixed 格式的 binlog。mixed 格式的意思是,MySQL 自己会判断这条 SQL 语句是否可能引起主备不一致,如果有可能,就用 row 格式,否则就用 statement 格式。
mixed 格式可以利用 statment 格式的优点,同时又避免了数据不一致的风险。
因此,如果线上 MySQL 设置的 binlog 格式是 statement 的话,那基本上就可以认为这是一个不合理的设置。至少应该把 binlog 的格式设置为 mixed。
现在越来越多的场景要求把 MySQL 的 binlog 格式设置成 row。这么做的理由有很多,一个可以直接看出来的好处:恢复数据。
- 从上文可以看出,即使执行的是 delete 语句,row 格式的 binlog 也会把被删掉的行的整行信息保存起来。所以,如果在执行完一条 delete 语句以后,发现删错数据了,可以直接把 binlog 中记录的 delete 语句转成 insert,把被错删的数据插入回去就可以恢复了。
- 如果执行错了 insert 语句呢?那就更直接了。row 格式下,insert 语句的 binlog 里会记录所有的字段信息,这些信息可以用来精确定位刚刚被插入的那一行。这时,直接把 insert 语句转成 delete 语句,删除掉这被误插入的一行数据就可以了。
- 如果执行的是 update 语句的话,binlog 里面会记录修改前整行的数据和修改后的整行数据。所以,如果误执行了 update 语句的话,只需要把这个 event 前后的两行信息对调一下,再去数据库里面执行,就能恢复这个更新操作了。
其实,由 delete、insert 或者 update 语句导致的数据操作错误,需要恢复到操作之前状态的情况,也时有发生。MariaDB 的Flashback工具就是基于上面介绍的原理来回滚数据的。
3.1 mixed模式下执行情况
修改binlog_format=mixed,重启mysql。
insert into test_24 values(10,10, now());
mysql> show binlog events in 'mysql-bin.000003';
+------------------+------+----------------+-----------+-------------+--------------------------------------------------------------+
| Log_name | Pos | Event_type | Server_id | End_log_pos | Info |
+------------------+------+----------------+-----------+-------------+--------------------------------------------------------------+
| mysql-bin.000003 | 804 | Anonymous_Gtid | 1 | 869 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' |
| mysql-bin.000003 | 869 | Query | 1 | 964 | BEGIN |
| mysql-bin.000003 | 964 | Query | 1 | 1094 | use `sqllearn`; insert into test_24 values(10,10, now()) |
| mysql-bin.000003 | 1094 | Xid | 1 | 1125 | COMMIT /* xid=57 */
再用 mysqlbinlog 工具来看看:
mysqlbinlog -vv /var/log/mysql-bin.000003 --start-position=804;
[root@izbp15dzsx0qokz9qdqojkz log]# mysqlbinlog -vv /var/log/mysql-bin.000003 --start-position=804;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#190816 9:35:48 server id 1 end_log_pos 123 CRC32 0x15c79aad Start: binlog v 4, server v 5.7.24-log created 190816 9:35:48 at startup
# Warning: this binlog is either in use or was not closed properly.
ROLLBACK/*!*/;
BINLOG '
dAhWXQ8BAAAAdwAAAHsAAAABAAQANS43LjI0LWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAB0CFZdEzgNAAgAEgAEBAQEEgAAXwAEGggAAAAICAgCAAAACgoKKioAEjQA
Aa2axxU=
'/*!*/;
# at 804
#190816 9:39:59 server id 1 end_log_pos 869 CRC32 0x17cb6017 Anonymous_GTID last_committed=2 sequence_number=3 rbr_only=no
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 869
#190816 9:39:59 server id 1 end_log_pos 964 CRC32 0x637d51f3 Query thread_id=3 exec_time=0 error_code=0
SET TIMESTAMP=1565919599/*!*/;
SET @@session.pseudo_thread_id=3/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=1436549152/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8 *//*!*/;
SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=8/*!*/;
SET @@session.time_zone='SYSTEM'/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
BEGIN
/*!*/;
# at 964
#190816 9:39:59 server id 1 end_log_pos 1094 CRC32 0x2501beec Query thread_id=3 exec_time=0 error_code=0
use `sqllearn`/*!*/;
SET TIMESTAMP=1565919599/*!*/;
insert into test_24 values(10,10, now())
/*!*/;
# at 1094
#190816 9:39:59 server id 1 end_log_pos 1125 CRC32 0xd1e8ff2c Xid = 57
COMMIT/*!*/;
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*/;
可以看到,原来 binlog 在记录 event 的时候,多记了一条命令:SET TIMESTAMP=1565919599。它用 SET TIMESTAMP 命令约定了接下来的 now() 函数的返回时间。
因此,不论这个 binlog 是 1 分钟之后被备库执行,还是 3 天后用来恢复这个库的备份,这个insert 语句插入的行,值都是固定的。也就是说,通过这条 SET TIMESTAMP 命令,MySQL就确保了主备数据的一致性。
如下方式重放binlog是有风险的:
- 用 mysqlbinlog 解析出日志,然后把里面的 statement 语句直接拷贝出来执行。因为有些语句的执行结果是依赖于上下文命令的,直接执行的结果很可能是错误的。
用 binlog 来恢复数据的标准做法是,用 mysqlbinlog 工具解析出来,然后把解析结果整个发给 MySQL 执行。类似下面的命令:
mysqlbinlog /var/log/mysql-bin.000003 --start-position=2738 --stop-position=2973 | mysql -h127.0.0.1 -P13000 -u$user -p$pwd;
这个命令的意思是,将/var/log/mysql-bin.000003文件里面从第 2738 字节到第 2942 字节中间这段内容解析出来,放到 MySQL 去执行。
4.循环复制问题
binlog 的特性确保了在备库执行相同的 binlog,可以得到与主库相同的状态。实际生产上使用比较多的是双 M 结构:
双 M 结构和 M-S 结构,其实区别只是多了一条线,即:节点A 和 B 之间总是互为主备关系。
双 M 结构还有一个问题需要解决(循环复制问题):
- 业务逻辑在节点 A 上更新了一条语句,然后再把生成的 binlog 发给节点 B,节点 B 执行完这条更新语句后也会生成 binlog。(建议把参数 log_slave_updates 设置为 on,表示备库执行 relay log 后生成 binlog)。
- 那么,如果节点 A 同时是节点 B 的备库,相当于又把节点 B 新生成的 binlog 拿过来执行了一次,然后节点 A 和 B 间,会不断地循环执行这个更新语句,也就是循环复制了。这个要怎么解决呢?
MySQL 在 binlog 中记录了这个命令第一次执行时所在实例的server id。因此,可以用下面的逻辑,来解决两个节点间的循环复制的问题:
- 1)规定两个库的 server id 必须不同,如果相同,则它们之间不能设定为主备关系;
- 2)一个备库接到 binlog 并在重放的过程中,生成与原 binlog 的 server id 相同的新的binlog;
- 3)每个库在收到从自己的主库发过来的日志后,先判断 server id,如果跟自己的相同,表示这个日志是自己生成的,就直接丢弃这个日志。
按照这个逻辑,如果设置了双 M 结构,日志的执行流就会变成这样:
- 1)从节点 A 更新的事务,binlog 里面记的都是 A 的 server id;
- 2)传到节点 B 执行一次以后,节点 B 生成的 binlog 的 server id 也是 A 的 server id;
- 3)再传回给节点 A,A 判断到这个 server id 与自己的相同,就不会再处理这个日志。所以,死循环在这里就断掉了。
问题
- MySQL 通过判断 server id 的方式,断掉死循环。但是,这个机制其实并不完备,在某些场景下,还是有可能出现死循环。
Ans:
- 1)一种场景是,在一个主库更新事务后,用命令 set global server_id=x 修改了 server_id。等日志再传回来的时候,发现 server_id 跟自己的 server_id 不同,就只能执行了。
-
2)另一种场景是,有三个节点的时候,如图 所示,trx1 是在节点 B 执行的,因此 binlog 上的server_id 就是 B,binlog 传给节点 A,然后 A 和 A’搭建了双 M 结构,就会出现循环复制。
解决方法:
- 1)如果这时候 A 和 A’上没有任何更新,可以把其中一个节点(比如 A)的 server_id 临时改成 B 的 server_id,这样循环复制就会终止。终止循环复制之后,就要再设置回这个节点(比如 A)原来的 server_id 值。
- 2)不过一般出现循环复制的情况,往往线上同时还有更新,这时就不能修改 server_id 了。这种情况下,我们需要先在节点 A 上执行 stop slave 命令,先停止同步;然后手动执行change master 命令,指向 A’最后一个 binlog 文件的文件末尾,再 start slave 就可以结束循环复制了。
网友评论