mysql日志分析【二进制日志】

硅谷探秘者 数据库 83 0 0
  • 开启和设置二进制日志
  • 日志切换
  • 二进制日志相关参数
  • 二进制日志恢复数据库

上一篇文章介绍了普通查询日志和慢查询日志等参考:mysql日志分析,本篇主要介绍二进制日志。

一、什么是二进制日志

  二进制日志主要记录mysql数据库的变化,二进制日志包含所有更新了数据或者潜在更新了数据(如没有匹配到任何行的delete语句),语句以时间的形式保存,描述了数据的更改。二进制日志还包含执行每个更新数据库语句的时间信息,使用二进制日志的主要目的是最大可能的恢复数据库。因为二进制日志包含备份后进行的所有更新,不记录没有修改任何数据的语句。开启二进制日志对性能的开销很小,带来的好处远大于坏处

二、开启和设置二进制日志

1.查看二进制日志状态

mysql> show variables like 'log_bin%';
+---------------------------------+-------+
| Variable_name                   | Value |
+---------------------------------+-------+
| log_bin                         | OFF   |
| log_bin_basename                |       |
| log_bin_index                   |       |
| log_bin_trust_function_creators | OFF   |
| log_bin_use_v1_row_events       | OFF   |
+---------------------------------+-------+
5 rows in set (0.01 sec)

OFF 代表关闭,ON代表开启。

2.修改配置文件

  默认情况下二进制日志是关闭的,只能通过配置文件来启动和设置二进制日志。因为系统变量log_bin是静态参数,不能动态修改的(因为它不是Dynamic Variable),所以只能修改配置文件。
  修改my.cnf,在[mysqld]下面增加log_bin=mysql_bin_log等配置项目,如下:

server-id = 1                    # mysql5.7必须加,否则mysql服务启动报错
log_bin=mysql_bin_log      # 路径及命名,默认在data下
expire_logs_days = 0        # 过期时间,二进制文件自动删除的天数,0代表不删除
max_binlog_size = 100M   # 单个日志文件大小

3.重启mysql并查看二进制日志状态

[root@localhost mysql_bin_log]# service mysqld restart
Redirecting to /bin/systemctl restart mysqld.service
mysql> show variables like 'log_bin%';
+---------------------------------+------------------------------------+
| Variable_name                   | Value                              |
+---------------------------------+------------------------------------+
| log_bin                         | ON                                 |
| log_bin_basename                | /var/lib/mysql/mysql_bin_log       |
| log_bin_index                   | /var/lib/mysql/mysql_bin_log.index |
| log_bin_trust_function_creators | OFF                                |
| log_bin_use_v1_row_events       | OFF                                |
+---------------------------------+------------------------------------+
5 rows in set (0.00 sec)

4.查看当前服务器所有的二进制日志文件

show binary logs或者show master logs

mysql> show binary logs;
+----------------------+-----------+
| Log_name             | File_size |
+----------------------+-----------+
| mysql_bin_log.000001 |       177 |
| mysql_bin_log.000002 |       177 |
| mysql_bin_log.000003 |       154 |
+----------------------+-----------+
3 rows in set (0.00 sec)

5.查看当前二进制日志状态

show master status

mysql> show master status;
+----------------------+----------+--------------+------------------+-------------------+
| File                 | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set |
+----------------------+----------+--------------+------------------+-------------------+
| mysql_bin_log.000003 |      154 |              |                  |                   |
+----------------------+----------+--------------+------------------+-------------------+
1 row in set (0.00 sec)

三、二进制日志切换方法

使用命令flush logs切换二进制日志,会生成一个新的二进制文件。

mysql> show master logs;
+----------------------+-----------+
| Log_name             | File_size |
+----------------------+-----------+
| mysql_bin_log.000001 |       177 |
| mysql_bin_log.000002 |       177 |
| mysql_bin_log.000003 |       154 |
+----------------------+-----------+
3 rows in set (0.00 sec)

mysql> flush logs;
Query OK, 0 rows affected (0.01 sec)

mysql> show master logs;      
+----------------------+-----------+
| Log_name             | File_size |
+----------------------+-----------+
| mysql_bin_log.000001 |       177 |
| mysql_bin_log.000002 |       177 |
| mysql_bin_log.000003 |       205 |
| mysql_bin_log.000004 |       154 |
+----------------------+-----------+
4 rows in set (0.00 sec)

  每次重启MySQL服务也会生成一个新的二进制日志文件,相当于二进制日志切换。切换二进制日志时,你会看到这些number会不断递增。另外,除了这些二进制日志文件外,你会看到还生成了一个DB-Server-bin.index的文件,这个文件中存储所有二进制日志文件的清单又称为二进制文件的索引。

