MySQL日志管理

一、MySQL日志简介

二、错误日志

作用：
记录mysql数据库的一般状态信息及报错信息，是我们对于数据库常规报错处理的常用日志。
默认位置： $MYSQL_HOME/data/
开启方式:（MySQL安装完后默认开启)

mysql> show variables like 'log_error';
+---------------+------------+
| Variable_name | Value |
+---------------+------------+
| log_error | ./db01.err |
+---------------+------------+
## 错误日志日志名：
$HOSTNAME.err
## 错误日志存储位置：
$datadir 数据目录下
## 错误日志默认是否开启：
开启的
## 如何修改配置：
vim /etc/my.cnf
[mysqld]
log_error=/opt/1.txt
## 日志文件必须提前创建出来，并且针对mysql用户有写入权限
touch /opt/1.txt
chown -R mysql.mysql /opt/1.txt

三、一般查询日志

root@localhost [(none)] >show variables like '%general%';
+------------------+--------------------------+
| Variable_name | Value |
+------------------+--------------------------+
| general_log | OFF |
| general_log_file | /app/mysql/data/db03.log |
+------------------+--------------------------+
## 常规日志日志名：
$HOSTNAME.log
## 常规日志存储位置：
$datadir 数据目录下
## 常规日志默认是否开启：
关闭
## 如何修改配置：
vim /etc/my.cnf
[mysqld]
general_log=1
general_log_file=/opt/xxx.log

四、二进制日志binlog

#查看二进制日志是否开启
mysql> show variables like '%log_bin%';
+---------------------------------+-------+
| Variable_name                   | Value |
+---------------------------------+-------+
| log_bin                         | OFF   |
+------------------+----------------------+
#常规的的日志名显示
mysql-bin.000001
mysql-bin.000002
mysql-bin.000003
mysql-bin.000004
## 常规日志存储位置：
$datadir 数据目录下
## 常规日志默认是否开启：
关闭
## 如何修改配置：
### 开启binlog 修改为行级模式，MySQL5.6默认statement //也可自定义路径文件，不过要给予mysql用户的属主属组权限
vim /etc/my.cnf
[mysqld]
log-bin=mysql-bin
binlog_format=row
### 开启binlog MySQL5.7
vim /etc/my.cnf
[mysqld]
log-bin=mysql-bin
server_id=1
binlog_format=row

binlog的工作模式

1）statement 语句模式

记录MySQL的SQL语句 DDL DML DCL
## MySQL5.6 默认语句模式
mysql> show variables like 'binlog_format';
+---------------+-----------+
| Variable_name | Value     |
+---------------+-----------+
| binlog_format | STATEMENT |
+---------------+-----------+

2）row 行级模式

记录MySQL的SQL语句 DDL、DCL，DML记录每一行的变化过程
## MySQL5.7 默认行级模式
root@localhost [(none)] >show variables like 'binlog_format';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| binlog_format | ROW   |
+---------------+-------+

3）mixed 混合模式

#statement 和 row的混合
可以同时使用两种不同的binlog格式，分别是"statement"（语句格式）和"row"（行格式）。
具体的选择取决于执行的具体SQL语句和设置的一些条件。

模式区别

#statement：
- 优点：
    - 易读
    - 占用磁盘空间小
- 缺点
    - 不严谨
#row：
- 优点：
    - 严谨
- 缺点
    - 不易读
    - 占用磁盘空间大
#mixed混合模式
极少用

查看binlog

