MySQL日志系统

mysql> create table T(ID int primary key, c int);
mysql> insert into T values(1,1);
mysql> insert into T values(2,2);
mysql> insert into T values(3,3);
mysql> update T set c=c+1 where ID=2;

redo log：重做日志
binlog：归档日志
# redo log和binlog的区别
（1）redo log是InnoDB引擎特有的；binlog是MySQL的Server层实现的，所有引擎都可以使用的。
（2）redo log是物理日志，记录的是"在某个数据页上做了什么修改"；binlog是逻辑日志，记录的是这个语句的原始逻辑，如果"给ID=2这一行的c字段加上1"。
（3）redo log是循环写的，空间固定会用完；binlog是可以追加写的。

# binlog的写入机制
事务执行过程中，先把日志写到binlog cache，事务提交的时候，再把binlog cache写到binlog文件中。
系统给binlog cache分配了一片内存，每个线程一个，参数binlog_cache_size用于控制单个线程内binlog cache所占内存的大小。
每个线程有自己的binlog cache，但是共用同一份binlog文件。
binlog写盘状态分为两步：
（1）write，把日志写入到文件系统的page cache，并没有把数据持久化到磁盘，所以速度比较快。
（2）fsync，将数据持久化到磁盘的操作。一般情况下，我们认为fsync才占磁盘的IOPS。
write和fsync的时机是由参数sync_binlog控制的：
（1）sync_binlog为0，表示每次提交事务都只write，不fsync；
（2）sync_binlog为1，表示每次提交事务都会执行fsync；
（3）sync_binlog为N（N>1），表示每次提交事务都只write，但累积N个事务后才fsync；
在出现IO瓶颈的场景里，将sync_binlog设置成一个比较大的值，可以提升性能。（比较常见的是将其设置为100~1000中的某个值）
风险是：如果主机发生异常重启，会丢失最近N个事务的binlog日志。

# redo log的写入机制

begin;
insert into t1 ...
insert into t2 ...
commit;

redo log buffer就是一块内存，用来先存redo日志的。也就是说，在执行第一个insert的时候，数据的内存被修改了，redo log buffer也写入了日志。但是，真正把日志写到redo log文件(文件名是ib_logfile+数字)，是在commit的时候做的。
单独执行一个更新语句的时候，InnoDB会自己启动一个事务，在语句执行完成的时候提交。过程跟上面是一样的，只不过是"压缩"到了一个语句里面完成。
Q：redo log buffer里面的内容，是不是每次生成后都要直接持久化？
不需要，如果事务执行期间MySQL发送异常重启，那这部分日志就丢失了。由于事务并没有提交，所以这时日志丢了也不会有损失。
Q：事务还没提交的时候，redo log buffer中的部分日子有没有可能被持久化到磁盘？
确实会有

redo log可能存在的三种状态：
（1）存在redo log buffer中，物理上是在MySQL进程内存中。
（2）写到磁盘(write)，但是没有持久化(fsync)，物理上是文件系统的page cache里面。
（3）持久化到磁盘，对应的是hard disk。

日志写到redo log buffer是很快的，write到page cache也差不多，但是持久化到磁盘的速度就慢多了。
为了控制redo log的写入策略，InnoDB提供了innodb_flush_log_at_trx_commit参数：
（1）设置为0，表示每次事务提交时都只是把redo log留在redo log buffer中；
（2）设置为1，表示每次事务提交时都将redo log直接持久化到磁盘；
（3）设置为2，表示每次事务提交时都只是把redo log写到page cache。

InnoDB有一个后台线程，每个1秒就会把redo log buffer中的日志，调用write写到文件系统的page cache，然后调用fsync持久化到磁盘。注意，事务执行过程中的redo log也是直接写在redo log buffer中的，这些redo log也会被后台线程一起持久化到磁盘。
也就是说，一个没有提交的事务的redo log也是可能已经持久化到磁盘的。
下面两种场景也会让一个没有提交的事务的redo log写入到磁盘：
（1）redo log buffer占用的空间即将到达innodb_log_buffer_size一半的时候，后台线程会主动写盘。只write，不fsync。
（2）并行的事务提交的时候，顺带将这个事务的redo log buffer持久化到磁盘。

# 组提交机制
WAL：Write-Ahead Logging，它的关键点就是先写日志，再写磁盘。
MySQL的"双1"配置，指的就是sync_binlog和innodb_flush_log_at_trx_commit都设置成1，也就是说，一个事务完整提交前，需要等待两次刷盘，一次是redo log(prepare阶段)，一次是binlog。
如果是"双1"配置，每个事务就有两次刷盘，MySQL通过组提交机制来减少磁盘IOPS。

