mysql工具类日志(binlog、slowlog、errorlog)

mysql日志管理

参考https://www.jianshu.com/p/00c54d2832ed

日志设置

工具日志,不同于undo log(事务等)

错误日志(排错、主从错误)--log-error,默认打开,路径datadir/主机名.err,文本格式,重点关注[ERROR]

慢查询日志(优化)--slow_query_log、--long_query_time

二进制日志(主从)--log-bin、--expire-logs-days

目录授权chown -R mysql.mysql /tmp/{errlog,binlog}

一般会定制这些日志的路径,避免数据盘出错,日志也拿不到

查看错误日志路径:select @@log_error,默认应该在./主机名.err,我的在stderr

修改到mysql.mysql有权限的路径,在/etc/my.cnf的[mysqld]下添加log_error=自定义错误日志路径,如/tmp/errlog/mysql.err或mysql.log(自动创建文件),重启生效

二进制日志(binlog),sql层逻辑日志,记录sql语句操作,默认关闭

  • 主从复制依赖binlog
  • 数据恢复依赖binlog

开启,需要配置参数(/etc/my.cnf的[mysqld]),重启生效:

  • server_id= 主从复制用,但5.7开始,开启binlog需要配置server_id,1-65535

  • log_bin= 设置为1,打开binlog功能,生成在默认位置,也可以指定路径如/tmp/binlog/mysql-bin,会打开binglog功能,且按指定路径和名称前缀生存二进制日志,也可以单独设置log_bin和log_bin_basename参数

    其中/tmp/binlog是路径,必须mysql.mysql有权限

    mysql-bin是前缀,生成日志名称mysql-bin.000001,mysql-bin.000002等,mysql只能使用一个,关注编号最大那个,其他是历史文件(可以设置自动清除的策略),每次重启会生成并使用新的binlog,其中mysql-bin.index列出所有二进制日志文件名称,相当于索引

  • 上面2给参数必须设置,下面可选,binlog_format=row,5.7版本默认配置就是row,可以不设置

innodb_flush_log_at_trx_commit=0:每秒一次将Log Buffer中数据写入到Log File中,并且Flush到磁盘。事务提交不会主动触发写磁盘操作。
innodb_flush_log_at_trx_commit=1:每次事务提交时将Log Buffer数据写入到Log File中,并且Flush到磁盘。
innodb_flush_log_at_trx_commit=2:每次事务提交时将Log Buffer数据写入到Log File中,但不立即Flush到磁盘,MySQL会每秒一次刷新到磁盘。
由于进程调度问题,每条一次操作不能保证每一秒都执行一次。

当innodb_flush_log_at_trx_commit=0时,最近一秒的事务日志存在MySQL的Log Buffer中,无论时MySQL实例停止还是MySQL服务器宕机,都会导致最近一秒的事务日志丢失。
当innodb_flush_log_at_trx_commit=1时,最近一秒的事务日志存在操作系统的文件缓存中,MySQL实例停止不会导致事务日志丢失,但MySQL服务器宕机会导致最近一秒事务日志丢失。

上述的一秒一次刷新,取决于参数innodb_flush_log_at_timeout默认值为1,DDL或其他InnoDB内部操作并不受参数innodb_flush_log_at_trx_commit的限制。

二进制日志概述

二进制日志记录:变更类操作日志,DML增删改(数据)、DDL(增删改表)、DCL(修改权限)

DDL和DCL(如建表create database 库名、alter、drop等),以语句的方式原样记录

DML语句(增删改),记录已提交的事务的SQL语句(未提交或回滚的事务不记录),多种记录格式(statement、row、mixed),通过binlog_format=row参数控制(该参数只控制DML语句),建议使用row。

  • statement:SBR模式,语句模式,以SQL语句原样记录命令,可读性强。对于范围操作,日志量少,节省空间(如update t set name='test' where id > 10,SBR只有一条日志,RBR有多少行数据被更新就加多少条日志)。但SBR可能记录不准确,如时间函数,举例insert into t values (1,'test',now());在主从复制或备份还原以后时间字段的值不准确。
  • row:RBR模式,行模式,记录一行数据的变化(与redo log区别,redo log记录page页的变化),推荐使用,默认。特点,可读性较弱,范围操作日志量大,但是不会出现记录错误。高可用环境新型架构很多新特性依赖RBR模式,所以建议使用RBR模式。
  • mixed:MBR模式,混合模式,由mysql决定选择SBR还是RBR,不可控,不建议使用。