## 查看语句模式
语法：mysqlbinlog binlog日志名字
[root@db01 data]# mysqlbinlog /app/mysql/data/mysql-bin.000001
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#230801 10:01:03 server id 1  end_log_pos 120 CRC32 0xdc513fcb  Start: binlog v 4, server v 5.6.50-log created 230801 10:01:03 at startup
ROLLBACK/*!*/;
BINLOG '
X2fIZA8BAAAAdAAAAHgAAAAAAAQANS42LjUwLWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAABfZ8hkEzgNAAgAEgAEBAQEEgAAXAAEGggAAAAICAgCAAAACgoKGRkAAcs/
Udw=
'/*!*/;
# at 120
#230801 10:25:10 server id 1  end_log_pos 167 CRC32 0xd9e5cd91  Rotate to mysql-bin.000002  pos: 4
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;
## 查看行级模式  
[root@db01 data]# mysqlbinlog --base64-output=decode-rows -vvv /app/mysql/data/mysql-bin.000001
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#230801 10:01:03 server id 1  end_log_pos 120 CRC32 0xdc513fcb  Start: binlog v 4, server v 5.6.50-log created 230801 10:01:03 at startup
ROLLBACK/*!*/;
# at 120
#230801 10:25:10 server id 1  end_log_pos 167 CRC32 0xd9e5cd91  Rotate to mysql-bin.000002  pos: 4
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;
## 查看有哪些binlog，每个binlog的大小
root@localhost [(none)] >show binary logs;
+------------------+-----------+
| Log_name         | File_size |
+------------------+-----------+
| mysql-bin.000001 |       167 |
| mysql-bin.000002 |       167 |
| mysql-bin.000003 |       167 |
| mysql-bin.000004 |       167 |
| mysql-bin.000005 |       167 |
| mysql-bin.000006 |       167 |
| mysql-bin.000007 |       167 |
| mysql-bin.000008 |      2186 |
+------------------+-----------+
8 rows in set (0.00 sec)
#查看当前处于那个binlog日志
root@localhost [(none)] >show master status;
+------------------+----------+--------------+------------------+-------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set |
+------------------+----------+--------------+------------------+-------------------+
| mysql-bin.000008 |     2186 |              |                  |                   |
+------------------+----------+--------------+------------------+-------------------+
1 row in set (0.00 sec)
#查看binlog事件
root@localhost [(none)] >show binlog events in 'mysql-bin.000001';
+------------------+-----+-------------+-----------+-------------+---------------------------------------+
| Log_name         | Pos | Event_type  | Server_id | End_log_pos | Info                                  |
+------------------+-----+-------------+-----------+-------------+---------------------------------------+
| mysql-bin.000001 |   4 | Format_desc |         1 |         120 | Server ver: 5.6.50-log, Binlog ver: 4 |
| mysql-bin.000001 | 120 | Rotate      |         1 |         167 | mysql-bin.000002;pos=4                |
+------------------+-----+-------------+-----------+-------------+---------------------------------------+
2 rows in set (0.00 sec)

事件介绍

什么是事件？
1）在指定的时间间隔或在指定的时间点执行一系列SQL语句。
2）在binlog中最小的记录单元为event
3）一个事务会被拆分成多个事件（event）

## MySQL5.6 事件（event）特性
1）每个event都有一个开始位置（start position）和结束位置（stop position）。
2）所谓的位置就是event对整个二进制的文件的相对位置。
3）对于一个二进制日志中，前120个position是文件格式信息预留空间。
4）MySQL第一个记录的事件，都是从120开始的。
5）MySQL5.6空的binlog 143
## MySQL5.7 事件（event）特性
1）每个event都有一个开始位置（start position）和结束位置（stop position）。
2）所谓的位置就是event对整个二进制的文件的相对位置。
3）对于一个二进制日志中，前154个position是文件格式信息预留空间。
4）MySQL第一个记录的事件，都是从154开始的。
5）MySQL5.7空的binlog 177

使用binlog恢复数据案例

模拟数据