[root@localhost mysql]# ls -lrt  mysql_bin_log.*
-rw-r-----. 1 mysql mysql 177 10月 12 23:08 mysql_bin_log.000001
-rw-r-----. 1 mysql mysql 177 10月 12 23:18 mysql_bin_log.000002
-rw-r-----. 1 mysql mysql  69 10月 12 23:29 mysql_bin_log.index
-rw-r-----. 1 mysql mysql 154 10月 12 23:29 mysql_bin_log.000003
[root@localhost mysql]# more mysql_bin_log.index
./mysql_bin_log.000001
./mysql_bin_log.000002
./mysql_bin_log.000003

四、查看二进制日志文件内容

方法1:使用show binlog events方式可以获取当前以及指定binlog的日志,不适宜提取大量日志。

语法:SHOW BINLOG EVENTS [IN 'log_name'] [FROM pos] [LIMIT [offset,] row_count]

首先刷新了一下二进制文件,然后向test.user表插入一条数据

mysql> show binlog events in 'mysql_bin_log.000005';
+----------------------+-----+----------------+-----------+-------------+---------------------------------------+
| Log_name             | Pos | Event_type     | Server_id | End_log_pos | Info                                  |
+----------------------+-----+----------------+-----------+-------------+---------------------------------------+
| mysql_bin_log.000005 |   4 | Format_desc    |         1 |         123 | Server ver: 5.7.35-log, Binlog ver: 4 |
| mysql_bin_log.000005 | 123 | Previous_gtids |         1 |         154 |                                       |
| mysql_bin_log.000005 | 154 | Anonymous_Gtid |         1 |         219 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS'  |
| mysql_bin_log.000005 | 219 | Query          |         1 |         291 | BEGIN                                 |
| mysql_bin_log.000005 | 291 | Table_map      |         1 |         342 | table_id: 245 (test.user)             |
| mysql_bin_log.000005 | 342 | Write_rows     |         1 |         391 | table_id: 245 flags: STMT_END_F       |
| mysql_bin_log.000005 | 391 | Xid            |         1 |         422 | COMMIT /* xid=117 */                  |
+----------------------+-----+----------------+-----------+-------------+---------------------------------------+
7 rows in set (0.00 sec)

方法2:mysqlbinlog命令查看二进制文件内容

[root@localhost mysql]# mysqlbinlog ./mysql_bin_log.000005        
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#211013  0:02:49 server id 1  end_log_pos 123 CRC32 0x3b09ae53  Start: binlog v 4, server v 5.7.35-log created 211013  0:02:49
# Warning: this binlog is either in use or was not closed properly.
BINLOG '
qbFlYQ8BAAAAdwAAAHsAAAABAAQANS43LjM1LWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAXwAEGggAAAAICAgCAAAACgoKKioAEjQA
AVOuCTs=
'/*!*/;
# at 123
#211013  0:02:49 server id 1  end_log_pos 154 CRC32 0x62e9dbd9  Previous-GTIDs
# [empty]
# at 154
#211013  0:03:21 server id 1  end_log_pos 219 CRC32 0x61ddc4b0  Anonymous_GTID  last_committed=0        sequence_number=1       rbr_only=yes
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 219
#211013  0:03:21 server id 1  end_log_pos 291 CRC32 0x324ec32e  Query   thread_id=3     exec_time=0     error_code=0
SET TIMESTAMP=1634054601/*!*/;
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=1436549152/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8mb4 *//*!*/;
SET @@session.character_set_client=45,@@session.collation_connection=45,@@session.collation_server=8/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
BEGIN
/*!*/;
# at 291
#211013  0:03:21 server id 1  end_log_pos 342 CRC32 0x24e77946  Table_map: `test`.`user` mapped to number 245
# at 342
#211013  0:03:21 server id 1  end_log_pos 391 CRC32 0x077b21a0  Write_rows: table id 245 flags: STMT_END_F

BINLOG '
ybFlYRMBAAAAMwAAAFYBAAAAAPUAAAAAAAEABHRlc3QABHVzZXIAAwMPAwL/AAZGeeck
ybFlYR4BAAAAMQAAAIcBAAAAAPUAAAAAAAEAAgAD//gBAAAABHBpdGUYAAAAoCF7Bw==
'/*!*/;
# at 391
#211013  0:03:21 server id 1  end_log_pos 422 CRC32 0x57d10f66  Xid = 117
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*/;

