日志文件记录了影响MySQL数据库的各种类型活动。MySQL数据库中常见的日志文件有:
这些日志文件可以帮助DBA对MySQL数据库的运行状态进行诊断,从而更好的进行数据库层面的优化。
二进制日志(binary log)记录了对MySQL数据库执行更改的所有操作,但是不包括select和show这类操作,因为该类操作本身对数据没有修改。然而,若操作本身并没有导致数据库发生变化,那么该操作可能也会写入二进制日志,比如update一个数据,即使不影响数据结果,依然会记录到二进制日志中。
如果用户想记录select和show操作,那么只能使用查询日志,而不是二进制日志。此外,二进制日志还包括了执行数据库更改操作的时间等其他额外信息。总的来说,二进制日志主要有以下几种作用。
通过配置参数log-bin [=name]可以启动二进制日志。如果不指定name,则默认二进制日志文件为主机名,后缀名为二进制日志的序列号,所在路径为数据库所在目录(datadir),如:
mysql> show variables like 'datadir';
+---------------+-----------------+
| Variable_name | Value |
+---------------+-----------------+
| datadir | /var/lib/mysql/ |
+---------------+-----------------+
1 row in set (0.00 sec)# 比如mysql-bin.000001为二进制日志文件
# mysql-bin.index为二进制的索引文件,用来存储过往产生的二进制日志序号,在通过情况下,不建议手工修改这个文件。
mysql> system ls -lh /var/lib/mysql
-rw-r----- 1 mysql mysql 50M Jul 8 2022 mysql-bin.000001
-rw-r----- 1 mysql mysql 209 Nov 16 14:53 mysql-bin.index
-rw-r--r-- 1 root root 138K Oct 8 16:50 zxy.sql
.......
二进制日志文件在默认情况下并没有启动,需要手动指定参数来启动。当然,开启二进制日志会影响数据库的性能,但是性能的损失十分有限。根据MySQL官网手册中测试表明,开启二进制日志会使性能下降1%,但考虑到可以使用复制(replaction)和point-in-time的恢复,这些性能的损失是可以接收的。
以下配置文件的参数影响着二进制日志记录的信息和行为:
max_binlog_size
参数max_binlog_size指定单个二进制文件的最大值,如果超过该值,则产生新的二进制文件,后缀名+1,并记录到.index文件。从MySQL 5.0开始的默认值为1 073 741 824,代表1G(在之前版本中max_binlog_size默认为1.1G)。
binlog_cache_size
当使用事物的表存储引擎(如InnoDB引擎)时,所有未提交(uncommitted)的二进制日志会被记录到一个缓存中去,等该事物提交(committed)时直接将缓冲中的二进制日志写入二进制文件,而该缓冲的大小由binlog_cache_size决定,默认大小为32K。
此外,binlog_cache_size是基于会话(session)的,也就是说,当一个线程开始一个事务的时候,MySQL会自动分配一个大小为binlog_cache_size的缓存,因此该值的设置需要相当小心,不能设置过大。当一个事务的记录大于设定的binlog_cache_size时,MySQL会把缓冲中的日志写入一个临时文件中,因此该值又不能设置太小。
通过show global status命令查看binlog_cache_use,binlog_cache_disk_use的状态,可以判断当前binlog_cache_size的设置是否合适。
mysql> show variables like 'binlog_cache_size';
+-------------------+-------+
| Variable_name | Value |
+-------------------+-------+
| binlog_cache_size | 32768 |
+-------------------+-------+
1 row in set (0.00 sec)
binlog_cache_use记录使用缓冲写二进制日志的次数,binlog_cache_disk_use记录使用临时文件写二进制日志的次数。
mysql> show global status like 'binlog_cache%';
+-----------------------+-------+
| Variable_name | Value |
+-----------------------+-------+
| Binlog_cache_disk_use | 71 |
| Binlog_cache_use | 60773 |
+-----------------------+-------+
2 rows in set (0.00 sec)
使用缓冲次数60773次,临时文件使用次数为71次。可以看出binlog_cache_size
为32KB对于当前数据库完全够用,暂时不必增加binlog_cache_size
的值。
sync_binlog
在默认情况下,二进制日志并不是在每次写的时候同步到磁盘(可以理解为缓冲写)。因此,当数据库所在操作系统发送宕机时,可能会有最后一部分数据没有写入二进制日志文件,这会给恢复和复制带来问题。参数sync_binlog=[N]表示每写缓冲多少次就同步到磁盘。如果将N设为1,即sync_binlog=1表示采用同步写磁盘的方式来写二进制日志,这时写操作不使用操作系统的缓冲来写二进制日志。sync_binlog的默认值为0,如果使用InnoDB存储引擎进行复制,并且想得到最大的高可用性,建议将值设置为ON。不过该值为ON时,确实会对数据库的IO系统带来一定的影响。
但是将sync_binlog设为1,还是会有一种情况导致问题的发送。当使用innodb存储引擎时,在一个事务发出commit动作之前,由于sync_binlog为1,因此会将二进制日志立即写入磁盘。如果此时已经写入二进制日志,但是还没提交就发生了宕机,那么MySQL数据库下次启动时,由于commit操作没有发生,这个事务就会被回滚。但二进制日志已经记录了该事务信息,又不能被回滚。这个问题可以通过设置参数innodb_suport_xa=1
来解决,确保二进制日志和InnoDB存储引擎数据文件的同步,但是默认这个参数是不开启的,因此性能影响会达到5%。
binlog-do-db
表示需要写入哪些库的的日志,默认为空,表示需要同步所有库的日志到二进制日志。
binlog-ignore-db
表示需要忽略哪些库的日志,默认为空,表示同步所有库的日志到二进制日志。
log-slave-update
如果当前数据库是slave角色,默认情况下slave不会将从master取得并执行的二进制日志写入自己的二进制日志文件中。如果需要写入,要设置log-slave-update。如果需要搭建master->slave->slave架构的复制,则必须设置该参数。
binlog_format
binlog_format参数十分重要,它影响记录二进制日志格式。在MySQL 5.1版本之前,没有这个参数。所有二进制文件的格式都是基于SQL语句(statement)级别的,因此基于这个格式的二进制日志文件的复制(replacation)和Oracle的逻辑Standy有点相似。同时,对于复制都是有一定要求的。如在主服务器运行的rand、uuid等函数,又或者使用触发器等操作,这些都可能会导致主从服务器上表中数据的不一致(not sync)。另一个影响是,会发现InnoDB存储引擎的默认事务隔离级别是repeatable read。这其实也是因为二进制日志文件格式的关系,如果使用read committed的事务隔离级别(大多数数据库,如Oracle、Microsoft SQL Server数据库的默认隔离级别),会出现类型丢失更新的现象,从而出现主从数据库上的数据不一致。
MySQL 5.1开始引入binlog_format参数,该参数可设的值有statement、row和mixed。
(1) statement格式和之前MySQL版本一样,二进制日志文件记录的是日志的逻辑SQL语句。
(2) 在row格式下,二进制日志记录的不再是简单的SQL语句了,而是记录表的行更改情况。基于row格式的复制类似于Oracle的物理standy(当然,还是有些区别)。同时,对上诉提及的Statement格式下复制的问题予以解决。从MySQL 5.1版本开始,如果设置了binlog_format为row,可以将InnoDB的事务隔离基本设为read committed,以获得更好的并发性。
(3) 在mixed格式下,MySQL默认采用statement格式进行二进制日志文件的记录,但是在一些情况下会使用row格式,可能的情况有:
此外,binlog_format参数还有对于存储引擎的限制,如下:
存储引擎 | Row格式 | Statement格式 |
---|---|---|
InnoDB | Yes | Yes |
MyISAM | Yes | Yes |
HEAP | Yes | Yes |
MERGE | Yes | Yes |
NDB | Yes | No |
Archive | Yes | Yes |
CSV | Yes | Yes |
Federate | Yes | Yes |
Blockhole | No | Yes |
binlog_format是动态参数,因此可以在数据库运行环境下进行唔该,例如,我们可以将当前会话的binlog_format设为ROW,如:
##通过set @@session.binlog_format='row';可以修改。
mysql> select @@session.binlog_format;
+-------------------------+
| @@session.binlog_format |
+-------------------------+
| ROW |
+-------------------------+
1 row in set (0.00 sec)
当然,也可以将全局的binlog_format设置为想要的格式,不过通常这个操作会带来问题,运行时要确保更改后不会对复制带来影响。
## set global binlog_format = 'row';
mysql> select @@global.binlog_format;
+------------------------+
| @@global.binlog_format |
+------------------------+
| ROW |
+------------------------+
1 row in set (0.00 sec)
通常情况下,我们将参数binlog_format设置为ROW,这可以为数据库的恢复和复制带俩更好的可靠性。但是不能忽略的一点是,这会带来二进制文件的增加,相较于statement格式,row格式的二进制日志会需要更大的容量。
所以当参数binlog_format设置为row时,会对磁盘空间要求有一点的增加。而由于腐殖酸采用传输二进制日志的方式实现的,因此复制的网络开销也有所增加。
人如其名,二进制的文件格式为二进制,它不能像错误日志、慢查询日志那样使用cat、head、tail等命令来查看。要查看二进制日志文件的内容,必须通过MySQL提供的工具mysqlbinlog
。对于statement格式的二进制日志文件,在使用mysqlbinlog后,看到的就是执行的逻辑SQL语句,如:
statement格式
## 1.设置当前会话binlog格式为statement
mysql> set @@session.binlog_format='statement';
Query OK, 0 rows affected (0.00 sec)## 2.查询当前会话的binlog格式
mysql> select @@session.binlog_format;
+-------------------------+
| @@session.binlog_format |
+-------------------------+
| STATEMENT |
+-------------------------+
1 row in set (0.00 sec)## 3.查看binlog状态、position
mysql> show master status\G;
*************************** 1. row ***************************File: mysql-bin.000011Position: 115152005Binlog_Do_DB:Binlog_Ignore_DB:
Executed_Gtid_Set:
1 row in set (0.00 sec)ERROR:
No query specified## 4.修改SQL
mysql> update zxy set name = 'zxy' where id = 3;
Query OK, 1 row affected (0.01 sec)
Rows matched: 1 Changed: 1 Warnings: 0## 5.使用mysqlbinlog工具,查看binlog,可以看到在statement格式下,记录的是SQL语句
[root@zxy_master mysql]# mysqlbinlog --start-position=115152005 mysql-bin.000011
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#221116 14:53:40 server id 1 end_log_pos 123 CRC32 0x9c0223e1 Start: binlog v 4, server v 5.7.38-log created 221116 14:53:40 at startup
# Warning: this binlog is either in use or was not closed properly.
ROLLBACK/*!*/;
BINLOG '
9Ih0Yw8BAAAAdwAAAHsAAAABAAQANS43LjM4LWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAD0iHRjEzgNAAgAEgAEBAQEEgAAXwAEGggAAAAICAgCAAAACgoKKioAEjQA
AeEjApw=
'/*!*/;
# at 115152005
#230208 9:23:08 server id 1 end_log_pos 115152070 CRC32 0xa3c7cc82 Anonymous_GTID last_committed=60946 sequence_number=60947 rbr_only=no
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 115152070
#230208 9:23:08 server id 1 end_log_pos 115152147 CRC32 0x275b9221 Query thread_id=2061 exec_time=0 error_code=0
SET TIMESTAMP=1675819388/*!*/;
SET @@session.pseudo_thread_id=2061/*!*/;
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.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
BEGIN
/*!*/;
# at 115152147
#230208 9:23:08 server id 1 end_log_pos 115152259 CRC32 0xc13c4af2 Query thread_id=2061 exec_time=0 error_code=0
use `zxy`/*!*/;
SET TIMESTAMP=1675819388/*!*/;
update zxy set name = 'zxy' where id = 3
/*!*/;
# at 115152259
#230208 9:23:08 server id 1 end_log_pos 115152290 CRC32 0xf3d9a61f Xid = 655358
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*/;
row格式
## 1.设置当前会话的binlog格式为row
mysql> set @@session.binlog_format='row';
Query OK, 0 rows affected (0.00 sec)## 2.查看当前会话的binlog格式
mysql> select @@session.binlog_format;
+-------------------------+
| @@session.binlog_format |
+-------------------------+
| ROW |
+-------------------------+
1 row in set (0.00 sec)## 3.查看binlog状态、position
mysql> show master status\G;
*************************** 1. row ***************************File: mysql-bin.000011Position: 115152290Binlog_Do_DB:Binlog_Ignore_DB:
Executed_Gtid_Set:
1 row in set (0.00 sec)ERROR:
No query specified## 4.测试SQL
mysql> update zxy set name = 'z' where id = 3;
Query OK, 1 row affected (0.01 sec)
Rows matched: 1 Changed: 1 Warnings: 0## 5.当binlog_format格式为row的时候,简单的SQL"update zxy set name = 'z' where id = 3;"语句就记录了对于整个行更改的而信息。这也解释了为什么在row格式下,二进制文件较大。
[root@zxy_master mysql]# mysqlbinlog -vv --start-position=115152290 mysql-bin.000011
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#221116 14:53:40 server id 1 end_log_pos 123 CRC32 0x9c0223e1 Start: binlog v 4, server v 5.7.38-log created 221116 14:53:40 at startup
# Warning: this binlog is either in use or was not closed properly.
ROLLBACK/*!*/;
BINLOG '
9Ih0Yw8BAAAAdwAAAHsAAAABAAQANS43LjM4LWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAD0iHRjEzgNAAgAEgAEBAQEEgAAXwAEGggAAAAICAgCAAAACgoKKioAEjQA
AeEjApw=
'/*!*/;
# at 115152290
#230208 9:55:59 server id 1 end_log_pos 115152355 CRC32 0x50a2e5ba Anonymous_GTID last_committed=60947 sequence_number=60948 rbr_only=yes
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 115152355
#230208 9:55:59 server id 1 end_log_pos 115152426 CRC32 0x74f02ce6 Query thread_id=2061 exec_time=0 error_code=0
SET TIMESTAMP=1675821359/*!*/;
SET @@session.pseudo_thread_id=2061/*!*/;
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.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
BEGIN
/*!*/;
# at 115152426
#230208 9:55:59 server id 1 end_log_pos 115152477 CRC32 0x78036d13 Table_map: `zxy`.`zxy` mapped to number 165
# at 115152477
#230208 9:55:59 server id 1 end_log_pos 115152537 CRC32 0xfdd1d78e Update_rows: table id 165 flags: STMT_END_FBINLOG '
LwHjYxMBAAAAMwAAAF0W3QYAAKUAAAAAAAEAA3p4eQADenh5AAMDDw8EGQAyAAcTbQN4
LwHjYx8BAAAAPAAAAJkW3QYAAKUAAAAAAAEAAgAD///4AwAAAAN6eHkDMTI0+AMAAAABegMxMjSO
19H9
'/*!*/;
### UPDATE `zxy`.`zxy`
### WHERE
### @1=3 /* INT meta=0 nullable=1 is_null=0 */
### @2='zxy' /* VARSTRING(25) meta=25 nullable=1 is_null=0 */
### @3='124' /* VARSTRING(50) meta=50 nullable=1 is_null=0 */
### SET
### @1=3 /* INT meta=0 nullable=1 is_null=0 */
### @2='z' /* VARSTRING(25) meta=25 nullable=1 is_null=0 */
### @3='124' /* VARSTRING(50) meta=50 nullable=1 is_null=0 */
# at 115152537
#230208 9:55:59 server id 1 end_log_pos 115152568 CRC32 0x4a89c161 Xid = 655362
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*/;