写在前面的话

 

日志是作为用户排查服务问题的重要依据,在 MySQL 中日志可以分为几类,各自产生着不同的作用。如 error log / bin log / slow log 等。很多时候优化数据库的优化来源就是日志。

 

 

错误日志(error log)

 

查看错误日志:



select @@log_error;



结果:

MYSQL general日志加密 mysql日志管理_MYSQL general日志加密

包含启动关闭以及运行中的警告和错误信息。

可以通过 my.cnf 中两个配置就行管理:



log-error=/data/logs/mysql/error.log
log_timestamps=system



 

  

二进制日志(bin log)

 

二进制日志的作用:

1. 备份恢复需要用到,特别是故障恢复,否则数据可能不完整。

2. 主从环境依赖于二进制日志。

 

在 MySQL 5.7 中,bin log 配置必须要有 server_id 配置。默认不开启。

查看二进制日志配置:



select @@log_bin;



结果:

MYSQL general日志加密 mysql日志管理_开发工具_02

也可以 show 查看:



show variables like "%log_bin%";



结果:

MYSQL general日志加密 mysql日志管理_运维_03

 

开启 bin log:

1. 创建目录:



mkdir -p /data/logs/mysql/binlog
chown mysql.mysql /data/logs/mysql/binlog



 

2. 添加配置:/etc/my.cnf



server_id=111
log_bin=/data/logs/mysql/binlog/mysql-bin
binlog_format=row



mysql-bin 不是目录,而是生成日志的前缀。binlog_format 其实可以不用设置,默认就是这个。

 

3. 重启数据库便可以看到生成的 bin log 文件:

MYSQL general日志加密 mysql日志管理_MYSQL general日志加密_04

 

关于 bin log:

1. bin log 只记录变更的 SQL 语句而不记录 select。

2. DDL 和 DCL 语句会原封不动的记录到 bin log 中。

3. DML 只记录已经提交的事务。

 

之前配置文件中配置了 binlog_format,包含三个值:

statement:5.6 默认,SBR,语句原封不动的记录到 bin log。可读性好,日志少,但数据不一定准确,比如 now() 这种函数。

row:5.7 默认,RBR,记录数据行变化,可读性差,日志大,但是数据准确。

mixed:MBR,混合前两种。

 

event 事件:

event 是 bin log 的最小记录单元,对于 DCL 和 DDL,一个语句就是一个 event。但是 DML 则已经提交的事务才是 event。如:



begin;
sql 1;
sql 2;
commit;



由于 commit 了,所以这是 4 个 event。同时每个事件拥有自己的标识:开始 at,结束 end_log_pos。

 

开启 bin log 之后可以完整的查看 bin log 的信息:



show variables like "%log_bin%";



结果:

MYSQL general日志加密 mysql日志管理_开发工具_05

可以看到 bin log 保存的地方。mysql-bin.index 用于记录当前使用的 bin log 是哪一个。可用去目录里面查看:



cat mysql-bin.index



结果:

MYSQL general日志加密 mysql日志管理_数据库_06

 

查看 / 刷新当前 bin log:



-- 查看
show binary logs;
-- 刷新
flush logs;



结果:

MYSQL general日志加密 mysql日志管理_数据库_07

 

查看当前数据库正在使用的 bin log 是哪个:



show master status;



结果:

MYSQL general日志加密 mysql日志管理_MYSQL general日志加密_08

需要知道的是,由于上面使用 flush logs,重新生成了 bin log,所以除了当前使用的 bin log 以外,其它的是没用的。

Position 就是 event 事件的结束指针,这个意味着在后面的恢复中可以通过指针来确定恢复点。

 

查看 bin log:文件是二进制文件,不能直接打开,需要专门的工具或者 sql 查看



show binlog events in "mysql-bin.000003";



结果:

MYSQL general日志加密 mysql日志管理_运维_09

这里先创建一个数据库,否则由于是后面添加的 bin log,我们还没有执行过什么语句,可能就只有系统默认的信息。

