写在前面的话
日志是作为用户排查服务问题的重要依据,在 MySQL 中日志可以分为几类,各自产生着不同的作用。如 error log / bin log / slow log 等。很多时候优化数据库的优化来源就是日志。
错误日志(error log)
查看错误日志:
select @@log_error;
结果:
包含启动关闭以及运行中的警告和错误信息。
可以通过 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;
结果:
也可以 show 查看:
show variables like "%log_bin%";
结果:
开启 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 文件:
关于 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%";
结果:
可以看到 bin log 保存的地方。mysql-bin.index 用于记录当前使用的 bin log 是哪一个。可用去目录里面查看:
cat mysql-bin.index
结果:
查看 / 刷新当前 bin log:
-- 查看
show binary logs;
-- 刷新
flush logs;
结果:
查看当前数据库正在使用的 bin log 是哪个:
show master status;
结果:
需要知道的是,由于上面使用 flush logs,重新生成了 bin log,所以除了当前使用的 bin log 以外,其它的是没用的。
Position 就是 event 事件的结束指针,这个意味着在后面的恢复中可以通过指针来确定恢复点。
查看 bin log:文件是二进制文件,不能直接打开,需要专门的工具或者 sql 查看
show binlog events in "mysql-bin.000003";
结果:
这里先创建一个数据库,否则由于是后面添加的 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 提供了另外一种读取 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]>'
同样的,还有其它参数也会引起类似的报错,所以可以考虑添加这个参数查看。
在该文件中可以看到指针 position,也能见到其它的 SQL。
此时可以添加事务再度查看:
查看 bin log:
mysqlbinlog --no-defaults /data/logs/mysql/binlog/mysql-bin.000005
结果:
可以看到事务中会有很多看不懂的符号,可以进行解码:
mysqlbinlog --no-defaults --base64-output=decode-rows -vvv /data/logs/mysql/binlog/mysql-bin.000005
这里的 vvv 随便你几个 v,不影响:
随便查看一个 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. 新建数据库插入数据,然后删除:
2. 查看目前使用的 bin log 是哪个:
show master status;
结果:
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
结果:
数据全部恢复回来,由于上面 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;
结果:
此时可以看到在 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";
如图:
可以看到上面的 SET 变成了这个!在 bin log 中,GTID 提供了一种更容易的恢复方式!
但是值得注意的是,由于 MySQL 在恢复的时候,对于数据库中存在的 GTID 值,会选择跳过。所以需要一些额外的参数。
GTID 数据恢复示例
1. 首先模拟线上业务:
中间误删除了数据,最后直接整个库都干掉了。
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 值:
我这里是 16,同时找到删库的 GTID 值:
这意味着从建库到删库,整个 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 导出到文件,便于查找:
这是通过将 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;
查看:
总结:其实整个过程和使用 positon 恢复差不多,GTID 在某些时候方便一些,因为只需要找到开始和结束 ID,再去掉中间不要的 ID,再 position 中去掉不要 ID 比较麻烦。
bin log 清理
在磁盘容量有限的情况下,需要对 bin log 进行定期清理,以保证资源的合理利用。其主要清理当时包括两种,自动和手动。
1. 自动清理:
MySQL 自己提供了一定的清理机制,可以通过 SQL 查看:
show variables like "%expire%";
默认为 0,代表永不清理:
这个值的设置依据按照全备的周期来设计,比如每周全备一次,那么这个值可以设置为 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';
结果:
另外一种方法:
a. 修改 my.cnf 关闭 bin log 配置,然后重启 MySQL。
b. rm 删除所有 bin log 文件,然后 my.cnf 中开启 bin log 再度重启 MySQL。
此时再度查看:
重新生成的 bin log 再度从 1 开始计数。
最后一种方法:
reset master
生产环境千万不能执行,否则主从同步必崩。
日志滚动更新:
触发新生成 bin log 文件的方法有:
1. 重启 MySQL 会写到新的文件。
2. 日志达到规定的大小:
select @@max_binlog_size;
默认一个 1G:
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 都是在生产中非常实用的东西,前者可能救我们的命,后者可能帮助我们优化业务。