binlog_error_action测试
场景一:磁盘空间满,导致binlog无法写入
准备测试环境:
主机 | 数据库实例 | 角色 | Sip | Binlog_format |
10.186.24.105 | Test1 | Master | 10.186.24.224 | Row |
10.186.24.106 | Test2 | Slave | 10.186.24.223 | Row |
刷盘环境
准备溢出盘:
挂载test1的binlog目录到/disk_test_bea
当binlog_error_action=ignore_error时:
当前binlog所处盘状态:
从sip利用sysbench写入数据
一直卡在这里不动,此时的磁盘占用如下:
无法再写入数据,SQL被阻塞:
主从未发生不一致现象。umount后可正常插入数据
:
结论
磁盘空间满与binlog_error_action两者关联度不高。
场景二:发生抢盘操作
环境准备测试环境:
主机 | 数据库实例 | 角色 | Sip | 共享存储设备号 |
192.168.59.138 | Test1 | Master | 192.168.59.111 | Sdc |
192.168.59.139 | Test2 | Slave | 192.168.59.112 | Sdc |
刷盘环境
测试时的相关资源:
共享存储在138上的设备号:
[root@node2 ianhol]# ll /dev/disk/by-path/
total 0
lrwxrwxrwx. 1 root root 9 Jun 3 10:46 ip-192.168.59.139:3260-iscsi-iqn.2016-04.dev.iscsi-target:iscsidisk2-lun-1-> ../../sdc
共享存储在139上的设备号:
[root@node3 ianhol]# ll /dev/disk/by-path/
total 0
lrwxrwxrwx. 1 root root 9 Jun 3 10:46 ip-192.168.59.139:3260-iscsi-iqn.2016-04.dev.iscsi-target:iscsidisk2-lun-1-> ../../sdc
139上的抢占测试脚本:
[root@machine2 ~]# cat test.sh #!/bin/bash
PHASE=test exit_on_error(){ echo $PHASE: $1; exit 1; } umount /dev/sdc sg_persist -o -n -C -K 0x1 -d /dev/sdc sg_persist -n -o -I -S 0x1 -d /dev/sdc sg_persist -n -o -P -T 5 -K 0x1 -S 0x2 -d /dev/sdc mount /dev/sdc /mnt/test
echo '-----------------------------------------' sg_persist -n -i -k -d /dev/sdc sg_persist -n -i -r -d /dev/sdc
echo '-----------------------------------------' for i in {1..10} do mysql -h192.168.59.111 -uianhol -pyoung -P13306 test -e "insert into test values($i)"; if [ $? != 0 ] then exit_on_error ERROR fi echo "sleep $i - 1s"; sleep 1 done |
138重新抢占的脚本:
[root@machine1 ~]# cat test.sh #!/bin/bash
umount /dev/sdc sg_persist -o -n -C -K 0x1 -d /dev/sdc sg_persist -n -o -I -S 0x1 -d /dev/sdc echo '-----------------' sleep 1 sg_persist -n -o -P -T 5 -K 0x1 -S 0x2 -d /dev/sdc sleep 1 echo '-----------------' sg_persist -n -i -k -d /dev/sdc sg_persist -n -i -r -d /dev/sdc echo '-----------------' mount /dev/sdc /usr/local/mysql/binlog |
在138注册sdc
[root@node2 data]# sg_persist -n -o -I -S0x1 -d /dev/sdc
在138预留sdd
[root@node2 data]# sg_persist -n -o -R -T 5-K 0x1 -d /dev/sdc
查看注册预留状态:
[root@node2 data]# sg_persist -n -i -k -d/dev/sdc
PRgeneration=0x1, 1 registered reservation key follows:
0x1
[root@node2 data]# sg_persist -n -i -r -d/dev/sdc
PRgeneration=0x1, Reservation follows:
Key=0x1
scope:LU_SCOPE, type: Write Exclusive,registrants only
在139上查看注册预留状态:
[root@node3 ~]# sg_persist -n -i -k -d/dev/sdc
PRgeneration=0x1, 1 registered reservation key follows:
0x1
[root@node3 ~]# sg_persist -n -i -r -d/dev/sdc
PRgeneration=0x1, Reservation follows:
Key=0x1
scope:LU_SCOPE, type: Write Exclusive,registrants only
查看binlog目录挂载状态:
[root@node2 ianhol]# df -h
Filesystem Size Used Avail Use% Mounted on
/dev/sda2 18G 4.1G 13G 25% /
tmpfs 931M 84K 931M 1% /dev/shm
/dev/sda1 291M 40M 237M 15% /boot
/dev/sdc 20G 172M 19G 1% /usr/local/mysql/binlog
查看主从状态:
当binlog_error_action=ignore_error时
139运行抢占脚本:
打印信息如下
抢盘成功
139端操作:
138端操作:
尝试再次插入数据:可成功插入数据
再次返回139端操作:发现数据没有同步
此时的binlog为只读:
kill掉MySQL进程并重新抢回共享存储:
启动MySQL,发现master在binlog文件只读时插入的数据已落盘,binlog文件不包含这些数据。并且binlog损坏。
观察从机复制情况,报如下错误:
删除掉多余的脏数据,删除旧binlog重启MySQL,从机清空binlog与relaylog,重新搭建主从。
结论
验证表明:在binlog_error_action的模式为IGNORE_ERROR的情况下,二进制变成只读时,后续数据能在忽略二进制日志的情况下继续正常的数据提交。并且主从伪健康。
当binlog_error_action=abort server时
其余参数不变,主从复制正常。并且test.test数据为空:
执行抢占脚本:
抢占成功,master报错binlog损坏并退出。查看slave数据:
仅插入一条数据。查看binlog:
# at390
#160603 17:03:55 server id 1 end_log_pos 438 CRC32 0x1a72646f GTID [commit=yes]
SET @@SESSION.GTID_NEXT= '31cefd71-2942-11e6-9fe6-000c29e3aa8a:2'/*!*/;
# at 438
#160603 17:03:55 server id 1 end_log_pos 510 CRC32 0xc176d56a Query thread_id=3 exec_time=0 error_code=0
SET TIMESTAMP=1464944635/*!*/;
BEGIN
/*!*/;
# at 510
#160603 17:03:55 server id 1 end_log_pos 557 CRC32 0x6149878a Table_map: `test`.`test` mapped to number 70
# at 557
#160603 17:03:55 server id 1 end_log_pos 597 CRC32 0x44c1c50b Write_rows: table id 70 flags: STMT_END_F
BINLOG '
+0dRVxMBAAAALwAAAC0CAAAAAEYAAAAAAAEABHRlc3QABHRlc3QAAQMAAYqHSWE=
+0dRVx4BAAAAKAAAAFUCAAAAAEYAAAAAAAEAAgAB//4BAAAAC8XBRA==
'/*!*/;
### INSERT INTO`test`.`test`
### SET
### @1=1 /* INT meta=0 nullable=1 is_null=0 */
# at 597
#160603 17:03:55 server id 1 end_log_pos 628 CRC32 0x60ae865d Xid = 22
COMMIT/*!*/;
SET @@SESSION.GTID_NEXT= 'AUTOMATIC' /*added by mysqlbinlog *//*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SETCOMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET@@SESSION.PSEUDO_SLAVE_MODE=0*/;:
?
还有个现象,不知道怎么解释:抢过来的binlog与在主机上的binlog有差别:
抢来的binlog少了一条insert语句。
蓝色为相同部分,黑色为不同部分。
主机binlog:
[root@node2ianhol]# df -h
Filesystem Size Used Avail Use% Mounted on
/dev/sda2 18G 4.0G 13G 24% /
tmpfs 931M 72K 931M 1% /dev/shm
/dev/sda1 291M 40M 237M 15% /boot
/dev/sdc 20G 172M 19G 1% /usr/local/mysql/binlog
[root@node2ianhol]# mysqlbinlog -vv /usr/local/mysql/binlog/mysql-bin.000002
# at 199
#160603 16:58:27server id 1 end_log_pos 267 CRC320x749d1053 Query thread_id=1 exec_time=0 error_code=0
SETTIMESTAMP=1464944307/*!*/;
SET@@session.pseudo_thread_id=1/*!*/;
SET@@session.foreign_key_checks=1, @@session.sql_auto_is_null=0,@@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=1075838976/*!*/;
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.lc_time_names=0/*!*/;
SET@@session.collation_database=DEFAULT/*!*/;
BEGIN
/*!*/;
# at 267
#160603 16:58:27server id 1 end_log_pos 314 CRC320x304ca232 Table_map: `test`.`test`mapped to number 70
# at 314
#160603 16:58:27server id 1 end_log_pos 359 CRC320x5a47430d Delete_rows: table id 70flags: STMT_END_F
BINLOG '
s0ZRVxMBAAAALwAAADoBAAAAAEYAAAAAAAEABHRlc3QABHRlc3QAAQMAATKiTDA=
s0ZRVyABAAAALQAAAGcBAAAAAEYAAAAAAAEAAgAB//4BAAAA/gEAAAANQ0da
'/*!*/;
### DELETE FROM`test`.`test`
### WHERE
### @1=1 /* INT meta=0 nullable=1 is_null=0 */
### DELETE FROM`test`.`test`
### WHERE
### @1=1 /* INT meta=0 nullable=1 is_null=0 */
# at 359
#160603 16:58:27server id 1 end_log_pos 390 CRC320xecb49fc7 Xid = 4
COMMIT/*!*/;
# at 390
#160603 17:03:55 server id 1 end_log_pos 438 CRC32 0x1a72646f GTID [commit=yes]
SET @@SESSION.GTID_NEXT='31cefd71-2942-11e6-9fe6-000c29e3aa8a:2'/*!*/;
# at 438
#160603 17:03:55 server id 1 end_log_pos 510 CRC32 0xc176d56a Query thread_id=3 exec_time=0 error_code=0
SET TIMESTAMP=1464944635/*!*/;
BEGIN
/*!*/;
# at 510
#160603 17:03:55 server id 1 end_log_pos 557 CRC32 0x6149878a Table_map: `test`.`test` mapped to number 70
# at 557
#160603 17:03:55 server id 1 end_log_pos 597 CRC32 0x44c1c50b Write_rows: table id 70 flags: STMT_END_F
BINLOG '
+0dRVxMBAAAALwAAAC0CAAAAAEYAAAAAAAEABHRlc3QABHRlc3QAAQMAAYqHSWE=
+0dRVx4BAAAAKAAAAFUCAAAAAEYAAAAAAAEAAgAB//4BAAAAC8XBRA==
'/*!*/;
### INSERT INTO`test`.`test`
### SET
### @1=1 /* INT meta=0 nullable=1 is_null=0 */
# at 597
#160603 17:03:55 server id 1 end_log_pos 628 CRC32 0x60ae865d Xid = 22
COMMIT/*!*/;
SET@@SESSION.GTID_NEXT= 'AUTOMATIC' /* added by mysqlbinlog *//*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added bymysqlbinlog */;
/*!50003 SETCOMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET@@SESSION.PSEUDO_SLAVE_MODE=0*/;
从机抢夺的binlog:
[root@node3ianhol]# df -h
Filesystem Size Used Avail Use% Mounted on
/dev/sda2 18G 4.1G 13G 25% /
tmpfs 491M 84K 491M 1% /dev/shm
/dev/sda1 291M 34M 242M 13% /boot
/dev/sdc 20G 172M 19G 1% /mnt/test
[root@node3ianhol]# mysqlbinlog -v -v /mnt/test/mysql-bin.000002
# at 267
#160603 16:58:27server id 1 end_log_pos 314 CRC320x304ca232 Table_map: `test`.`test`mapped to number 70
# at 314
#160603 16:58:27server id 1 end_log_pos 359 CRC320x5a47430d Delete_rows: table id 70flags: STMT_END_F
BINLOG '
s0ZRVxMBAAAALwAAADoBAAAAAEYAAAAAAAEABHRlc3QABHRlc3QAAQMAATKiTDA=
s0ZRVyABAAAALQAAAGcBAAAAAEYAAAAAAAEAAgAB//4BAAAA/gEAAAANQ0da
'/*!*/;
### DELETE FROM`test`.`test`
### WHERE
### @1=1 /* INT meta=0 nullable=1 is_null=0 */
### DELETE FROM`test`.`test`
### WHERE
### @1=1 /* INT meta=0 nullable=1 is_null=0 */
# at 359
#160603 16:58:27server id 1 end_log_pos 390 CRC32 0xecb49fc7 Xid = 4
COMMIT/*!*/;
SET@@SESSION.GTID_NEXT= 'AUTOMATIC' /* added by mysqlbinlog *//*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added bymysqlbinlog */;
/*!50003 SETCOMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;
结论:
binlog_error_action参数在ABORT_SERVER模式下能触发mysql进程自动关闭,并可以保证数据一致性。