#查看当前处于那个binlog日志目录
root@localhost [(none)] >show master status;
+------------------+----------+--------------+------------------+-------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set |
+------------------+----------+--------------+------------------+-------------------+
| mysql-bin.000009 |      120 |              |                  |                   |
+------------------+----------+--------------+------------------+-------------------+
1 row in set (0.00 sec)
#创建库
root@localhost [(none)] >create database binlog;
Query OK, 1 row affected (0.00 sec)
#切换到binlog库
root@localhost [(none)] >use binlog
Database changed
root@localhost [binlog] >
#创建表
root@localhost [binlog] >create table binlog.test_log(id int);
Query OK, 0 rows affected (0.19 sec)
#插入数据
root@localhost [binlog] >insert into binlog.test_log values(1),(2),(3);
Query OK, 3 rows affected (0.00 sec)
Records: 3  Duplicates: 0  Warnings: 0
#提交
root@localhost [binlog] >commit;
Query OK, 0 rows affected (0.00 sec)
#再次查看Position数值
root@localhost [binlog] >show master status;
+------------------+----------+--------------+------------------+-------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set |
+------------------+----------+--------------+------------------+-------------------+
| mysql-bin.000009 |      542 |              |                  |                   |
+------------------+----------+--------------+------------------+-------------------+
1 row in set (0.00 sec)
#查看表数据
root@localhost [binlog] >select * from test_log;
+------+
| id   |
+------+
|    1 |
|    2 |
|    3 |
+------+
3 rows in set (0.00 sec)
#修改数据
root@localhost [binlog] >update test_log set id=10 where id=1;
Query OK, 1 row affected (0.00 sec)
Rows matched: 1  Changed: 1  Warnings: 0
#提交
root@localhost [binlog] >commit;
#查看表数据
root@localhost [binlog] >select * from test_log;
+------+
| id   |
+------+
|   10 |
|    2 |
|    3 |
+------+
#删除一行数据
root@localhost [binlog] >delete from test_log where id=3;
Query OK, 1 row affected (0.00 sec)
#提交
root@localhost [binlog] >commit;
Query OK, 0 rows affected (0.00 sec)
#查看数据
root@localhost [binlog] >select * from test_log;
+------+
| id   |
+------+
|   10 |
|    2 |
+------+
2 rows in set (0.00 sec)
root@localhost [binlog] >show master status;
+------------------+----------+--------------+------------------+-------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set |
+------------------+----------+--------------+------------------+-------------------+
| mysql-bin.000009 |      944 |              |                  |                   |
+------------------+----------+--------------+------------------+-------------------+
1 row in set (0.00 sec)

模拟数据故障

#删除表
root@localhost [binlog] >drop table test_log;
Query OK, 0 rows affected (0.01 sec)
#删除库
root@localhost [binlog] >drop database binlog;
Query OK, 0 rows affected (0.00 sec)

恢复数据

