第 14 章 数据库日志

作者: Brinnatt 分类: mysql 经验专题 发布时间: 2023-01-13 16:27

我们在讲解数据库事务时,讲过两种日志:重做日志、回滚日志。下面讲述数据库其他重要日志。

对于线上数据库应用系统,突然遭遇 数据库宕机 怎么办?在这种情况下,定位宕机的原因 就非常关键。

我们可以查看数据库的 错误日志。因为日志中记录了数据库运行中的诊断信息,包括了错误、警告和注释等信息。

比如:从日志中发现某个连接中的 SQL 操作发生了死循环,导致内存不足,被系统强行终止了。明确了原因,处理起来也就轻松了,系统很快就恢复了运行。

除了发现错误,日志在数据复制、数据恢复、操作审计,以及确保数据的永久性和一致性等方面,都有着不可替代的作用。

千万不要小看日志。很多看似奇怪的问题,答案往往就藏在日志里。很多情况下,只有通过查看日志才能发现问题的原因,真正解决问题。所以,一定要学会查看日志,养成检查日志的习惯,对提升你的数据库应用开发能力至关重要。

MySQL8.0 官网日志地址:https://dev.mysql.com/doc/refman/8.0/en/server-logs.html

14.1、MySQL 支持的日志

14.1.1、日志类型

MySQL 有不同类型的日志文件,用来存储不同类型的日志,分为 二进制日志错误日志通用查询日志慢查询日志,这也是常用的 4 种。

MySQL 8 又新增两种支持的日志:中继日志数据定义语句日志。使用这些日志文件,可以查看 MySQL 内部发生的事情。

这 6 类日志分别为:

  • 慢查询日志:记录所有执行时间超过 long_query_time 的所有查询,方便我们对查询进行优化。
  • 通用查询日志:记录所有连接的起始时间和终止时间,以及连接发送给数据库服务器的所有指令,对我们复原操作的实际场景、发现问题,甚至是对数据库操作的审计都有很大的帮助。
  • 错误日志:记录 MySQL 服务的启动、运行或停止 MySQL 服务时出现的问题,方便我们了解服务器的状态,从而对服务器进行维护。
  • 二进制日志:记录所有更改数据的语句,可以用于主从服务器之间的数据同步,以及服务器遇到故障时数据的无损失恢复。
  • 中继日志:用于主从服务器架构中,从服务器用来存放主服务器二进制日志内容的一个中间文件。从服务器通过读取中继日志的内容,来同步主服务器上的操作。
  • 数据定义语句日志:记录数据定义语句执行的元数据操作。

除二进制日志外,其他日志都是 文本文件。默认情况下,所有日志创建于 MySQL数据目录 中。

14.1.2、日志的弊端

  • 日志功能会 降低MySQL数据库的性能。例如,在查询非常频繁的 MySQL 数据库系统中,如果开启了通用查询日志和慢查询日志,MySQL 数据库会花费很多时间记录日志。
  • 日志会 占用大量的磁盘空间。对于用户量非常大,操作非常频繁的数据库,日志文件需要的存储空间设置比数据库文件需要的存储空间还要大。

14.2、慢查询日志(slow query log)

参见第 6 章的 "[定位执行慢的 SQL](./06 Linux MySQL Performance Analysis.md#6.4、定位执行慢的 SQL)" 章节。

14.3、通用查询日志(general query log)

通用查询日志用来 记录用户的所有操作,包括启动和关闭 MySQL 服务、所有用户的连接开始时间和截止时间、发给 MySQL 数据库服务器的所有 SQL 指令等。

当我们的数据发生异常时,查看通用查询日志,还原操作时的具体场景,可以帮助我们准确定位问题。

14.3.1、案例说明

在电商系统中,购买商品并且使用微信支付完成以后,却发现支付中心的记录并没有新增,此时用户再次使用支付宝支付,就会出现 重复支付 的问题。

但是当去数据库中查询数据的时候,会发现只有一条记录存在。那么此时给到的现象就是只有一条支付记录,但是用户却支付了两次。

我们对系统进行了仔细检查,没有发现数据问题,因为用户编号和订单编号以及第三方流水号都是对的。可是用户确实支付了两次,这个时候,我们想到了检查通用查询日志,看看当天到底发生了什么。

查看之后,发现:

  1. 1 月 1 日下午 2 点,用户使用微信支付完以后,但是由于网络故障,支付中心没有及时收到微信支付的回调通知,导致当时没有写入数据。
  2. 1 月 1 日下 2 点 30,用户又使用支付宝支付,此时记录更新到支付中心。
  3. 1 月 1 日晚上 9 点,微信的回调通知过来了,但是支付中心已经存在了支付宝的记录,所以只能覆盖记录了。
  4. 由于网络的原因导致了重复支付。至于解决问题的方案就很多了,这里省略。可以看到通用查询日志可以帮助我们了解操作发生的具体时间和操作的细节,对找出异常发生的原因极其关键。

14.3.2、查看当前状态

mysql> SHOW VARIABLES LIKE '%general%';
+------------------+---------------------------+
| Variable_name    | Value                     |
+------------------+---------------------------+
| general_log      | OFF                       |    # 通用查询日志处于关闭状态
| general_log_file | /var/lib/mysql/node01.log |    # 通用查询日志文件的名称是node01.log
+------------------+---------------------------+
2 rows in set (0.03 sec)

说明 1:系统变量 general_log 的值是 OFF,即通用查询日志处于关闭状态。在 MySQL 中,这个参数的默认值是关闭的。因为一旦开启记录通用查询日志,MySQL 会记录所有的连接起止和相关的 SOL 操作,这样会消耗系统资源并且占用磁盘空间。我们可以通过手动修改变量的值,在 需要的时候开启日志

