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 statusG
  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 statusG
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() 也是准确的