可以知道的是,在 MySQL 5.7 中,bin log 的默认指针是从 4 开始的。到 154 结束都是系统的信息。

前一个结束的指针值会成为后一个事件的指针开始值。可以清晰的找到创建数据库的语句,从 219 - 337 指针。前面那个 SET 是系统打印的。

以为这不是 DML 语句,所以可以直接读取。

当然,如果直接在数据库中打开其实不便于数据处理,比如筛选这些,可以在 MySQL 非交互命令行打开:



mysql -uroot -p -e "show binlog events in 'mysql-bin.000003';" | grep "create"



可以直接筛选某个:

MYSQL general日志加密 mysql日志管理_开发工具_10

当然,这并不是最终想要的查看方式,比较想通过这种方式恢复指定数据太难了。

 

MySQL 提供了另外一种读取 bin log 的方法:



mysqlbinlog --no-defaults /data/logs/mysql/binlog/mysql-bin.000003



这里多加了个 --no-defaults 参数,以为配置文件有:prompt=3306/\u [\d]> 配置,无法识别,会报错:



mysqlbinlog: [ERROR] unknown variable 'prompt=3306/\u [\d]>'



同样的,还有其它参数也会引起类似的报错,所以可以考虑添加这个参数查看。

MYSQL general日志加密 mysql日志管理_运维_11

在该文件中可以看到指针 position,也能见到其它的 SQL。

 

此时可以添加事务再度查看:

MYSQL general日志加密 mysql日志管理_mysql_12

查看 bin log:



mysqlbinlog --no-defaults /data/logs/mysql/binlog/mysql-bin.000005



结果:

MYSQL general日志加密 mysql日志管理_数据库_13

可以看到事务中会有很多看不懂的符号,可以进行解码:



mysqlbinlog --no-defaults --base64-output=decode-rows -vvv /data/logs/mysql/binlog/mysql-bin.000005



这里的 vvv 随便你几个 v,不影响:

MYSQL general日志加密 mysql日志管理_mysql_14

随便查看一个 insert,也只能看懂一半,但是没关系,数据库能够识别就行。

也可以单独只看某个数据库的操作,这样有助于在多个库的情况下,根据 bin log 恢复某个库:



mysqlbinlog --no-defaults --base64-output=decode-rows -vvv -d testdb1 /data/logs/mysql/binlog/mysql-bin.000005



通过 -d参数指定数据库,此时得到的数据就是单个数据库的。

 

除此之外,还可以通过开始指针和结束指针截取,参数如:



--start-position=219 --stop-position=1347



 

也可以通过开始事件和结束时间:



--start-datetime='2019-08-27 17:00:00' --stop-datetime='2019-08-27 17:01:00'



最后只需要将截取出来的内容重定向到 sql 文件中即可在数据库中导入使用。

最后就是在截取中间的部分行的时候,可以使用:from limit

 

 

bin log 恢复数据库示例

 

1. 新建数据库插入数据,然后删除:

MYSQL general日志加密 mysql日志管理_mysql_15

 

2. 查看目前使用的 bin log 是哪个:



show master status;



结果:

MYSQL general日志加密 mysql日志管理_数据库_16

 

3. 由于不想全库恢复,只想恢复 testdb2,所以需要先抽取出 testdb2 的 SQL:



mysqlbinlog --no-defaults -d testdb2 /data/logs/mysql/binlog/mysql-bin.000005 >/tmp/bin.sql



这里不需要解码,以为我们本身就是给数据库读取的。

 

4. 由于这个 SQL 里面还是存在 drop,所以需要将这个 drop 干掉:



sed -i 's#drop database testdb2##g' /tmp/bin.sql



使用 sed 直接替换掉为空! 

 

5. 导入数据:在数据库中执行以下 SQL



source /tmp/bin.sql



结果:

MYSQL general日志加密 mysql日志管理_运维_17

数据全部恢复回来,由于上面 sed 了语句,恢复过程中可能最后会有点错误,不用理会。