mysql5.7以上内容已经被加密,可以通过一下命令查看解密的文件。

[root@localhost mysql]# mysqlbinlog --base64-output=decode-rows -v ./mysql_bin_log.000005  
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#211013  0:02:49 server id 1  end_log_pos 123 CRC32 0x3b09ae53  Start: binlog v 4, server v 5.7.35-log created 211013  0:02:49
# Warning: this binlog is either in use or was not closed properly.
# at 123
#211013  0:02:49 server id 1  end_log_pos 154 CRC32 0x62e9dbd9  Previous-GTIDs
# [empty]
# at 154
#211013  0:03:21 server id 1  end_log_pos 219 CRC32 0x61ddc4b0  Anonymous_GTID  last_committed=0        sequence_number=1       rbr_only=yes
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 219
#211013  0:03:21 server id 1  end_log_pos 291 CRC32 0x324ec32e  Query   thread_id=3     exec_time=0     error_code=0
SET TIMESTAMP=1634054601/*!*/;
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=1436549152/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8mb4 *//*!*/;
SET @@session.character_set_client=45,@@session.collation_connection=45,@@session.collation_server=8/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
BEGIN
/*!*/;
# at 291
#211013  0:03:21 server id 1  end_log_pos 342 CRC32 0x24e77946  Table_map: `test`.`user` mapped to number 245
# at 342
#211013  0:03:21 server id 1  end_log_pos 391 CRC32 0x077b21a0  Write_rows: table id 245 flags: STMT_END_F
### INSERT INTO `test`.`user`
### SET
###   @1=1
###   @2='pite'
###   @3=24
# at 391
#211013  0:03:21 server id 1  end_log_pos 422 CRC32 0x57d10f66  Xid = 117
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*/;

可以看到insert语句了。

五、删除二进制日志的方法

  二进制日志的删除可以通过命令手工删除,也可以设置自动清理。自动清理可以通过之前提到过的配置文件选项 expire_logs_days 来配置,参考标题二。

1.删除某个日志之前的所有二进制日志文件

命令:purge binary logs to 'xxx';

mysql> show master logs;
+----------------------+-----------+
| Log_name             | File_size |
+----------------------+-----------+
| mysql_bin_log.000001 |       177 |
| mysql_bin_log.000002 |       177 |
| mysql_bin_log.000003 |       205 |
| mysql_bin_log.000004 |      1121 |
| mysql_bin_log.000005 |       422 |
+----------------------+-----------+
5 rows in set (0.00 sec)

mysql> purge binary logs to 'mysql_bin_log.000003'; 
Query OK, 0 rows affected (0.00 sec)

mysql> show master logs;
+----------------------+-----------+
| Log_name             | File_size |
+----------------------+-----------+
| mysql_bin_log.000003 |       205 |
| mysql_bin_log.000004 |      1121 |
| mysql_bin_log.000005 |       422 |
+----------------------+-----------+
3 rows in set (0.00 sec)

2.清除某个时间点以前的二进制日志文件

mysql> purge binary logs before '2021-10-13 10:10:00';      
Query OK, 0 rows affected, 1 warning (0.00 sec)

3.清除7天前的二进制日志文件

mysql> purge master logs before date_sub( now( ), interval 7 day);
Query OK, 0 rows affected, 1 warning (0.00 sec)

4.清除所有的二进制日志文件(当前不存在主从复制关系)

mysql> reset master;
Query OK, 0 rows affected (0.01 sec)

mysql> show master logs;
+----------------------+-----------+
| Log_name             | File_size |
+----------------------+-----------+
| mysql_bin_log.000001 |       154 |
+----------------------+-----------+
1 row in set (0.00 sec)

六、二进制日志相关参数

1.log_bin_basename

  系统变量log_bin_basename是MySQL 5.6.2开始引入的。 它表示二进制日志文件名。默认值为datadir + ‘/‘ + hostname + ‘-bin’。 该参数不需要设置,也不能在my.cnf中设置,否则会报错。

2.log_bin_index

  系统变量log_bin_index是MySQL 5.6.4开始引入的。 它表示二进制日志的索引文件。该参数可以在my.cnf中设置。

3.log_bin_trust_function_creators

  系统变量log_bin_trust_function_creators,默认为OFF,这个参数开启会限制存储过程、Function、触发器的创建。

4.sql_log_bin

  系统变量sql_log_bin 用于控制会话级别二进制日志功能的开启或关闭,默认为ON,表示启用二进制日志功能。