#目前表数据状态有如下几种，这里以恢复表数据10 2 3为例   
+------+
| id   |
+------+
| 1    |
| 2    |
| 3    |
+------+
+------+
| id   |
+------+
| 10   |
| 2    |
| 3    |
+------+
+------+
| id   |
+------+
| 10   |
| 2    |
+------+
# 1.查看当前使用的是哪个binlog？
root@localhost [(none)] >show master status;
+------------------+----------+--------------+------------------+-------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set |
+------------------+----------+--------------+------------------+-------------------+
| mysql-bin.000009 |     1158 |              |                  |                   |
+------------------+----------+--------------+------------------+-------------------+
1 row in set (0.01 sec)
# 2.使用mysqlbinlog命令查看binlog内容
[root@db01 ~]# cd /app/mysql/data
[root@db01 data]# ll
total 227580
-rw-rw---- 1 mysql mysql       56 Jul 19 15:46 auto.cnf
-rw-rw---- 1 mysql mysql   145563 Jul 21 16:28 db01.err
-rw-rw---- 1 mysql mysql        6 Aug  1 10:01 db01.pid
-rw-rw---- 1 mysql mysql 79691776 Aug  1 15:52 ibdata1
-rw-rw---- 1 mysql mysql 52428800 Jul 31 20:04 ibdata2
-rw-rw---- 1 mysql mysql 50331648 Aug  1 15:52 ib_logfile0
-rw-rw---- 1 mysql mysql 50331648 Jul 19 15:44 ib_logfile1
drwx------ 2 mysql mysql      166 Jul 25 20:17 linux50
drwx------ 2 mysql mysql     4096 Jul 26 15:30 mtlbbdb_19900
drwx------ 2 mysql mysql     4096 Jul 28 15:08 mysql
-rw-rw---- 1 mysql mysql      167 Aug  1 10:25 mysql-bin.000001
-rw-rw---- 1 mysql mysql      167 Aug  1 10:25 mysql-bin.000002
-rw-rw---- 1 mysql mysql      167 Aug  1 10:50 mysql-bin.000003
-rw-rw---- 1 mysql mysql      167 Aug  1 10:50 mysql-bin.000004
-rw-rw---- 1 mysql mysql      167 Aug  1 10:50 mysql-bin.000005
-rw-rw---- 1 mysql mysql      167 Aug  1 10:50 mysql-bin.000006
-rw-rw---- 1 mysql mysql      167 Aug  1 10:50 mysql-bin.000007
-rw-rw---- 1 mysql mysql     2331 Aug  1 15:37 mysql-bin.000008
-rw-rw---- 1 mysql mysql     1158 Aug  1 15:52 mysql-bin.000009
-rw-rw---- 1 mysql mysql      171 Aug  1 15:37 mysql-bin.index
drwx------ 2 mysql mysql     4096 Jul 19 15:44 performance_schema
drwx------ 2 mysql mysql       54 Jul 28 15:18 test
drwx------ 2 mysql mysql      165 Jul 30 13:04 world
[root@db01 data]# mysqlbinlog --base64-output=decode-rows -vvv mysql-bin.000009 
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#230801 15:37:20 server id 1  end_log_pos 120 CRC32 0xd26468b0  Start: binlog v 4, server v 5.6.50-log created 230801 15:37:20
# Warning: this binlog is either in use or was not closed properly.
# at 120
#230801 15:38:43 server id 1  end_log_pos 220 CRC32 0x69da3209  Query   thread_id=8     exec_time=0     error_code=0
SET TIMESTAMP=1690875523/*!*/;
SET @@session.pseudo_thread_id=8/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=1073741824/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8 *//*!*/;
SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=33/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
create database binlog
/*!*/;
............
#找到需要恢复数据的起始点和终止点 //120以前忽略
恢复思路：
1）明确记得删库和删表之前有过什么操作
2）思考快速定位需要恢复数据的SQL语句 //这里案例以创库语句开始，updata修改语句结束
3）查看SQL语句所在出，导出数据至文件夹
4）关闭binlog读取
5）重新导入数据
创库语句开始：120
# at 120
#230801 15:38:43 server id 1  end_log_pos 220 CRC32 0x69da3209  Query   thread_id=8     exec_time=0     error_code=0
SET TIMESTAMP=1690875523/*!*/;
SET @@session.pseudo_thread_id=8/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=1073741824/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8 *//*!*/;
SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=33/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
create database binlog
/*!*/;
结束语句：746  //746之后的BEGIN为下个delete的事务，所以这里结尾是在746
COMMIT/*!*/;
# at 746
#230801 15:47:16 server id 1  end_log_pos 820 CRC32 0xac77e130  Query   thread_id=8     exec_time=0     error_code=0
SET TIMESTAMP=1690876036/*!*/;
BEGIN
/*!*/;
# at 820
#230801 15:47:16 server id 1  end_log_pos 873 CRC32 0xeeece9b2  Table_map: `binlog`.`test_log` mapped to number 73
# at 873
#230801 15:47:16 server id 1  end_log_pos 913 CRC32 0x56e3773c  Delete_rows: table id 73 flags: STMT_END_F
### DELETE FROM `binlog`.`test_log`

#截取日志数据
[root@db01 data]# mysqlbinlog --start-position=120 --stop-position=746 mysql-bin.000009 >/tmp/1.sql
[root@db01 data]# ll /tmp/
total 8
-rw-r--r-- 1 root root 2923 Aug  1 16:17 1.sql
# 临时关闭binlog的记录
root@localhost [(none)] >set sql_log_bin=0;
Query OK, 0 rows affected (0.00 sec)
#恢复数据
root@localhost [(none)] >source /tmp/1.sql
Query OK, 0 rows affected (0.00 sec)
Query OK, 0 rows affected, 1 warning (0.00 sec)
Query OK, 0 rows affected (0.00 sec)
Query OK, 0 rows affected (0.00 sec)
Query OK, 0 rows affected (0.00 sec)
Query OK, 0 rows affected (0.00 sec)
Query OK, 0 rows affected (0.00 sec)
Query OK, 0 rows affected (0.00 sec)
Query OK, 0 rows affected (0.00 sec)
Charset changed
Query OK, 0 rows affected (0.00 sec)
Query OK, 0 rows affected (0.00 sec)
Query OK, 0 rows affected (0.00 sec)
Query OK, 0 rows affected (0.00 sec)
Query OK, 1 row affected (0.00 sec)
Database changed
Query OK, 0 rows affected (0.00 sec)
Query OK, 0 rows affected (0.01 sec)
Query OK, 0 rows affected (0.00 sec)
Query OK, 0 rows affected (0.00 sec)
Query OK, 0 rows affected (0.00 sec)
Query OK, 0 rows affected (0.11 sec)
Query OK, 0 rows affected (0.00 sec)
Query OK, 0 rows affected (0.00 sec)
Query OK, 0 rows affected (0.00 sec)
Query OK, 0 rows affected (0.01 sec)
Query OK, 0 rows affected (0.00 sec)
Query OK, 0 rows affected (0.00 sec)
Query OK, 0 rows affected (0.00 sec)
#开启binlog记录
root@localhost [binlog] >set sql_log_bin=1;
Query OK, 0 rows affected (0.00 sec)
#查看数据
root@localhost [binlog] >select * from binlog.test_log;
+------+
| id   |
+------+
|   10 |
|    2 |
|    3 |
+------+
3 rows in set (0.00 sec)