说明 2:通用查询日志文件的名称是 node01.log。存储路径是 /var/lib/mysql/,默认也是数据路径。这样我们就知道在哪里可以查看通用查询日志的内容了。

14.3.3、启动日志

方式 1:永久性方式

修改 my.cnf 或者 my.ini 配置文件来设置。在 [mysqld] 组下加入 log 选项,并重启 MySQL 服务。格式如下:

[mysqld]
general_log=ON
general_log_file=[path[filename]] # 日志文件所在目录路径,filename为日志文件

如果不指定目录和文件名,通用查询日志将默认存储在 MySQL 数据目录中的 hostname.log 文件中,hostname 表示主机名。

方式 2:临时性方式

SET GLOBAL general_log=on; # 开启通用查询日志
SET GLOBAL general_log_file=’path/filename’; # 设置日志文件保存位置

对应的,关闭操作 SQL 命令如下:

SET GLOBAL general_log=off; # 关闭通用查询日志

查看设置后情况:

SHOW VARIABLES LIKE 'general_log%';

14.3.4、查看日志

通用查询日志是以 文本文件 的形式存储在文件系统中的,可以使用 文本编辑器 直接打开日志文件。每台 MySQL 服务器的通用查询日志内容是不同的。

  • 在 Windows 操作系统中,使用文本文件查看器;
  • 在 Linux 系统中,可以使用 vi 工具或者 gedit 工具查看;
  • 在 Mac OSX 系统中,可以使用文本文件查看器或者 vi 等工具查看。

SHOW VARIABLES LIKE 'general_log%'; 结果中可以看到通用查询日志的位置。

/usr/sbin/mysqld, Version: 8.0.26 (MySQL Community Server - GPL). started with:
Tcp port: 3306 Unix socket: /var/lib/mysql/mysql.sock
Time Id Command Argument
2022-01-04T07:44:58.052890Z 10 Query SHOW VARIABLES LIKE '%general%'
2022-01-04T07:45:15.666672Z 10 Query SHOW VARIABLES LIKE 'general_log%'
2022-01-04T07:45:28.970765Z 10 Query select * from student
2022-01-04T07:47:38.706804Z 11 Connect root@localhost on using Socket
2022-01-04T07:47:38.707435Z 11 Query select @@version_comment limit 1
2022-01-04T07:48:21.384886Z 12 Connect root@172.16.210.1 on using TCP/IP
2022-01-04T07:48:21.385253Z 12 Query SET NAMES utf8
2022-01-04T07:48:21.385640Z 12 Query USE `atguigu12`
2022-01-04T07:48:21.386179Z 12 Query SHOW FULL TABLES WHERE Table_Type != 'VIEW'
2022-01-04T07:48:23.901778Z 13 Connect root@172.16.210.1 on using TCP/IP
2022-01-04T07:48:23.902128Z 13 Query SET NAMES utf8
2022-01-04T07:48:23.905179Z 13 Query USE `atguigu`
2022-01-04T07:48:23.905825Z 13 Query SHOW FULL TABLES WHERE Table_Type != 'VIEW'
2022-01-04T07:48:32.163833Z 14 Connect root@172.16.210.1 on using TCP/IP
2022-01-04T07:48:32.164451Z 14 Query SET NAMES utf8
2022-01-04T07:48:32.164840Z 14 Query USE `atguigu`
2022-01-04T07:48:40.006687Z 14 Query select * from account

在通用查询日志里面,我们可以清楚地看到,什么时候开启了新的客户端登陆数据库,登录之后做了什么 SQL 操作,针对的是哪个数据表等信息。

14.3.5、停止日志

方式 1:永久性方式

修改 my.cnf 或者 my.ini 文件,把 [mysqld] 组下的 general_log 值设置为 OFF 或者把 general_log 一项注释掉。修改保存后,再 重启MySQL服务,即可生效。

举例 1:

[mysqld]
general_log=OFF

举例 2:

[mysqld]
# general_log=ON

方式 2:临时性方式

使用 SET 语句停止 MySQL 通用查询日志功能:

SET GLOBAL general_log=off;

查询通用日志功能:

SHOW VARIABLES LIKE 'general_log%';

14.3.6、删除和刷新日志

如果数据的使用非常频繁,那么通用查询日志会占用服务器非常大的磁盘空间。数据管理员可以删除很长时间之前的查询日志,以保证 MySQL 服务器上的硬盘空间。

手动删除文件

SHOW VARIABLES LIKE 'general_log%';

可以看出,通用查询日志的目录默认为 MySQL 数据目录。在该目录下手动删除通用查询日志 node01.log。

使用如下命令重新生成查询日志文件,具体命令如下。刷新 MySQL 数据目录,发现创建了新的日志文 件。前提一定要开启通用日志。

mysqladmin -uroot -p flush-logs

如果希望备份旧的通用查询日志,就必须先将旧的日志文件复制出来或者改名,然后执行上面的 mysqladmin 命令。正确流程如下:

cd mysql-data-directory # 输入自己的通用日志文件所在目录
mv mysql.general.log mysql.general.log.old # 指定旧的文件名 以及 新的文件名
mysqladmin -uroot -p flush-logs

14.4、错误日志(error log)

错误日志记录了 MySQL 服务器启动、停止运行的时间,以及系统启动、运行和停止过程中的诊断信息,包括 错误警告提示 等。
通过错误日志可以查看系统的运行状态,便于即时发现故障、修复故障。如果 MySQL 服务 出现异常,错误日志是发现问题、解决故障的 首选

14.4.1、启动日志

在 MySQL 数据库中,错误日志功能是 默认开启 的。而且,错误日志 无法被禁止