日志逻辑序列号(log sequence number, LSN)的概念，LSN是单调递增的，用来对应redo log的一个个写入点。
每次写入长度为length的redo log，LSN的值就会加上length。
binlog_group_commit_sync_delay参数：表示延迟多少微秒后才调用fsync。
binlog_group_commit_sync_no_delay_count参数：表示累积多少次以后才调用fsync。
这两个条件是或的关系，也就是说只要有一个满足条件就会调用fsync。

WAL机制是减少磁盘写，主要得益于两方面：
（1）redo log和binlog都是顺序写，磁盘的顺序写比随机写速度要快；
（2）组提交机制，可以大幅降低磁盘的IOPS消耗。

# binlog的三种格式对比statement、row、mixed
1、statement格式

mysql> delete from t where a>=4 and t_modified<='2018-11-10' limit 1;
Query OK, 1 row affected, 1 warning (0.11 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，这个命令可能是不安全的。
delete带limit可能会出现主备数据不一致的情况。原因是：
（1）如果delete语句使用的是索引a，那么会根据索引a找到第一个满足条件的行，也就是说删除的是a=4这一行。
（2）如果使用的是索引t_modified，那么删除的就是t_modified='2018-11-09'，也就是a=5这一行。
由于statement格式下，记录到binlog里的是语句原文，因此可能会出现这样一种情况：在主库执行这条SQL语句的时候，用的是索引a；而在备库执行这条SQL语句的时候，却使用了索引t_modified。因此MySQL认为这样写是有风险的。

mysql> show binlog events in 'mysql-bin.000003';
+------------------+------+----------------+-----------+-------------+-----------------------------------------------------------------------------+
| Log_name         | Pos  | Event_type     | Server_id | End_log_pos | Info                                                                        |
+------------------+------+----------------+-----------+-------------+-----------------------------------------------------------------------------+                                                       |
| mysql-bin.000003 | 2293 | Anonymous_Gtid |         1 |        2358 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS'                                        |
| mysql-bin.000003 | 2358 | Query          |         1 |        2445 | BEGIN                                                                       |
| mysql-bin.000003 | 2445 | Query          |         1 |        2590 | use `test`; delete from t   where a>=4 and t_modified<='2018-11-10' limit 1 |
| mysql-bin.000003 | 2590 | Xid            |         1 |        2621 | COMMIT /* xid=46 */                                                         |
+------------------+------+----------------+-----------+-------------+-----------------------------------------------------------------------------+

第一行SET @@SESSION.GTID_NEXT= 'ANONYMOUS' ，主备切换时使用
第二行BEGIN，和第四行的COMMIT对应，表示中间是一个事务
第三行是真实执行的语句。use `test`; 是MySQL根据当前要操作的表所在的数据库自行添加的，
这样保证日志传到备库去执行时，不论当前的工作线程在哪个库，都能够正确地更新到test库的表t。
第四行COMMIT，xid是binlog和redo log都用的字段，用来把两者关联起来。

2、row格式

mysql> delete from t where a>=4 and t_modified<='2018-11-10';
Query OK, 2 rows affected (0.11 sec)

mysql> show binlog events in 'mysql-bin.000003';
+------------------+------+----------------+-----------+-------------+-----------------------------------------------------------------------------+
| Log_name         | Pos  | Event_type     | Server_id | End_log_pos | Info                                                                        |
+------------------+------+----------------+-----------+-------------+-----------------------------------------------------------------------------+
| mysql-bin.000003 | 3491 | Anonymous_Gtid |         1 |        3556 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS'                                        |
| mysql-bin.000003 | 3556 | Query          |         1 |        3636 | BEGIN                                                                       |
| mysql-bin.000003 | 3636 | Table_map      |         1 |        3683 | table_id: 108 (test.t)                                                      |
| mysql-bin.000003 | 3683 | Delete_rows    |         1 |        3731 | table_id: 108 flags: STMT_END_F                                             |
| mysql-bin.000003 | 3731 | Xid            |         1 |        3762 | COMMIT /* xid=66 */                                                         |
+------------------+------+----------------+-----------+-------------+-----------------------------------------------------------------------------+

Table_map event，用于说明接下来要操作的表是test库的t表
Delete_rows event，用于定义删除的行为

// -vv参数是为了把内容都解析出来
root@ubuntu:/# mysqlbinlog -vv ./var/lib/mysql/mysql-bin.000003 --start-position=3491;

BEGIN
/*!*/;
# at 3636
#190505 18:07:51 server id 1  end_log_pos 3683 CRC32 0x4e1e308d 	Table_map: `test`.`t` mapped to number 108
# at 3683
#190505 18:07:51 server id 1  end_log_pos 3731 CRC32 0x415ff6e1 	Delete_rows: table id 108 flags: STMT_END_F

BINLOG '
97XOXBMBAAAALwAAAGMOAAAAAGwAAAAAAAEABHRlc3QAAXQAAwMDEQEAAo0wHk4=
97XOXCABAAAAMAAAAJMOAAAAAGwAAAAAAAEAAgAD//gEAAAABAAAAFvlrwDh9l9B
'/*!*/;
### DELETE FROM `test`.`t`
### WHERE
###   @1=4 /* INT meta=0 nullable=0 is_null=0 */
###   @2=4 /* INT meta=0 nullable=1 is_null=0 */
###   @3=1541779200 /* TIMESTAMP(0) meta=0 nullable=0 is_null=0 */
# at 3731
#190505 18:07:51 server id 1  end_log_pos 3762 CRC32 0x8914cf26 	Xid = 66
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的这个库上执行的。
CRC32，每个event都有CRC32的值
@1=4 @2=4 记录了真实删除的主键id。
Xid event，用于表示事务被正确地提交了
row格式时，binlog里面记录了真实删除行的主键id，这样binlog传到备库去的时候，就肯定会删除id=4的行，不会有主备删除不同行的问题。

3、mixed格式
有些statement格式的binlog可能会导致主备不一致，所以要使用row格式，但row格式的缺点是很占空间。
所以，MySQL取了个折中方案mixed格式，MySQL会判断这条SQL语句是否可能引起主备不一致，如果有可能，就要row格式，否则就要statement格式。使用row格式还有一个直接的好处：恢复数据。

4、如何使用binlog保持数据一致

mysql> insert into t values(10,10, now());

如果binlog格式设置为mixed，MySQL会把它记录为statement。如果binlog过来1分钟才传给备库的话，主备数据会不一致吗？
通过mysqlbinlog查看发现，binlog在记录event的时候，多记了一条命令：SET TIMESTAMP=1557056183
它用 SET TIMESTAMP 命令约定了接下来的now()函数的返回时间。

root@ubuntu:/# mysqlbinlog -vv ./var/lib/mysql/mysql-bin.000003 --start-position=4925;
BEGIN
/*!*/;
# at 5077
#190505 19:36:23 server id 1  end_log_pos 5193 CRC32 0x2d698d88 	Query	thread_id=7	exec_time=0	error_code=0
use `test`/*!*/;
SET TIMESTAMP=1557056183/*!*/;
insert into t values(10,10, now())
/*!*/;
# at 5193
#190505 19:36:23 server id 1  end_log_pos 5224 CRC32 0x0444e570 	Xid = 96
COMMIT/*!*/;

Q：MySQL怎么知道binlog是完整的？
statement格式的binlog，最后会有COMMIT
row格式的binlog，最后会有XID event（例如最后一行为 Xid = 96）
此外可以通过binlog-checksum参数，用来验证binlog内容的正确性。

Q：redo log和binlog是怎么关联起来的？
它们有一个共同的数据字段XID，崩溃恢复的时候，会按顺序扫描redo log
如果碰到既有prepare，又有commit的redo log，就直接提交；
如果碰到只有prepare，而没有commit的redo log，就拿着XID去binlog找对应的事务。

Q：如果MySQL出现了性能瓶颈，而且瓶颈在IO上，可以通过哪些方法来提升性能呢？
考虑下面三种方法：
（1）设置binlog_group_commit_sync_delay和binlog_group_commit_sync_no_delay_count参数，减少binlog的写盘次数。
这种方法是基于"额外的故意等待"来实现的，因此可能会增加语句的响应时间，但没有丢失数据的风险。
（2）将sync_binlog设置大于1的值（比较常见是100~1000），这样做的风险是主机掉电时会丢binlog日志。
（3）将innodb_flush_log_at_trx_commit设置为2，这样做的风险是主机掉电的时候会丢数据。MySQL异常重启时不会丢失数据。

Q：什么时候会把线上生产库设置成"非双1"？
（1）业务高峰期，一般如果有预知的高峰期，DBA会有预案，把主库设置成"非双1"
（2）备库延迟，为了让备库尽快赶上主库
（3）用备份恢复主库的副本，应用binlog的过程，跟上一种场景类似
（4）批量导入数据的时候。
一般"非双1"配置，设置innodb_flush_log_at_trx_commit=2，sync_binlog=1000。