企业种经常碰见的问题

1）企业中的binlog很大，位置点不好找需要配合使用grep
2）企业中所有数据不会只在一个binlog中配合全备（mysqldump）
3）想要恢复的库，中途有其他库表操作，如何只截取指定库的使用选项-d指定查看库

[root@db01 data]# mysqlbinlog -d db1 --start-position=120 --stop-position=1035 mysql-bin.000007 > /tmp/test_binlog.sql

binlog的刷新和删除

binlog的刷新

1)重启数据库
/etc/init.d/mysqld restart
2)执行flush logs;
3)mysqladmin
[root@db01 ~]# mysqladmin -uroot -p123 flush-log
4)自动切割，当binlog达到1G后自动刷新

删除binlog

# 1.根据时间删除
root@localhost [(none)] >set global expire_logs_days=7;
也可以写入配置文件: 
vim /etc/my.cnf
[mysqld]
expire_logs_days = 7
# 2.根据时间删除
root@localhost [(none)] >purge binary logs before now() - interval 7 day;
# 3.根据文件名删除
root@localhost [(none)] >purge binary logs to 'mysql-bin.000001';
# 4.删除binlog
root@localhost [(none)] >reset master;

五、慢查询日志

#查看慢查询是否开启
root@localhost [(none)] >show variables like '%slow%';
+---------------------------+-------------------------------+
| Variable_name             | Value                         |
+---------------------------+-------------------------------+
| log_slow_admin_statements | OFF                           |
| log_slow_slave_statements | OFF                           |
| slow_launch_time          | 2                             |
| slow_query_log            | OFF                           |
| slow_query_log_file       | /app/mysql/data/db01-slow.log |
+---------------------------+-------------------------------+
5 rows in set (0.00 sec)
## 常规日志日志名：
$HOSTNAME-slow.log
## 常规日志存储位置：
$datadir 数据目录下
## 常规日志默认是否开启：
关闭
## 如何修改配置：
[root@db01 ~]# vim /etc/my.cnf
[mysqld]
#指定是否开启慢查询日志
slow_query_log = 1
#指定慢日志文件存放位置（默认在data）
slow_query_log_file=/application/mysql/data/slow.log
#设定慢查询的阀值(默认10s)
long_query_time=0.05
#不使用索引的慢查询日志是否记录到索引
log_queries_not_using_indexes

慢查询命令

[root@db01 data]# mysqldumpslow db01-slow.log
[root@db01 data]# mysqldumpslow -s c db01-slow.log
-s：指定排序方式
    - c：count按照SQL语句执行次数排序
    - t：time时间排序
    - r：row行数排序
    - l：lock锁定时间排序
-t：top 看前几个排行
-g：接正则表达式匹配SQL语句
#使用第三方插件
[root@db01 ~]# wget http://test.driverzeng.com/MySQL_Package/percona-toolkit-3.0.11-1.el6.x86_64.rpm
[root@db01 ~]# yum install -y percona-toolkit-3.0.11-1.el6.x86_64.rpm
使用percona公司提供的pt-query-digest工具分析慢查询日志
[root@db01 ~]# pt-query-digest /app/mysql/data/db01-slow.log