默认情况下,错误日志存储在 MySQL 数据库的数据文件夹下,名称默认为 mysqld.log(Linux 系统) 或 hostname.err(mac 系统)。如果需要制定文件名,则需要在 my.cnf 或者 my.ini 中做如下配置:

[mysqld]
log-error=[path/[filename]] # path为日志文件所在的目录路径,filename为日志文件名

修改配置项后,需要重启 MySQL 服务以生效。

14.4.2、查看日志

MySQL 错误日志是以文本文件形式存储的,可以使用文本编辑器直接查看。

查询错误日志的存储路径:

mysql> SHOW VARIABLES LIKE 'log_err%';
+----------------------------+----------------------------------------+
| Variable_name              | Value                                  |
+----------------------------+----------------------------------------+
| log_error                  | /var/log/mysqld.log                    |
| log_error_services         | log_filter_internal; log_sink_internal |
| log_error_suppression_list |                                        |
| log_error_verbosity        | 2                                      |
+----------------------------+----------------------------------------+
4 rows in set (0.00 sec)

执行结果中可以看到错误日志文件是 mysqld.log,位于操作系统默认日志目录 /var/log 下面。

下面我们查看一下错误日志的内容。

2022-09-06T17:51:13.087896Z 0 [System] [MY-013169] [Server] /usr/sbin/mysqld (mysqld 8.0.30) initializing of server in progress as process 1475
2022-09-06T17:51:13.093777Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2022-09-06T17:51:13.494064Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
2022-09-06T17:51:15.189939Z 6 [Note] [MY-010454] [Server] A temporary password is generated for root@localhost: TdvG9TYaD%p/
2022-09-06T17:51:18.428292Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 8.0.30) starting as process 1524
2022-09-06T17:51:18.453462Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2022-09-06T17:51:19.320387Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
2022-09-06T17:51:19.929223Z 0 [Warning] [MY-010068] [Server] CA certificate ca.pem is self signed.
2022-09-06T17:51:19.929332Z 0 [System] [MY-013602] [Server] Channel mysql_main configured to support TLS. Encrypted connections are now supported for this channel.
2022-09-06T17:51:19.963208Z 0 [System] [MY-010931] [Server] /usr/sbin/mysqld: ready for connections. Version: '8.0.30'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  MySQL Community Server - GPL.
2022-09-06T17:51:19.963314Z 0 [System] [MY-011323] [Server] X Plugin ready for connections. Bind-address: '::' port: 33060, socket: /var/run/mysqld/mysqlx.sock
2022-09-07T09:55:16.047172Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 8.0.30) starting as process 778
2022-09-07T09:55:16.140153Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2022-09-07T09:55:17.319204Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
2022-09-07T09:55:17.742018Z 0 [System] [MY-010229] [Server] Starting XA crash recovery...
2022-09-07T09:55:17.855770Z 0 [System] [MY-010232] [Server] XA crash recovery finished.
......

可以看到,错误日志文件中记录了服务器启动的时间,以及存储引擎 InnoDB 启动和停止的时间等。我们在做初始化时候生成的数据库初始密码也是记录在 error.log 中。

14.4.3、删除和刷新日志

对于很久以前的错误日志,数据库管理员查看这些错误日志的可能性不大,可以将这些错误日志删除,以保证 MySQL 服务器上的 硬盘空间。MySQL 的错误日志是以文本文件的形式存储在文件系统中的,可以 直接删除

  1. 删除操作

    # 在运行状态下删除错误日志文件后,MySQL并不会自动创建日志文件。
    第一种,直接删除:rm -f /var/lib/mysql/mysqld.log
    
    第二种,重命名文件:mv /var/log/mysqld.log /var/log/mysqld.log.old
  2. 重建日志

    mysqladmin -uroot -p flush-logs

    如果删除了错误日志,执行这步可能报错:

    [root@node01 ~]# mysqladmin -uroot -p flush-logs
    Enter password: 
    mysqladmin: refresh failed; error: 'Could not open file '/var/log/mysqld.log' for error logging.'

    官网提示:

    Note
    For the server to recreate a given log file after you have renamed the file externally, the file location must be writable by the server. This may not always be the case. For example, on Linux, the server might write the error log as /var/log/mysqld. log, where /var/log is owned by root and not writable by mysqld. ln this case, log-flushing operations fail to create a new log file.
    To handle this situation, you must manually create the new log file with the proper ownership after renaming the original logfile. For example, execute these commands as root:

    mv /var/log/mysqld.log /var/log/mysqld.log.old
    install -omysql -gmysql -m0644 /dev/null /var/log/mysqld.log
  3. 根据官方提示,补充操作

    install -omysql -gmysql -m0644 /dev/null /var/log/mysqld.log

flush-logs 指令操作:

  • MySQL 5.5.7 以前的版本,flush-logs 将错误日志文件重命名为 filename.err_old,并创建新的日志文件。
  • 从 MySQL 5.5.7 开始,flush-logs 只是重新打开日志文件,并不做日志备份和创建的操作。
  • 如果日志文件不存在,MySQL 启动或者执行 flush-logs 时会自动创建新的日志文件(前提是 mysql 进程有写权限)。

14.4.4、MySQL 8.0 新特性

MySQL8.0 里对错误日志的改进。MySQL8.0 的错误日志可以理解为一个全新的日志,在这个版本里,接受了来自社区的广泛批评意见,在这些意见和建议的基础上生成了新的日志。
下面这些是来自社区的意见:

  • 默认情况下内容过于冗长
  • 遗漏了有用的信息
  • 难以过滤某些信息
  • 没有标识错误信息的子系统源
  • 没有错误代码,解析消息需要识别错误
  • 引导消息可能会丢失
  • 固定格式