5.expire_logs_days

  系统变量expire_logs_days 用于配置超时删除日志文件,单位是天,0代表用不删除。

6.binlog_cache_size

  系统变量binlog_cache_size 表示为每个客户端分配binlog_cache_size大小的缓存,默认值32768。二进制日志缓存使用的前提条件是服务器端使用了支持事务的引擎以及开启了bin log功能,它是MySQL用来提高binlog的效率而设计的一个用于短时间内临时缓存binlog数据的内存区域。一般来说,如果我们的数据库中没有什么大事务,写入也不是特别频繁,2MB~4MB是一个合适的选择。但是如果我们的数据库大事务较多或多事务语句,写入量比较大,可适当调高binlog_cache_size。同时,我们可以通过binlog_cache_use 以及 binlog_cache_disk_use来分析设置的binlog_cache_size是否足够,是否有大量的binlog_cache由于内存大小不够而使用临时文件(binlog_cache_disk_use)来缓存了。

7.max_binlog_cache_size

  系统变量max_binlog_cache_size 二进制日志能够使用的最大cache内存大小。当执行多语句事务时,max_binlog_cache_size 如果不够大,系统可能会报出“Multi-statement transaction required more than ‘max_binlog_cache_size’ bytes of storage”的错误。

8.max_binlog_stmt_cache_size

  max_binlog_cache_size针对事务语句,max_binlog_stmt_cache_size针对非事务语句,当我们发现Binlog_cache_disk_use或者Binlog_stmt_cache_disk_use比较大时就需要考虑增大cache的大小

9.max_binlog_size

  系统变量max_binlog_size, 表示二进制日志的最大值,一般设置为512M或1GB,但不能超过1GB。该设置并不能严格控制二进制日志的大小,尤其是二进制日志比较靠近为不而又遇到一根比较大事务时, 为了保证事务的完整性,不可能做切换日志的动作,只能将该事务的所有SQL都记录进当前日志,直到事务结束。

10.binlog_checksum

  系统变量binlog_checksum 用作复制的主从校检。 NONE表示不生成checksum,CRC-32表示使用这个算法做校检。

11.sync_binlog

  系统变量sync_binlog,这个参数对于Mysql系统来说是至关重要的,它不仅影响到二进制日志文件对MySQL所带来的性能损耗,而且还影响到MySQL中数据的完整性。
  sync_binlog=0,当事务提交后,Mysql仅仅是将binlog_cache中的数据写入binlog文件,但不执行fsync之类的磁盘同步指令通知文件系统将缓存刷新到磁盘,而是让Filesystem自行决定什么时候来做同步。MySQL中默认的设置是 sync_binlog=0,即不作任何强制性的磁盘刷新指令,这个设置性能是最好的,但风险也是最大的。一旦系统崩溃(Crash),在文件系统缓存中的所有二进制日志信息都会丢失。从而带来数据不完整问题。
  sync_binlog=n,在进行n次事务提交以后,Mysql将执行一次fsync之类的磁盘同步指令,同时文件系统将Binlog文件缓存刷新到磁盘。

12.binlog_format

  系统变量binlog_format 指定二进制日志的类型。分别有STATEMENT、ROW、MIXED三种值。MySQL 5.7.6之前默认为STATEMENT模式。MySQL 5.7.7之后默认为ROW模式。这个参数主要影响主从复制。

七、使用二进制日志恢复数据库

  如果开启了二进制日志,出现了数据丢失,可以通过二进制日志恢复数据库,语法如下:

mysqlbinlog [option] filename | mysql -u username -p passwd

  option的参数主要有四个 —start-datetime —stop-datetime 和 start-position —stop-position ,前者指定恢复的时间点,后者指定恢复的位置。

例如,日志的部分内容如下:

BEGIN
/*!*/;
# at 3239
#211013  1:18:40 server id 1  end_log_pos 3290 CRC32 0x69aad344         Table_map: `test`.`user` mapped to number 108
# at 3290
#211013  1:18:40 server id 1  end_log_pos 3339 CRC32 0x57166053         Write_rows: table id 108 flags: STMT_END_F
### INSERT INTO `test`.`user`
### SET
###   @1=13
###   @2='pite'
###   @3=24
# at 3339
#211013  1:18:40 server id 1  end_log_pos 3370 CRC32 0x222c180f         Xid = 88
COMMIT/*!*/;
# at 3370
#211013  1:19:36 server id 1  end_log_pos 3435 CRC32 0x76e7e402         Anonymous_GTID  last_committed=12       sequence_number=13      rbr_only=yes
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 3435
#211013  1:19:36 server id 1  end_log_pos 3507 CRC32 0x7bb2c2f1         Query   thread_id=3     exec_time=0     error_code=0
SET TIMESTAMP=1634059176/*!*/;
BEGIN
/*!*/;
# at 3507
#211013  1:19:36 server id 1  end_log_pos 3558 CRC32 0xd62db679         Table_map: `test`.`user` mapped to number 108
# at 3558
#211013  1:19:36 server id 1  end_log_pos 3775 CRC32 0x39ad8c69         Delete_rows: table id 108 flags: STMT_END_F
### DELETE FROM `test`.`user`
### WHERE
###   @1=1
###   @2='pite'
###   @3=24
### DELETE FROM `test`.`user`
### WHERE
###   @1=2
###   @2='pite'
###   @3=24
### DELETE FROM `test`.`user`

# at 3558之前都是在插入数据,之后执行了一个DELETE FROM test.user语句,把user表的数据全部删除了。现在要把删除的数据还原。

mysqlbinlog --start-position="123" --stop-position="3558" ./mysql_bin_log.000001 | mysql -uroot -p123456

[root@localhost mysql]# mysqlbinlog --start-position="123" --stop-position="3558" ./mysql_bin_log.000001 | mysql -uroot -p123456
WARNING: The range of printed events ends with a row event or a table map event that does not have the STMT_END_F flag set. This might be because the last statement was not fully written to the log, or because you are using a --stop-position or --stop-datetime that refers to an event in the middle of a statement. The event(s) from the partial statement have not been written to output.
mysql: [Warning] Using a password on the command line interface can be insecure.

执行完成之后数据就恢复了。

参考:
https://blog.csdn.net/demonson/article/details/80664141
https://www.cnblogs.com/f-ck-need-u/p/9001061.html

猜你喜欢
数据库 46 MariaDB/MySQL中,主要有5种文件:1.错误(errorlog):记录mysql服务的启停时正确和错误的信息,还记录启动、停止、运行过程中的错误信息。2.查询(generallog):
框架 1693 log4j.properties配置1.完整示例:##屏蔽com.mchange.v2包下面的debug,info,warn信息##log4j.logger.xxx=error意为屏蔽xxx包下
框架 20 -warn"/appender-refref="file-error"//root/configuration不同级别的由不同的appender处理。、application.yml配置的文件存放目
框架 911 ""log4j.dtd"log4j:configuration!--输出到控台--appendername="consoleAppender"class="org.apache.log4j.Conso
框架 2556 springaop实现操作记录此次的目的是实现对controller中的方法执行情况行记录,记录的有方法执行时间,操作人,请求的路径,方法的入参,模块,功能等。并实现利用注解的方式实现对被操作
数据库基础 2445 mysql年月秒格式化DATE_FORMATSELECTDATE_FORMAT(NOW(),'%Y-%m-%d%H:%i:%s')
框架 596 1.Log注解importjava.lang.annotation.Documented;importjava.lang.annotation.ElementType;importjava.lang.annotation.Retention;importjava.lang.annotation.RetentionPolicy;importjava.lang.annotation.Target;//
框架 6897 多么痛的领悟~离资源打包后运行项目,启动失败数据源初始化失败~检查问题,这种情况下没有打印错误,首先配置一下,将错误报告在控台中打印出来。resources文件夹下创建一个
归档
2018年11月  12 2018年12月  33 2019年01月  28 2019年02月  28 2019年03月  32 2019年04月  27 2019年05月  33 2019年06月  6 2019年07月  12 2019年08月  12 2019年09月  21 2019年10月  8 2019年11月  15 2019年12月  25 2020年01月  9 2020年02月  5 2020年03月  16 2020年04月  4 2020年06月  1 2020年07月  7 2020年08月  13 2020年09月  9 2020年10月  5 2020年12月  3 2021年01月  1 2021年02月  5 2021年03月  7 2021年04月  4 2021年05月  4 2021年06月  1 2021年07月  7 2021年08月  2 2021年09月  8 2021年10月  9 2021年11月  16
标签
算法基础 linux 前端 c++ 数据结构 框架 数据库 计算机基础 储备知识 java基础 ASM 其他 深入理解java虚拟机 nginx git 消息中间件 搜索 maven redis docker dubbo vue 导入导出 软件使用 idea插件 协议
目录
祝愿神州十三飞行乘组平安归来