面试:SBR和RBR的区别,选择依据,看上面的笔记即可。

二进制日志的记录单元:

最小单元event,事件,了解了这些,方便有需要截取某些部分日志做数据恢复的需求,比如如删除某几条数据的恢复这种操作,需要知道截取哪些范围的event

不同类型的语句,事件不同

DDL、DCL以SQL形式记录,每个语句(操作)就是一个事件

DML(标准事务语句begin; 语句1;语句2;commit;,这里有4条语句,4个事件),一个事务包含多个语句,每条语句是一个事件

event事件的开始、结束号码(方便从日志中截取想要的event日志事件范围):

操作二进制文件

查找二进制日志是否开启及位置:从配置文件看,或执行show variables like '%log_bin%';

查看二进制日志文件列表:去log_bin的路径下看,或执行show binary logs;

执行flush logs;会滚动出一个新的日志,再执行show binary logs;就会新增加一个文件。

查看正在使用的二进制文件:show master status;

先做些操作记录事件:

create database binlog charset utf8mb4;

use binlog;

create table t1(id int);

insert into t1 values(1);

查看二进制日志的事件:

show master status;  查看使用的二进制日志文件
show binlog events in '文件名' [limit 10];  查看事件
mysql> show binlog events in 'mysql-bin.000001';
+------------------+-----+----------------+-----------+-------------+----------------------------------------+
| Log_name         | Pos | Event_type     | Server_id | End_log_pos | Info                                   |
+------------------+-----+----------------+-----------+-------------+----------------------------------------+
| mysql-bin.000001 |   4 | Format_desc    |         6 |         123 | Server ver: 5.7.26-log, Binlog ver: 4  |
| mysql-bin.000001 | 123 | Previous_gtids |         6 |         154 |                                        |
| mysql-bin.000001 | 154 | Anonymous_Gtid |         6 |         219 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS'   |
| mysql-bin.000001 | 219 | Query          |         6 |         335 | create database binlog charset utf8mb4 |
| mysql-bin.000001 | 335 | Anonymous_Gtid |         6 |         400 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS'   |
| mysql-bin.000001 | 400 | Query          |         6 |         501 | use `binlog`; create table t1(id int)  |
| mysql-bin.000001 | 501 | Anonymous_Gtid |         6 |         566 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS'   |
| mysql-bin.000001 | 566 | Query          |         6 |         640 | BEGIN                                  |
| mysql-bin.000001 | 640 | Table_map      |         6 |         687 | table_id: 108 (binlog.t1)              |
| mysql-bin.000001 | 687 | Write_rows     |         6 |         727 | table_id: 108 flags: STMT_END_F        |
| mysql-bin.000001 | 727 | Xid            |         6 |         758 | COMMIT /* xid=16 */                    |
+------------------+-----+----------------+-----------+-------------+----------------------------------------+
11 rows in set (0.00 sec)

其中前两行是二进制文件头格式,不用关心,第三行事件POS是154

每行一个事件,pos和end_log_pos是事件开始和结束的位置号码,上一个事件的结束位置是下一个事件的开始位置,开始和结束位置可以作为截取事件的依据,事务截取要从begin到commit才完整。

查看二进制日志文件(二进制格式,用工具查看),Linux下查看日志文件类型:file mysql-bin.000001(mysql复制日志)

[root@VM_0_4_centos ~]# file /tmp/binlog/mysql-bin.000001
/tmp/binlog/mysql-bin.000001: MySQL replication log

查看二进制日志内容:mysqlbinlog mysql-bin.000001;或mysqlbinlog mysql-bin.00001 | grep -v '^SET';不看SET开头的事件

@号码,这是一个事件开始的标志,从#@154开始看,那些SET的事件可以跳过不看,可以对照上面的事件查看结果来看,事件的第一行是注释,注明了事件发生时间