针对这些意见,MySQL 做了如下改变:

  • 采用组件架构,通过不同的组件执行日志的写入和过滤功能
  • 写入错误日志的全部信息都具有唯一的错误代码从10000开始
  • 增加了一个新的消息分类《system》用于在错误日志中始终可见,关于服务器状态更改事件的非错误消息
  • 增加了额外的附加信息,例如关机时的版本信息,谁发起的关机等等
  • 两种过滤方式,Internal 和 Dragnet
  • 三种写入形式,经典、JSON 和 syseventlog

小结:

通常情况下,管理员不需要查看错误日志。但是,MySQL 服务器发生异常时,管理员可以从错误日志中找到发生异常的时间、原因,然后根据这些信息来解决异常。

14.5、二进制日志(bin log)

binlog 可以说是 MySQL 中比较 重要 的日志了,在日常开发及运维过程中,经常会遇到。

binlog 即 binary log,二进制日志文件,也叫作变更日志(update log)。它记录了数据库所有执行的 DDLDML 等数据库更新事件的语句,但是不包含没有修改任何数据的语句(如数据查询语句 select、show 等)。

它以 事件形式 记录并保存在 二进制文件 中。通过这些信息,我们可以再现数据更新操作的全过程。

如果想要记录所有语句(例如,为了识别有问题的查询),需要使用通用查询日志。

binlog 主要应用场景:

  • 一是用于 数据恢复,如果 MySQL 数据库意外停止,可以通过二进制日志文件来查看用户执行了哪些操作,对数据库服务器文件做了哪些修改,然后根据二进制日志文件中的记录来恢复数据库服务器。
  • 二是用于 数据复制,由于日志的延续性和时效性,master 把它的二进制日志传递给 slaves 来达到 master-slave 数据一致的目的。

可以说 MySQL 数据库的 数据备份主备主主主从 都离不开 binlog,需要依靠 binlog 来同步数据,保证数据一致性。

mysql_binlog

14.5.1、查看默认情况

查看记录二进制日志是否开启:在 MySQL8 中默认情况下,二进制文件是开启的。

mysql> show variables like '%log_bin%';
+---------------------------------+-----------------------------+
| Variable_name                   | Value                       |
+---------------------------------+-----------------------------+
| log_bin                         | ON                          |
| log_bin_basename                | /var/lib/mysql/binlog       |
| log_bin_index                   | /var/lib/mysql/binlog.index |
| log_bin_trust_function_creators | ON                          |
| log_bin_use_v1_row_events       | OFF                         |
| sql_log_bin                     | ON                          |
+---------------------------------+-----------------------------+
6 rows in set (0.00 sec)

log_bin_basename:是 binlog 日志的基本文件名,后面会追加标识来表示每一个文件。

log_bin_index:是 binlog 文件的索引文件,这个文件管理了所有的 binlog 文件的目录。

log_bin_trust_function_creators:限制存储过程,前面我们已经讲过了,这是因为二进制日志的一个重要功能是用于主从复制,而存储函数有可能导致主从的数据不一致。所以当开启二进制日志后,需要限制存储函数的创建、修改、调用。

log_bin_use_v1_row_events:此只读系统变量已弃用。ON 表示使用版本 1 二进制日志行,OFF 表示使用版本 2 二进制日志行(MySQL 5.6 的默认值为 2)。

14.5.2、日志参数设置

方式 1:永久性方式

修改 MySQL 的 my.cnfmy.ini 文件可以设置二进制日志的相关参数:

[mysqld]
# 启用二进制日志
log-bin=atguigu-bin
binlog_expire_logs_seconds=600
max_binlog_size=100M

提示:

  1. log-bin=mysql-bin:打开日志(主机需要打开),这个 mysql-bin 也可以自定义,这里也可以加上路径,如:/home/www/mysql_bin_log/mysql-bin
  2. binlog_expire_logs_seconds:此参数控制二进制日志文件保留的时长,单位是 ,默认 2592000 30 天 -- 14400 4 小时;86400 1 天;259200 3 天;
  3. max_binlog_size:控制单个二进制日志大小,当前日志文件大小超过此变量时,执行切换动作。此参数的 最大和默认值是 1GB,该设置并 不能严格控制 Binlog 的大小,尤其是 Binlog 比较靠近最大值而又遇到一个比较大事务时,为了保证事务的完整性,可能不做切换日志的动作,只能将该事务的所有 SQL 都记录进当前日志,直到事务结束。一般情况下可采取默认值。

重新启动 MySQL 服务,查询二进制日志的信息,执行结果:

mysql> show variables like '%log_bin%';
+---------------------------------+----------------------------------+
| Variable_name                   | Value                            |
+---------------------------------+----------------------------------+
| log_bin                         | ON                               |
| log_bin_basename                | /var/lib/mysql/atguigu-bin       |
| log_bin_index                   | /var/lib/mysql/atguigu-bin.index |
| log_bin_trust_function_creators | OFF                              |
| log_bin_use_v1_row_events       | OFF                              |
| sql_log_bin                     | ON                               |
+---------------------------------+----------------------------------+
6 rows in set (0.00 sec)

设置带文件夹的 bin-log 日志存放目录

如果想改变日志文件的目录和名称,可以对 my.cnf 或 my.ini 中的 log_bin 参数修改如下:

[mysqld]
log-bin="/var/lib/mysql/binlog/atguigu-bin"

注意:新建的文件夹需要使用 mysql 用户,使用下面的命令即可。

chown -R -v mysql:mysql binlog

重启 MySQL 服务之后,新的二进制日志文件将出现在 /var/lib/mysql/binlog/ 目录下面:

mysql> SHOW VARIABLES LIKE '%log_bin%';
+---------------------------------+-----------------------------------------+
| Variable_name                   | Value                                   |
+---------------------------------+-----------------------------------------+
| log_bin                         | ON                                      |
| log_bin_basename                | /var/lib/mysql/binlog/atguigu-bin       |
| log_bin_index                   | /var/lib/mysql/binlog/atguigu-bin.index |
| log_bin_trust_function_creators | ON                                      |
| log_bin_use_v1_row_events       | OFF                                     |
| sql_log_bin                     | ON                                      |
+---------------------------------+-----------------------------------------+
6 rows in set (0.01 sec)

[root@node01 ~]# ll /var/lib/mysql/binlog/
total 8
-rw-r----- 1 mysql mysql 157 Dec  9 01:42 atguigu-bin.000001
-rw-r----- 1 mysql mysql  41 Dec  9 01:42 atguigu-bin.index

提示:

数据库文件最好不要与日志文件放在同一个磁盘上!这样,当数据库文件所在的磁盘发生故障时,可以使用日志文件恢复数据。

方式 2:临时性方式

如果不希望通过修改配置文件并重启的方式设置二进制日志的话,还可以使用如下指令,需要注意的是在 mysql8 中只有 会话级别 的设置,没有了 global 级别的设置。