总结:在生产中值得注意的是,我们应该在测试数据库中对数据进行恢复,然后再导出 SQL 到线上执行。这是规范。另外,在恢复大量数据的时候,可以在数据库里面执行 set sql_log_bin=0; 然后再 source,这样当前窗口恢复过程就不用再度写 bin log 了,还可以提升性能。

 

 

bin log 中的 GTID

 

GTID (Global Transaction ID)属于 5.6 版本中加入的特性,在 5.7 版本中得以增强。但是在 5.6 版本中需要手动开启。5.7 版本会自动生成。

在 bin log 中可以看到,但并未用到它:



SET @@SESSION.GTID_NEXT= 'ANONYMOUS'



 

在配置文件中开启 GTID:my.cnf



gtid-mode=on
enforce-gtid-consistency=true



重启数据库生效!

 

此时插入数据测试:



use testdb2;
insert into t1 values(4, "老张");
commit;



 

查看 bin log 状态:



show master status;



结果:

MYSQL general日志加密 mysql日志管理_mysql_18

此时可以看到在 Executed_Gtid_Set 项多了以下值:



8718822a-b440-11e9-9dbc-000c29ed1116:1



冒号前面的是数据库初始化的 server_uuid,后面的就是一个标记,类似之前的指针 position。uuid 可以在 /data/data/mysql/auto.cnf 中看到。

 

查看 bin log:



show binlog events in "mysql-bin.000006";



如图:

MYSQL general日志加密 mysql日志管理_数据库_19

可以看到上面的 SET 变成了这个!在 bin log 中,GTID 提供了一种更容易的恢复方式!

但是值得注意的是,由于 MySQL 在恢复的时候,对于数据库中存在的 GTID 值,会选择跳过。所以需要一些额外的参数。

 

 

GTID 数据恢复示例

 

1. 首先模拟线上业务:

MYSQL general日志加密 mysql日志管理_MYSQL general日志加密_20

中间误删除了数据,最后直接整个库都干掉了。



create database testdb4 charset="utf8";
use testdb4;
create table t1 (id int(4),name varchar(10));
insert into t1 values (1,"张三");
insert into t1 values (2,"李四");
insert into t1 values (3,"王五");
commit;
delete from t1 where id=3;
commit;
insert into t1 values (4,"老张");
insert into t1 values (5,"老李");
insert into t1 values (6,"老王");
commit;
create database testdb5 charset="utf8";
drop database testdb4;



 

2. 查看 bin log:



show binlog events in "mysql-bin.000007";



找到创建数据库时候的 GTID 值:

MYSQL general日志加密 mysql日志管理_运维_21

我这里是 16,同时找到删库的 GTID 值:

MYSQL general日志加密 mysql日志管理_数据库_22

这意味着从建库到删库,整个 GTID 值范围为 16 - 26。

当然,也可以通过指定数据库的 binlog 来查找:



mysqlbinlog --no-defaults -d testdb4 /data/logs/mysql/binlog/mysql-bin.000007



 

3. 我们知道了范围,但是其中又包含了误删数据的语句,所以还得通过 mysqlbinlog 命令找到误删数据的 GTID 值:



mysqlbinlog --no-defaults -d testdb4 --base64-output=decode-rows -vvv /data/logs/mysql/binlog/mysql-bin.000007 > /tmp/1.txt



将 bin log 导出到文件,便于查找:

MYSQL general日志加密 mysql日志管理_数据库_23

这是通过将 bin log 导出到文件,使用 vim 进行查找找到的,使用 show 看不出来,直接 mysqlbinlog 查看又不好找。

于是知道了本次需要恢复的范围:16 - 25,因为 26 是删库,还需要排除 21。

 

4. 将导出成 SQL:



mysqlbinlog --no-defaults -d testdb4 --include-gtids="8718822a-b440-11e9-9dbc-000c29ed1116:16-25" --exclude-gtids="8718822a-b440-11e9-9dbc-000c29ed1116:21" --skip-gtids /data/logs/mysql/binlog/mysql-bin.000007 > /tmp/gtid_bin.sql