其中行模式记录的sql是base64编码的,要想以解码的方式看,-vvv是使结果更加详细,执行:

mysqlbinlog --base64-output=decode-rows -vvv mysql-bin.000001; 执行mysqlbinlog --help可以查看这些参数

# at 687
#200130 21:37:52 server id 6  end_log_pos 727 CRC32 0x209b53a6  Write_rows: table id 108 flags: STMT_END_F
### INSERT INTO `binlog`.`t1`
### SET
###   @1=1 /* INT meta=0 nullable=1 is_null=0 */

向binlog.t1插入数据,给第一列设置为1,多列分别为@1,@2...

截取二进制日志:

show binlog events in 'mysql-bin.000001';
mysqlbinlog --start-position=起始位置 --stop-position=结束位置 mysql-bin.000001 [ >/tmp/t1.sql];

查看并截取,其中前两行事件的记录依然存在,使用>可以将截取内容输出到sql文件,可以用于数据恢复。

position是事件在二进制文件中的字节占用的位置。

使用二进制日志进行数据恢复(source sql文件;)

误操作或故障以后做数据恢复

drop 库名 表名;删了表和库。

截取二进制日志从库创建到误删除之前的日志,保持为sql文件。

使用source导入sql文件,这部分不需要记录binlog,因为这些日志是从binlog截取的,再记录binlog,以后用binlog做全量恢复会出问题。使用set sql_log_bin=0;在当前会话中临时设置参数将binlog关闭,不影响其它会话,source命令执行完成以后,执行set sql_log_bin=1;修改回来

二进制日志恢复在数据恢复中必不可少,但是有弊端,如数据量大,时间长,只能作为辅助(使用备份+日志)。

若带过滤截取,只能截取某个库的(因为有use可以标识),不能截取某个表的(没有标识,截取较麻烦,如二次开发改写二进制记录的方式,对表的create和增删改操作加上标识):

mysqlbinlog -d 库名 mysql-bin.000001;

gtid模式(全局事务id)

5.6出现的,但不完善,5.7开始企业中建议将二进制日志文件改为gtid模式管理,某些高级功能新特性必须在RBR模式+gtid下才能使用

gtid之前按事件来组织二进制日志的内容,用事件起始、终止position去截取binlog

gtid之后,对binlog中的每个独立事务(不同于innodb的事务)生产一个gtid号码

ddl和dcl,如create database,一条语句就是一个事件event,就是一个事务,就有一个gtid号码

dml,从begin到commit才是一个事务,有一个gtid号码

gtid组成:server-uuid:TID,server-uuid是数据库第一次启动自动生成的,在数据目录下的auto.cnf文件中(若删除该文件,重启会生成新的,但不要删除和修改它),TID是事务号码,从1开始自增长,不是innodb的事务id

gtid具有幂等性:即用开启了gtid的日志去恢复数据时,系统中存在相同的gtid,若存在重复的gtid自动跳过(执行过的不再执行),会影响binlog的恢复和主从复制

gtid的开启和配置,配置/etc/my.cnf:

gtid-mode=on   开启gtid
enforce-gtid-consistency=true   强制gtid一致性

重启systemctl restart mysqld,gtid开启只影响后面的事务

开启gtid之后操作数据库,执行show master status;在Executed_Gtid_Set列会有值,即server-uuid:TID,其中TID,一个事务是1,n给事务是1-n

执行show binlog events in 'mysql-bin.000001'查看事件,每个事务开始之前有SET设置GTID

截取时使用GTID即可,不用position:

mysqlbinlog --skip-gtids --include-gtids='server-uuid:TID范围,如1-3' mysql-bin.000001 >/tmp/gtid.sql

恢复set sql_log_bin=0; source /tmp/gtid.sql; set sql_log_bin=1;

--skip-gtids参数在导出的时候忽略gtid幂等性(生成的备份不记录原有的gtid信息,恢复时生成新的gtid),否则恢复的时候会检查系统以后的binlog里面是否有要恢复的gtid,有就跳过(幂等性),导致结果不正确。