# global 级别
mysql> set global sql_log_bin=0;
ERROR 1228 (HY000): Variable 'sql_log_bin' is a SESSION variable and can`t be used
with SET GLOBAL

# session级别
mysql> SET sql_log_bin=0;
Query OK, 0 rows affected (0.01 秒)

14.5.3、查看日志

当 MySQL 创建二进制日志文件时,先创建一个以 filename 为名称、以 .index 为后缀的文件,再创建一个以 filename 为名称、以 .000001 为后缀的文件。

MySQL 服务 重新启动一次,以 .000001 为后缀的文件就会增加一个,并且后缀名按 1 递增。即日志文件的个数与 MySQL 服务启动的次数相同;如果日志长度超过了 max_binlog_size 的上限(默认是 1GB),就会创建一个新的日志文件。

查看当前的二进制日志文件列表及大小。指令如下:

mysql> SHOW BINARY LOGS;
+--------------------+-----------+-----------+
| Log_name           | File_size | Encrypted |
+--------------------+-----------+-----------+
| atguigu-bin.000001 | 156       | No        |
+--------------------+-----------+-----------+
1 行于数据集 (0.02 秒)

所有对数据库的修改都会记录在 binlog 中。但 binlog 是二进制文件,无法直接查看,想要更直观的观测它就要借助 mysqlbinlog 命令工具了。指令如下:在查看执行,先执行一条 SQL 语句,如下:

update student set name='张三_back' where id=1;

开始查看 binlog:

[root@node01 ~]# mysqlbinlog /var/lib/mysql/binlog/atguigu-bin.000001 
# The proper term is pseudo_replica_mode, but we use this compatibility alias
# to make the statement usable on server versions 8.0.24 and older.
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#221209  1:42:17 server id 1  end_log_pos 126 CRC32 0xa4589fd5  Start: binlog v 4, server v 8.0.30 created 221209  1:42:17 at startup
# Warning: this binlog is either in use or was not closed properly.
ROLLBACK/*!*/;
BINLOG '
+SGSYw8BAAAAegAAAH4AAAABAAQAOC4wLjMwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAD5IZJjEwANAAgAAAAABAAEAAAAYgAEGggAAAAICAgCAAAACgoKKioAEjQA
CigAAdWfWKQ=
'/*!*/;
# at 126
#221209  1:42:17 server id 1  end_log_pos 157 CRC32 0xea311179  Previous-GTIDs
# [empty]
# at 157
#221209  2:48:13 server id 1  end_log_pos 236 CRC32 0xd5a6e1f4  Anonymous_GTID  last_committed=0      sequence_number=1 rbr_only=yes    original_committed_timestamp=1670525293122171   immediate_commit_timestamp=1670525293122171 transaction_length=349
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
# original_commit_timestamp=1670525293122171 (2022-12-09 02:48:13.122171 CST)
# immediate_commit_timestamp=1670525293122171 (2022-12-09 02:48:13.122171 CST)
/*!80001 SET @@session.original_commit_timestamp=1670525293122171*//*!*/;
/*!80014 SET @@session.original_server_version=80030*//*!*/;
/*!80014 SET @@session.immediate_server_version=80030*//*!*/;
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 236
#221209  2:48:13 server id 1  end_log_pos 326 CRC32 0x294f74e1  Query   thread_id=9 exec_time=0   error_code=0
SET TIMESTAMP=1670525293/*!*/;
SET @@session.pseudo_thread_id=9/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=1168113696/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8mb4 *//*!*/;
SET @@session.character_set_client=255,@@session.collation_connection=255,@@session.collation_server=255/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
/*!80011 SET @@session.default_collation_for_utf8mb4=255*//*!*/;
BEGIN
/*!*/;
# at 326
#221209  2:48:13 server id 1  end_log_pos 394 CRC32 0x1f704963  Table_map: `atguigudb1`.`student` mapped to number 95
# at 394
#221209  2:48:13 server id 1  end_log_pos 475 CRC32 0xe77e5a18  Update_rows: table id 95 flags: STMT_END_F

BINLOG '
bTGSYxMBAAAARAAAAIoBAAAAAF8AAAAAAAEACmF0Z3VpZ3VkYjEAB3N0dWRlbnQAAwMPDwQ8AB4A
BgEBAAIBIWNJcB8=
bTGSYx8BAAAAUQAAANsBAAAAAF8AAAAAAAEAAgAD//8AAQAAAAblvKDkuIkG5LiA54+tAAEAAAAN
5byg5LiJX2JhY2t1cAbkuIDnj60YWn7n
'/*!*/;
# at 475
#221209  2:48:13 server id 1  end_log_pos 506 CRC32 0x30efa4cc  Xid = 23
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*/;

执行结果可以看到,这是一个简单的日志文件,日志中记录了用户的一些操作,这里并没有出现具体的 SQL 语句,这是因为 binlog 关键字 后面的内容是经过编码后的 二进制日志

这里一个 update 语句包含如下事件:

  • Query 事件:负责开始一个事务(BEGIN)。
  • Table_map 事件:负责映射需要的表。
  • Update_rows 事件:负责写入数据。
  • Xid 事件:负责结束事务。

下面命令将行事件以 伪 SQL 的形式 表现出来:

[root@node01 ~]# mysqlbinlog -v "/var/lib/mysql/binlog/atguigu-bin.000001" 
......
BINLOG '
bTGSYxMBAAAARAAAAIoBAAAAAF8AAAAAAAEACmF0Z3VpZ3VkYjEAB3N0dWRlbnQAAwMPDwQ8AB4A
BgEBAAIBIWNJcB8=
bTGSYx8BAAAAUQAAANsBAAAAAF8AAAAAAAEAAgAD//8AAQAAAAblvKDkuIkG5LiA54+tAAEAAAAN
5byg5LiJX2JhY2t1cAbkuIDnj60YWn7n
'/*!*/;
### UPDATE `atguigudb1`.`student`
### WHERE
###   @1=1
###   @2='张三'
###   @3='一班'
### SET
###   @1=1
###   @2='张三_backup'
###   @3='一班'
# at 475
#221209  2:48:13 server id 1  end_log_pos 506 CRC32 0x30efa4cc  Xid = 23
COMMIT/*!*/;
SET @@SESSION.GTID_NEXT= 'AUTOMATIC' /* added by mysqlbinlog */ /*!*/;
DELIMITER ;
......

前面的命令同时显示 binlog 格式的语句,使用如下命令不显示它:

[root@node01 ~]# mysqlbinlog -v --base64-output='DECODE-ROWS' "/var/lib/mysql/binlog/atguigu-bin.000001"

关于 mysqlbinlog 工具的使用技巧还有很多,例如只解析对某个库的操作或者某个时间段内的操作等。简单分享几个常用的语句,更多操作可以参考官方文档

# 可查看参数帮助
mysqlbinlog --no-defaults --help

# 查看最后100行
mysqlbinlog --no-defaults --base64-output=decode-rows -vv atguigu-bin.000002 |tail -100

# 根据position查找
mysqlbinlog --no-defaults --base64-output=decode-rows -vv atguigu-bin.000002 |grep -A 20 '4939002'

上面这种办法读取出 binlog 日志的全文内容比较多,不容易分辨查看到 pos 点信息,下面介绍一种更为方便的查询命令:

mysql> show binlog events [IN 'log_name'] [FROM pos] [LIMIT [offset,] row_count];
  • IN 'log_name':指定要查询的 binlog 文件名(不指定就是第一个 binlog 文件)。
  • FROM pos:指定从哪个 pos 起始点开始查起(不指定就是从整个文件首个 pos 点开始算)。
  • LIMIT [offset]:偏移量(不指定就是 0)。
  • row_count:查询总条数(不指定就是所有行)。
mysql> show binlog events in 'atguigu-bin.000001';
+--------------------+-----+----------------+-----------+-------------+--------------------------------------+
| Log_name           | Pos | Event_type     | Server_id | End_log_pos | Info                                 |
+--------------------+-----+----------------+-----------+-------------+--------------------------------------+
| atguigu-bin.000001 |   4 | Format_desc    |         1 |         126 | Server ver: 8.0.30, Binlog ver: 4    |
| atguigu-bin.000001 | 126 | Previous_gtids |         1 |         157 |                                      |
| atguigu-bin.000001 | 157 | Anonymous_Gtid |         1 |         236 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' |
| atguigu-bin.000001 | 236 | Query          |         1 |         326 | BEGIN                                |
| atguigu-bin.000001 | 326 | Table_map      |         1 |         394 | table_id: 95 (atguigudb1.student)    |
| atguigu-bin.000001 | 394 | Update_rows    |         1 |         475 | table_id: 95 flags: STMT_END_F       |
| atguigu-bin.000001 | 475 | Xid            |         1 |         506 | COMMIT /* xid=23 */                  |
+--------------------+-----+----------------+-----------+-------------+--------------------------------------+
7 rows in set (0.00 sec)

上面这条语句可以将指定的 binlog 日志文件,分成有效事件行的方式返回,并可使用 limit 指定 pos 点的起始偏移查询条数。其它举例:

# a、查询第一个最早的binlog日志:
show binlog events\G;

# b、指定查询mysql-bin.000002这个文件:
show binlog events in 'atguigu-bin.000002'\G;

# c、指定查询mysql-bin.000002这个文件,从pos点391开始查起:
show binlog events in 'atguigu-bin.000002' from 391\G;

# d、指定查询mysql-bin.000002这个文件,从pos点391开始查起,查询5条(即5条语句):
show binlog events in 'atguigu-bin.000002' from 391 limit 5\G;

# e、指定查询mysql-bin.000002这个文件,从pos点391开始查起,偏移2行(即中间跳过2个),查询5条(即5条语句):
show binlog events in 'atguigu-bin.000002' from 391 limit 2,5\G;

上面我们讲了这么多都是基于 binlog 的默认格式,binlog 格式查看:

mysql> show variables like 'binlog_format';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| binlog_format | ROW   |
+---------------+-------+
1 row in set (0.00 sec)

除此之外,binlog 还有 2 种格式,分别是 StatementMixed

  • Statement

    每一条会修改数据的 sql 都会记录在 binlog 中。

    优点:不需要记录每一行的变化,减少了 binlog 日志量,节约了 IO,提高性能。

  • Row

    5.1.5 版本的 MySQL 才开始支持 row level 的复制,它不记录 sql 语句上下文相关信息,仅保存哪条记录被修改。

    优点:row level 的日志内容会非常清楚的记录下每一行数据修改的细节。而且不会出现某些特定情况下的存储过程,或 function,以及 trigger 的调用和触发无法被正确复制的问题。

  • Mixed

    从 5.1.8 版本开始,MySQL 提供了 Mixed 格式,实际上就是 Statement 与 Row 的结合。

14.5.4、使用日志恢复数据

如果 MySQL 服务器启用了二进制日志,在数据库出现意外丢失数据时,可以使用 MySQLbinlog 工具从指定的时间点开始(例如,最后一次备份)直到现在或另一个指定的时间点的日志中恢复数据。

mysqlbinlog 恢复数据的语法如下:

mysqlbinlog [option] filename|mysql –uuser -ppass;

这个命令可以这样理解:使用 mysqlbinlog 命令来读取 filename 中的内容,然后使用 mysql 命令将这些内容恢复到数据库中。

  • filename:是日志文件名。
  • option:可选项,比较重要的两对 option 参数是 --start-date--stop-date--start-position-- stop-position
    • --start-date --stop-date:可以指定恢复数据库的起始时间点和结束时间点。
    • --start-position--stop-position:可以指定恢复数据的开始位置和结束位置。

注意:使用 mysqlbinlog 命令进行恢复操作时,必须是编号小的先恢复,例如 atguigu-bin.000001 必须在 atguigu-bin.000002 之前恢复。

14.5.5、删除二进制日志

MySQL 的二进制文件可以配置自动删除,同时 MySQL 也提供了安全的手动删除二进制文件的方法。PURGE MASTER LOGS 只删除指定部分的二进制日志文件,RESET MASTER 删除所有的二进制日志文件。具体如下:

14.5.5.1、PURGE MASTER LOGS

删除指定日志文件,PURGE MASTER LOGS 语法如下:

PURGE {MASTER | BINARY} LOGS TO ‘指定日志文件名’
PURGE {MASTER | BINARY} LOGS BEFORE ‘指定日期’

举例:使用 PURGE MASTER LOGS 语句删除创建时间比 binlog.000005 早的所有日志。

  1. 多次重新启动 MySQL 服务,便于生成多个日志文件。然后用 SHOW 语句显示二进制日志文件列表。

    SHOW BINARY LOGS;
  2. 执行 PURGE MASTER LOGS 语句删除创建时间比 binlog.000005 早的所有日志。

    PURGE MASTER LOGS TO "binlog.00005";
  3. 显示二进制日志文件列表。

    SHOW BINARY LOGS;

比 binlog.000005 早的所有日志文件都已经被删除了。

举例:使用 PURGE MASTER LOGS 语句删除 2020 年 10 月 25 号前创建的所有日志文件。具体步骤如下:

  1. 显示二进制日志文件列表。

    SHOW BINARY LOGS;
  2. 执行 mysqlbinlog 命令查看二进制日志文件 binlog.000005 的内容。

    mysqlbinlog --no-defaults "/var/lib/mysql/binlog/atguigu-bin.000005"

    结果可以看出 20220105 为日志创建的时间,即 2022 年 1 月 05 日。

  3. 使用 PURGE MASTER LOGS 语删除 2022 年 1 月 05 日前创建的所有日志文件。

    PURGE MASTER LOGS before "20220105";
  4. 显示二进制日志文件列表。

    SHOW BINARY LOGS;

    2022 年 01 月 05 号之前的二进制日志文件都已经被删除,最后一个没有删除,是因为当前在用,还未记录最后的时间,所以未被删除。

14.5.5.2、RESET MASTER

使用 RESET MASTER 语句,清空所有的 binlog 日志。MySQL 会重新创建二进制文件,新的日志文件扩展名将重新从 000001 开始编号。慎用!

举例:使用 RESET MASTER 语句删除所有日志文件。

  1. 重启 MySQL 服务若干次,执行 SHOW 语句显示二进制日志文件列表。

    SHOW BINARY LOGS;
  2. 执行 RESET MASTER 语句,删除所有日志文件。

    RESET MASTER;

    执行完该语句后,原来的所有二进制日志已经全部被删除。

14.5.6、其它场景

二进制日志可以通过数据库的 全量备份 和二进制日志中保存的 增量信息,完成数据库的 无损失恢复。但是,如果遇到数据量大、数据库和数据表很多(比如分库分表的应用)的场景,用二进制日志进行数据恢复,是很有挑战性的,因为起止位置不容易管理。

在这种情况下,一个有效的解决办法是 配置主从数据库服务器,甚至是 一主多从 的架构,把二进制日志文件的内容通过中继日志,同步到从数据库服务器中,这样就可以有效避免数据库故障导致的数据异常等问题。

14.6、深入二进制日志(binlog)

14.6.1、写入机制

binlog 的写入时机也非常简单,事务执行过程中,先把日志写到 binlog cache,事务提交的时候,再把 binlog cache 写到 binlog 文件中。因为一个事务的 binlog 不能被拆开,无论这个事务多大,也要确保一次性写入,所以系统会给每个线程分配一个块内存作为 binlog cache。

我们可以通过 binlog_cache_size 参数控制单个线程 binlog cache 大小,如果存储内容超过了这个参数,就要暂存到磁盘(Swap)。binlog 日志刷盘流程如下:

mysql_binlog_cache

  • 上图的 write,是指把日志写入到文件系统的 page cache,并没有把数据持久化到磁盘,所以速度比较快。
  • 上图的 fsync,才是将数据持久化到磁盘的操作。

write 和 fsync 的时机,可以由参数 sync_binlog 控制,默认是 0。为 0 的时候,表示每次提交事务都只 write,由系统自行判断什么时候执行 fsync。虽然性能得到提升,但是机器宕机,page cache 里面的 binglog 会丢失。如下图:

mysql_binlog_cache_sync

为了安全起见,可以设置为 1,表示每次提交事务都会执行 fsync,就如同 redo log 刷盘流程 一样。最后还有一种折中方式,可以设置为 N(N>1),表示每次提交事务都 write,但累积 N 个事务后才 fsync。

mysql_binlog_cache_sync_compromise

在出现 IO 瓶颈的场景里,将 sync_binlog 设置成一个比较大的值,可以提升性能。同样的,如果机器宕机,会丢失最近 N 个事务的 binlog 日志。

14.6.2、binlog 与 redolog 对比

  • redo log 它是 物理日志,记录内容是 在某个数据页上做了什么修改,属于 InnoDB 存储引擎层产生的。
  • 而 binlog 是 逻辑日志,记录内容是语句的原始逻辑,类似于 给 ID=2 这一行的 c 字段加 1,属于 MySQL Server 层。
  • 虽然它们都属于持久化的保证,但是侧重点不同。
    • redo log 让 InnoDB 存储引擎拥有了崩溃恢复能力。
    • binlog 保证了 MySQL 集群架构的数据一致性。

14.6.3、两阶段提交

在执行更新语句过程,会记录 redo log 与 binlog 两块日志,以基本的事务为单位,redo log 在事务执行过程中可以不断写入,而 binlog 只有在提交事务时才写入,所以 redo log 与 binlog 的 写入时机 不一样。

mysql_binlog_redolog

redo log 与 binlog 两份日志之间的逻辑不一致,会出现什么问题

以 update 语句为例,假设 id=2 的记录,字段 c 值是 0,把字段 c 值更新为 1,SQL 语句为 update T set c = 1 where id = 2。

假设执行过程中写完 redo log 日志后,binlog 日志写期间发生了异常,会出现什么情况呢?

mysql_binlog_redolog_1

由于 binlog 没写完就异常,这时候 binlog 里面没有对应的修改记录。因此,之后用 binlog 日志恢复数据时,就会少这一次更新,恢复出来的这一行 c 值为0,而原库因为 redo log 日志恢复,这一行 c 的值是1,最终数据不一致。

mysql_binlog_redolog_2

为了解决两份日志之间的逻辑一致问题,InnoDB 存储引擎使用两阶段提交方案。原理很简单,将 redo log 的写入拆成了两个步骤 prepare 和 commit,这就是两阶段提交

mysql_binlog_redolog_3

使用两阶段提交后,写入 binlog 时发生异常也不会有影响,因为 MySQL 根据 redo log 日志恢复数据时,发现 redo log 还处于 prepare 阶段,并且没有对应 binlog 日志,就会回滚该事务。

mysql_binlog_redolog_4

另一个场景,redo log 设置 commit 阶段发生异常,那会不会回滚事务呢?

mysql_binlog_redolog_5

并不会回滚事务,它会执行上图框住的逻辑,虽然 redo log 是处于 prepare 阶段,但是能通过事务 id 找到对应的 binlog 日志,所以 MySQL 认为是完整的,就会提交事务恢复数据。

14.7、中继日志(relay log)

14.7.1、介绍

中继日志只在主从服务器架构的从服务器上存在

从服务器为了与主服务器保持一致,要从主服务器读取二进制日志的内容,并且把读取到的信息写入 本地的日志文件 中,这个从服务器本地的日志文件就叫 中继日志

然后,从服务器读取中继日志,并根据中继日志的内容对从服务器的数据进行更新,完成主从服务器的数据同步。

搭建好主从服务器之后,中继日志默认会保存在从服务器的数据目录下。

文件名的格式是: 从服务器名-relay-bin.序号。中继日志还有一个索引文件:从服务器名-relay-bin.index,用来定位当前正在使用的中继日志。

14.7.2、查看中继日志

中继日志与二进制日志的格式相同,可以用 mysqlbinlog 工具进行查看。下面是中继日志的一个片段:

SET TIMESTAMP=1618558728/*!*/;
BEGIN
/*!*/;
# at 950
#210416 15:38:48 server id 1 end_log_pos 832 CRC32 0xcc16d651 Table_map:
`atguigu`.`test` mapped to number 91
# at 1000
#210416 15:38:48 server id 1 end_log_pos 872 CRC32 0x07e4047c Delete_rows: table id
91 flags: STMT_END_F -- server id 1 是主服务器,意思是主服务器删了一行数据
BINLOG '
CD95YBMBAAAAMgAAAEADAAAAAFsAAAAAAAEABGRlbW8ABHRlc3QAAQMAAQEBAFHWFsw=
CD95YCABAAAAKAAAAGgDAAAAAFsAAAAAAAEAAgAB/wABAAAAfATkBw==
'/*!*/;
# at 1040

这一段的意思是,主服务器(server id 1)对表 atguigu.test 进行了 2 步操作:

定位到表 atguigu.test 编号是 91 的记录,日志位置是 832;
删除编号是 91 的记录,日志位置是 872

14.7.3、恢复的典型错误

如果从服务器宕机,有的时候为了系统恢复,要重装操作系统,这样就可能会导致你的 服务器名称 与之前 不同。而中继日志里是 包含从服务器名 的。在这种情况下,就可能导致你恢复从服务器的时候,无法从宕机前的中继日志里读取数据,以为是日志文件损坏了,其实是名称不对了。

解决的方法也很简单,把从服务器的名称改回之前的名称。

标签云