mysql二进制日志
知识点
1.binlog 日志组成分析
2.binlog日志复制的几种复制模式
3.now()和sysdate()在语义化复制要注意的点
binary log日志简介
查看日志格式
show variables like 'binlog_format';
+---------------+-----------+ | Variable_name | Value | +---------------+-----------+ | binlog_format | STATEMENT | +---------------+-----------+
二进制日志的内容结构
二进制日志的内容由以下三部分组成
(1) 文件头 ：格式描述事件
(2)文件主体:二进制日志事件
(3)文件尾:日志轮换事件
格式描述事件包含的内容:服务器版本,通用头长度,文件状态信息
binlog事件体：日志文件,位置,事件类型(query,xid,user_var),服务器id,结束位置,详细语句信息
文件尾:事件轮换事件
什么时候轮换?
重启数据库
binlog文件达到最大尺寸
flush logs 操作
异常轮换
奔溃或者非正常关闭(kill杀进程)数据库时,轮换日志表示未正常的关闭(没有轮换记录)
用户数据库奔溃的系统自动修复,或者dba干扰重放
mysql> show binary logs;
+------------------+-----------+ | Log_name | File_size | +------------------+-----------+ | mysql-bin.000001 | 19730 | | mysql-bin.000002 | 765307 | | mysql-bin.000003 | 624 | | mysql-bin.000004 | 327 | | mysql-bin.000005 | 409 | +------------------+-----------+ 5 rows in set (0.00 sec) mysql> show binlog events in 'mysql-bin.000005'; +------------------+-----+-------------+-----------+-------------+--------------------------------------------+ | Log_name | Pos | Event_type | Server_id | End_log_pos | Info | +------------------+-----+-------------+-----------+-------------+--------------------------------------------+ | mysql-bin.000005 | 4 | Format_desc | 250 | 106 | Server ver: 5.1.73-log, Binlog ver: 4 | | mysql-bin.000005 | 106 | Query | 250 | 207 | use `hk`; insert into test values(4,now()) | | mysql-bin.000005 | 207 | Query | 250 | 308 | use `hk`; insert into test values(5,now()) | | mysql-bin.000005 | 308 | Query | 250 | 409 | use `hk`; insert into test values(6,now()) | +------------------+-----+-------------+-----------+-------------+--------------------------------------------+ mysql> flush logs; Query OK, 0 rows affected (0.02 sec) mysql> show binary logs; +------------------+-----------+ | Log_name | File_size | +------------------+-----------+ | mysql-bin.000001 | 19730 | | mysql-bin.000002 | 765307 | | mysql-bin.000003 | 624 | | mysql-bin.000004 | 327 | | mysql-bin.000005 | 452 | | mysql-bin.000006 | 106 | +------------------+-----------+ mysql> show binlog events in 'mysql-bin.000005'; +------------------+-----+-------------+-----------+-------------+--------------------------------------------+ | Log_name | Pos | Event_type | Server_id | End_log_pos | Info | +------------------+-----+-------------+-----------+-------------+--------------------------------------------+ | mysql-bin.000005 | 4 | Format_desc | 250 | 106 | Server ver: 5.1.73-log, Binlog ver: 4 | | mysql-bin.000005 | 106 | Query | 250 | 207 | use `hk`; insert into test values(4,now()) | | mysql-bin.000005 | 207 | Query | 250 | 308 | use `hk`; insert into test values(5,now()) | | mysql-bin.000005 | 308 | Query | 250 | 409 | use `hk`; insert into test values(6,now()) | | mysql-bin.000005 | 409 | Rotate | 250 | 452 | mysql-bin.000006;pos=4 | +------------------+-----+-------------+-----------+-------------+--------------------------------------------+ 5 rows in set (0.00 sec) mysql> show binlog events in 'mysql-bin.000006'; +------------------+-----+-------------+-----------+-------------+---------------------------------------+ | Log_name | Pos | Event_type | Server_id | End_log_pos | Info | +------------------+-----+-------------+-----------+-------------+---------------------------------------+ | mysql-bin.000006 | 4 | Format_desc | 250 | 106 | Server ver: 5.1.73-log, Binlog ver: 4 | +------------------+-----+-------------+-----------+-------------+---------------------------------------+ 1 row in set (0.00 sec) ps -ef|grep mysql mysql 2759 1 0 Feb07 ? 00:00:16 /usr/libexec/mysqld --basedir=/usr --datadir=/var/lib/mysql --user=mysql --log-error=/var/log/mysqld.log --pid-file=/var/run/mysqld/mysqld.pid --socket=/var/lib/mysql/mysql.sock root 5161 4530 0 08:06 pts/0 00:00:00 grep mysql [root@centos1 ~]# kill -9 2759 [root@centos1 ~]# service mysqld status; mysqld 已死，但 pid 文件仍存 [root@centos1 log]# service mysqld start 正在启动 mysqld：
mysql> show binary logs; +------------------+-----------+ | Log_name | File_size | +------------------+-----------+ | mysql-bin.000001 | 19730 | | mysql-bin.000002 | 765307 | | mysql-bin.000003 | 624 | | mysql-bin.000004 | 327 | | mysql-bin.000005 | 452 | | mysql-bin.000006 | 106 | | mysql-bin.000007 | 106 | +------------------+-----------+ 7 rows in set (0.00 sec) mysql> show binlog events in 'mysql-bin.000006'; +------------------+-----+-------------+-----------+-------------+---------------------------------------+ | Log_name | Pos | Event_type | Server_id | End_log_pos | Info | +------------------+-----+-------------+-----------+-------------+---------------------------------------+ | mysql-bin.000006 | 4 | Format_desc | 250 | 106 | Server ver: 5.1.73-log, Binlog ver: 4 | +------------------+-----+-------------+-----------+-------------+---------------------------------------+ 1 row in set (0.00 sec) mysql> show binlog events in 'mysql-bin.000007'; +------------------+-----+-------------+-----------+-------------+---------------------------------------+ | Log_name | Pos | Event_type | Server_id | End_log_pos | Info | +------------------+-----+-------------+-----------+-------------+---------------------------------------+ | mysql-bin.000007 | 4 | Format_desc | 250 | 106 | Server ver: 5.1.73-log, Binlog ver: 4 | +------------------+-----+-------------+-----------+-------------+---------------------------------------+ mysql-bin.000006 没有轮换事件
mysql二进制的复制有3中格式
1.基于语句的复制
配置选项 :binlog_format=STAEMENT
特点:相对落后,把主库的语句放到从库再执行一次,速度较慢,无法保证所有语句都正确复制,但是二进制日志相对较小
2.基于行的复制
配置选项 : binlog_format=row
特点:将主库的改动记为二进制日志的一行,保存的是物理的更新数据,更加方便,速度相对较快,保证所有语句都能正确复制
但二进制日志文件相对较大
3.混合类型
binlog_format=mixed
大多情况下是statement 格式,只有特定情况下是row 格式
在statement下
在slave库
stop slave io_thread; show slave status\G Connect_Retry: 60 Master_Log_File: mysql-bin.000008 Read_Master_Log_Pos: 120 Relay_Log_File: mysqld-relay-bin.000019 Relay_Log_Pos: 283 Relay_Master_Log_File: mysql-bin.000008 Slave_IO_Running: No Slave_SQL_Running: Yes 在主库 mysql> select * from test; +----+---------------------+ | id | time | +----+---------------------+ | 1 | 2017-02-04 10:04:12 | | 2 | 2017-02-04 13:53:35 | | 3 | 2017-02-08 19:46:49 | | 4 | 2017-02-08 20:34:49 | | 5 | 2017-02-09 09:34:42 | | 6 | 2017-02-09 10:08:48 | | 7 | 2017-02-09 10:18:06 | | 8 | 2017-02-09 17:35:10 | +----+---------------------+ mysql> flush logs; Query OK, 0 rows affected (0.05 sec) mysql> show binary logs; +------------------+-----------+ | Log_name | File_size | +------------------+-----------+ | mysql-bin.000001 | 143 | | mysql-bin.000002 | 367 | | mysql-bin.000003 | 120 | | mysql-bin.000004 | 677 | | mysql-bin.000005 | 367 | | mysql-bin.000006 | 619 | | mysql-bin.000007 | 591 | | mysql-bin.000008 | 167 | | mysql-bin.000009 | 120 | +------------------+-----------+ 9 rows in set (0.00 sec) mysql> insert into test values(9,now()); Query OK, 1 row affected (0.00 sec) mysql> insert into test values(10,sysdate()); Query OK, 1 row affected, 1 warning (0.00 sec) mysql> select * from test; +----+---------------------+ | id | time | +----+---------------------+ | 1 | 2017-02-04 10:04:12 | | 2 | 2017-02-04 13:53:35 | | 3 | 2017-02-08 19:46:49 | | 4 | 2017-02-08 20:34:49 | | 5 | 2017-02-09 09:34:42 | | 6 | 2017-02-09 10:08:48 | | 7 | 2017-02-09 10:18:06 | | 8 | 2017-02-09 17:35:10 | | 9 | 2017-02-10 09:21:17 | | 10 | 2017-02-10 09:21:33 |
因为从库的io进程没开
所以没有把主库的二进制日志取到relay log里,slave里自然没有记录
现在slave开启io_thread ;
start slave io_thread;
在slave
mysql> select * from test; +----+---------------------+ | id | time | +----+---------------------+ | 1 | 2017-02-04 10:04:12 | | 2 | 2017-02-04 13:53:35 | | 3 | 2017-02-08 19:46:49 | | 4 | 2017-02-08 20:34:49 | | 5 | 2017-02-09 09:34:42 | | 6 | 2017-02-09 10:09:40 | | 7 | 2017-02-09 10:18:06 | | 8 | 2017-02-09 17:35:10 | +----+---------------------+ 8 rows in set (0.01 sec) mysql> start slave io_thread; Query OK, 0 rows affected (0.01 sec) mysql> select * from test; +----+---------------------+ | id | time | +----+---------------------+ | 1 | 2017-02-04 10:04:12 | | 2 | 2017-02-04 13:53:35 | | 3 | 2017-02-08 19:46:49 | | 4 | 2017-02-08 20:34:49 | | 5 | 2017-02-09 09:34:42 | | 6 | 2017-02-09 10:09:40 | | 7 | 2017-02-09 10:18:06 | | 8 | 2017-02-09 17:35:10 | | 9 | 2017-02-10 09:21:17 | | 10 | 2017-02-10 09:24:45 | +----+---------------------+ 10 rows in set (0.00 sec)
发现只有id为9的记录和主库一样,id为10的记录有延迟,和主库不一致
在master
mysql> show binlog events in 'mysql-bin.000009'; +------------------+-----+-------------+-----------+-------------+-------------------------------------------------+ | Log_name | Pos | Event_type | Server_id | End_log_pos | Info | +------------------+-----+-------------+-----------+-------------+-------------------------------------------------+ | mysql-bin.000009 | 4 | Format_desc | 108 | 120 | Server ver: 5.6.35-log, Binlog ver: 4 | | mysql-bin.000009 | 120 | Query | 108 | 203 | BEGIN | | mysql-bin.000009 | 203 | Query | 108 | 313 | use `hk`; insert into test values(9,now()) | | mysql-bin.000009 | 313 | Xid | 108 | 344 | COMMIT /* xid=24 */ | | mysql-bin.000009 | 344 | Query | 108 | 427 | BEGIN | | mysql-bin.000009 | 427 | Query | 108 | 542 | use `hk`; insert into test values(10,sysdate()) | | mysql-bin.000009 | 542 | Xid | 108 | 573 | COMMIT /* xid=25 */ | +------------------+-----+-------------+-----------+-------------+-------------------------------------------------+
二进制日志里记录了这2次插入
到slave
show slave status\G Master_Log_File: mysql-bin.000009 Read_Master_Log_Pos: 573 Relay_Log_File: mysqld-relay-bin.000022 Relay_Log_Pos: 736 Relay_Master_Log_File: mysql-bin.000009 Slave_IO_Running: Yes Slave_SQL_Running: Yes
现在的Relay_Log_File: mysqld-relay-bin.000022
到slave的mysql外面
[root@bogon ~]# cd /var/lib/mysql [root@bogon mysql]# ll 总用量 110624 -rw-rw----. 1 mysql mysql 56 2月 8 19:44 auto.cnf drwx------. 2 mysql mysql 49 2月 4 10:03 hk -rw-rw----. 1 mysql mysql 12582912 2月 10 09:24 ibdata1 -rw-rw----. 1 mysql mysql 50331648 2月 10 09:24 ib_logfile0 -rw-rw----. 1 mysql mysql 50331648 2月 3 16:53 ib_logfile1 -rw-rw----. 1 mysql mysql 127 2月 10 09:24 master.info drwx------. 2 mysql mysql 4096 2月 3 16:53 mysql -rw-rw----. 1 mysql mysql 221 2月 10 09:24 mysqld-relay-bin.000021 -rw-rw----. 1 mysql mysql 736 2月 10 09:24 mysqld-relay-bin.000022 -rw-rw----. 1 mysql mysql 52 2月 10 09:24 mysqld-relay-bin.index srwxrwxrwx. 1 mysql mysql 0 2月 10 09:07 mysql.sock drwx------. 2 mysql mysql 4096 2月 3 16:53 performance_schema -rw-rw----. 1 mysql mysql 59 2月 10 09:24 relay-log.info
mysqlbinlog mysqld-relay-bin.000022
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/; /*!40019 SET @@session.max_insert_delayed_threads=0*/; /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/; DELIMITER /*!*/; # at 4 #170210 9:24:45 server id 163 end_log_pos 120 CRC32 0xad8f9f6a Start: binlog v 4, server v 5.6.35 created 170210 9:24:45 BINLOG ' XRadWA+jAAAAdAAAAHgAAABAAAQANS42LjM1AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAXAAEGggAAAAICAgCAAAACgoKGRkAAWqf j60= '/*!*/; # at 120 #170210 9:24:45 server id 108 end_log_pos 0 CRC32 0x0d3f1bdd Rotate to mysql-bin.000009 pos: 4 # at 167 #170210 9:20:26 server id 108 end_log_pos 120 CRC32 0x79450af9 Start: binlog v 4, server v 5.6.35-log created 170210 9:20:26 BINLOG ' WhWdWA9sAAAAdAAAAHgAAAAAAAQANS42LjM1LWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAXAAEGggAAAAICAgCAAAACgoKGRkAAfkK RXk= '/*!*/; # at 283 #170210 9:21:17 server id 108 end_log_pos 203 CRC32 0xaceb5c00 Query thread_id=3 exec_time=0 error_code=0 SET TIMESTAMP=1486689677/*!*/; 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=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.time_zone='SYSTEM'/*!*/; SET @@session.lc_time_names=0/*!*/; SET @@session.collation_database=DEFAULT/*!*/; BEGIN /*!*/; # at 366 #170210 9:21:17 server id 108 end_log_pos 313 CRC32 0x03e32c0a Query thread_id=3 exec_time=0 error_code=0 use `hk`/*!*/; SET TIMESTAMP=1486689677/*!*/; insert into test values(9,now()) /*!*/; # at 476 #170210 9:21:17 server id 108 end_log_pos 344 CRC32 0x3a657546 Xid = 24 COMMIT/*!*/; # at 507 #170210 9:21:33 server id 108 end_log_pos 427 CRC32 0x0e4bf105 Query thread_id=3 exec_time=0 error_code=0 SET TIMESTAMP=1486689693/*!*/; BEGIN /*!*/; # at 590 #170210 9:21:33 server id 108 end_log_pos 542 CRC32 0x8b162e58 Query thread_id=3 exec_time=0 error_code=0 SET TIMESTAMP=1486689693/*!*/; insert into test values(10,sysdate()) /*!*/; # at 705 #170210 9:21:33 server id 108 end_log_pos 573 CRC32 0x1d0f5307 Xid = 25 COMMIT/*!*/; DELIMITER ; # End of log file ROLLBACK /* added by mysqlbinlog */; /*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/; /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;
发现
在执行一些时间函数前 先 SET TIMESTAMP操作
now() 受 SET TIMESTAMP='值' 的影响 这个值主从都是一样的
而sysdate();不受 SET TIMESTAMP 操作的影响
所以在statement下 即使io线程即使有延迟 now() 也是准确的