参数说明: 

--include-gtids:指出 GTID 的范围,可以使用 - 表示范围。

--exclude-gtids:排除 GTID,多个需要逗号隔开。

--skip-gtids:之前说过 MySQL 会跳过已经执行过的 GTID,所以需要这个参数让他重新生成 GTID,否则无法恢复。

 

5. 进入数据库恢复查看:记得临时关闭当前会话的 binlog 写入,提升恢复性能



set sql_log_bin=0;
source /tmp/gtid_bin.sql
set sql_log_bin=1;



查看:

MYSQL general日志加密 mysql日志管理_mysql_24

总结:其实整个过程和使用 positon 恢复差不多,GTID 在某些时候方便一些,因为只需要找到开始和结束 ID,再去掉中间不要的 ID,再 position 中去掉不要 ID 比较麻烦。

 

 

bin log 清理

 

在磁盘容量有限的情况下,需要对 bin log 进行定期清理,以保证资源的合理利用。其主要清理当时包括两种,自动和手动。

1. 自动清理:

MySQL 自己提供了一定的清理机制,可以通过 SQL 查看:



show variables like "%expire%";



默认为 0,代表永不清理:

MYSQL general日志加密 mysql日志管理_mysql_25

这个值的设置依据按照全备的周期来设计,比如每周全备一次,那么这个值可以设置为 8,周 + 1,这样就能够确保有两个 bin log。

企业建议保留两个以上,确保数据安全。也就是 全备周期 x 2 + 1

 

2. 手动清理:

这里的手动清理不是自己上服务器上面去 rm 文件,而是通过特定的 SQL 来删除:



-- 清除 3 天以前的
purge binary logs before now() - interval 3 day;
-- 清除 05 以前的
purge binary logs to 'mysql-bin.000005';



结果:

MYSQL general日志加密 mysql日志管理_运维_26

另外一种方法:

a. 修改 my.cnf 关闭 bin log 配置,然后重启 MySQL。

b. rm 删除所有 bin log 文件,然后 my.cnf 中开启 bin log 再度重启 MySQL。

此时再度查看:

MYSQL general日志加密 mysql日志管理_开发工具_27

重新生成的 bin log 再度从 1 开始计数。

最后一种方法:



reset master



生产环境千万不能执行,否则主从同步必崩。 

 

日志滚动更新:

触发新生成 bin log 文件的方法有:

1. 重启 MySQL 会写到新的文件。

2. 日志达到规定的大小:



select @@max_binlog_size;



默认一个 1G:

MYSQL general日志加密 mysql日志管理_mysql_28

3. 手动触发:



flush logs;



4. MySQL 备份时加入指定参数。

 

 

慢日志(slow log)

 

作用:记录数据库中执行慢的 SQL,默认没开启。

开启配置:

1. 新建日志目录:



mkdir /data/logs/mysql/slowlog
chown -R mysql.mysql /data/logs/mysql/slowlog



 

2. 在 my.cnf 中加入以下 4 个参数:



# 开启慢日志
slow_query_log=1
# 指定慢日志路径
slow_query_log_file=/data/logs/mysql/slowlog/slow.log
# 指定慢日志的最小执行时间,我这里2秒
long_query_time=2
# 记录不走索引的
log_queries_not_using_indexes=1



完成后重启 MySQL!

由于慢日志里面会记录所有的慢语句,这意味着会有很多重复或者类似的语句。可以通过 MySQL 自带的工具查看:



mysqldumpslow -s c -t 10 /data/logs/mysql/slowlog/slow.log



其中 -s c指定规则,按照出现的次数。-t 10 指排行前 10 的,也就是急需优化的。

除此之外,还要一些第三方工具,如 percona-toolkit 里面的 pt-query-diagest

后者可以结合 Anemometer 实现可视化操作。

 

 

小结

 

本章节超级重要,bin log 和 slow log 都是在生产中非常实用的东西,前者可能救我们的命,后者可能帮助我们优化业务。