--include-gtids='server-uuid:TID范围,如1-3',‘server-uuid:TID5',需要导出的事务

--exclude-gtids='server-uuid:TID范围,如1-3',’server-uuid:TID5','server-uuid:TID7',忽略导出的事务

慢查询日志

slowlog,慢查询日志,记录运行慢的sql,优化参考工具,默认关闭

开启,配置/etc/my.cnf的[mysqld]

slow_query_log=1 开关
slow_query_log_file=/tmp/slowlog/slow.log 路径及文件名,/tmp/slowlog需要有mysql.mysql权限,文件名随意
log_query_time=0.1 慢查询时间设定,单位秒,执行select @@long_query_time;(或show variables like '%long_query_time%';)查询默认时间是10.000000秒(不合理,百万数据全表扫描才2-3秒)可以精确到微秒
log_queries_not_using_indexes 没走索引的语句也记录

重启systemctl restart mysqld

构造一张大表,desc 表名;找一个key自带没有值的列(无索引),做查询(全表扫描),构造多条慢查询。

slowlog是文本文件,直接查看即可,记录了超过log_query_time的sql执行记录或没有走索引的查询,包括执行的时间点,库、表、语句、查询时间等。按时间点排序。

过滤,将慢查询日志中,相同的查询语句合并(记录平均查询时间),不同的语句按查询次数(次数多是热语句,优先级高)、Query_time降序排列,使用慢查询分析工具:

mysqldumpslow -s c -t 10 /tmp/slowlog/slow.log  -s是排序,c是次数,-s c是按次数排序,-t 10是top 10,自动按查询时间做第二排序维度

拿到需要优化的sql,去做执行计划分析,如分析是否走索引,或是否需要改写sql等

第三方慢查询分析工具(rpm包)

https://www.percona.com/downloads/percona-toolkit/LATEST下载并安装rpm包

安装依赖:

yum install perl-DBD-MYSQL perl-Time-HiRes perl-IO-Socket-SSL perl-Digest-MD5

运行:

pt-query-diagest /tmp/slowlog/slow.log

安装Anemometer可基于pt-query-digest将慢查询以网页形式可视化。

补充

现象:网站访问越来越慢,最后无法访问了,经过检查发现磁盘满了。查询下来是由于mysql的binlog太多太大占用了空间。
  分析过程及解决方案:通常出现这种问题都应该登录服务器检查磁盘、内存和进程使用的情况,通过top、df –h和free –m来检查,发现磁盘空间满了。再进一步通过du –sh对可以的目录进行检查,发现是mysql的binlog占用空间过大。清理binlog的方法如下:
  1) 设置日志保留时长expire_logs_days自动删除
  查看当前日志保存天数:
  show variables like '%expire_logs_days%';
  这个默认是0,也就是logs不过期,可通过设置全局的参数,使他临时生效:
  set global expire_logs_days=7;
  设置了只保留7天BINLOG, 下次重启mysql这个参数默认会失败,所以需在/etc/my.cnf中设置
  expire_logs_days=7
  2) 手动删除BINLOG (purge binary logs,官网https://dev.mysql.com/doc/refman/5.6/en/purge-binary-logs.html)
  用于删除列于在指定的日志或日期之前的日志索引中的所有二进制日志。这些日志文件也会从日志索引文件中删除:
  PURGE {MASTER | BINARY} LOGS TO 'log_name'
  PURGE {MASTER | BINARY} LOGS BEFORE 'date'
  例如:
  PURGE MASTER LOGS TO 'mysql-bin.000001';
  PURGE MASTER LOGS BEFORE '2008-06-22 13:00:00';
  PURGE MASTER LOGS BEFORE DATE_SUB(NOW(), INTERVAL 3 DAY);
  purge binary logs before current_timestamp-interval 1 day;

purge.sh脚本(可加入定时任务):

#!/bin/bash
mysql -uroot -piMC123 mysql<<EOFMYSQL
purge binary logs before current_timestamp-interval 1 day  #或purge binary logs to 'mysql-bin.000001'
EOFMYSQL
posted @ 2020-01-31 12:44  发挥哥  阅读(680)  评论(3编辑  收藏  举报