4. MySQL 日志管理

作者: 随便写写咯 | 来源:发表于2021-02-26 02:32 被阅读0次

1 日志管理

MySQL支持丰富的日志类型, 如下:

事务日志: transaction log, 记录事务的操作过程
事务日志的写入类型为"追加", 因此其操作为"顺序IO"; 通常也被称为: 预写式日志write ahead logging
事务日志文件: ib_logfile0, ib_logfile1
错误日志: error log
通用日志: general log
慢查询日志: slow query log
二进制日志: binary log
中继日志: relay log, 在主从复制架构中, 从服务器用于保存从主服务器的二进制日志中读取的事件

1.1 事务日志

事务日志: transaction log
事务型存储引擎自行管理和使用, 建议和数据文件分开存放, redo log和undo log

Innodb事务日志相关配置:

show variables like "%innodb_log%";
---
innodb_log_file_size 50331648 # 每个日志文件大小
innodb_log_files_in_group 2 # 日志组成员个数
innodb_log_group_home_dir ./ # 事务文件路径
innodb_flush_log_at_trx_commit; # 默认为1

mysql> show variables like "%innodb_log%";
+-----------------------------+----------+
| Variable_name               | Value    |
+-----------------------------+----------+
| innodb_log_buffer_size      | 16777216 | # 事务日志缓冲
| innodb_log_checksums        | ON       |
| innodb_log_compressed_pages | ON       |
| innodb_log_file_size        | 50331648 |
| innodb_log_files_in_group   | 2        |
| innodb_log_group_home_dir   | ./       |
| innodb_log_write_ahead_size | 8192     |
+-----------------------------+----------+
7 rows in set (0.05 sec)

事务日志默认保存在mysql的数据目录下, 记录的是redo_log

-rw-r----- 1 mysql mysql 50331648 Nov 23 20:43 ib_logfile0
-rw-r----- 1 mysql mysql 50331648 Nov 19 00:10 ib_logfile1

redo log

redo_log记录的是数据库事务的操作过程, 两个文件一个写满了, 就会覆盖另一个文件, 互相覆盖
redo_log是顺序写, 记录非常快

undo log

undo_log用于保留事务执行操作前的数据状态, 如果事务撤销了, 可以通过undo_log使数据回到原来的状态
undo_log存放在数据库存放数据的位置, 在每个数据库的数据文件里和数据一起存放在ibd文件里

-rw-r----- 1 mysql mysql  98304 Nov 23 19:55 teachers.ibd

对数据库执行事务操作, 即使未commit, 只要执行了操作, 那么redo_log和undo_log都会发生变化, redo_log会记录事务的操作, 而undo_log会记录数据修改前的状态
撤销事务时, 利用undo_log, 把数据撤回到事务执行前的状态, redo_log中此前记录的事务操作也会被删除
一旦事务提交后, undo_log就会把之前记录的旧的数据状态删除, 因为已经提交了. redo_log会把事务操作的内容的更改写入磁盘

因此, 事务执行快是因为把数据写到了redo_log里, 而且是顺序写, 比非事务的随机写快
非事务操作是直接写到数据库磁盘文件里, 而且随机写也不是连续的磁盘空间

redo和undo日志的变化

开启事务, 执行事务, 未提交

redo日志和undo日志都会发生变化: ib_logfile0或者ib_logfile1的时间戳会发生变化, 对应的表的ibd文件也会变大, 时间戳发生变化.

撤销事务
redo log会再次发生变化, 刷新时间戳, 撤销此前操作, undo log会刷新, 回到修改前状态, 但是空间不会立即释放
一旦提交了事务, redo log会把提交的事务操作交给数据库执行操作, undo log会把之前备份的原始数据状态删除, 因为已经确认更改了

事务执行之所以快是因为事务执行是把数据写到事务日志文件里, 而且是顺序写. 顺序写比数据库的随机写快很多.
不用事务执行时, 数据提交到内存然后写到表在磁盘的文件里, 但是数据在磁盘的位置不一定是连续的,比如磁盘碎片. 因此写数据时有可能是随机写. 事务文件都是顺序追加数据. 因此以事务方式写数据, 效率会提高

1.2 事务日志性能优化

innodb_flush_log_at_trx_commit=0|1|2

图片.png

1 为默认值, 每次提交事务, 会直接写入到操作系统缓冲区, 同时写入到磁盘
           因此, 每次事务提交, 都会产生磁盘IO操作. 虽然完全符合ACID特性, 但对性能有影响
           如果1秒内, 提交了100个事务, 那么就会产生100次磁盘IO

0 事务提交时没有写磁盘的操作, 而是先把数据保存到MySQL日志缓存区
  每秒执行一次将事务日志缓冲区提交的所有事务写入到操作系统缓存区, 并且刷新到磁盘
  这样可提供更好的性能, 但mysql崩溃或者服务器宕机可能丢失最后一秒的事务
  如果1秒内, 提交了100个事务, 那么只会产生1次磁盘IO 

2 每次事务提交后, 都会先把事务操作写入操作系统的缓冲区, 但每秒才会进行一次刷新到磁盘文件中, 性能比0略差一些, 但是操作系统崩溃或停电可能导致最后一秒的交易丢失

高并发业务下, 使用2模式, 折中

1. 配置为2和配置为0性能差异并不大, 因为将数据从MySQL的日志缓冲区拷贝到操作系统缓冲区, 虽然跨越用户态与内核态, 但毕竟只是内存的数据拷贝, 速度很快
2. 配置为2和配置为0, 安全差异巨大, 操作系统崩溃的概率相比MySQL应用程序崩溃的概率小很多, 设置为2, 只要操作系统不崩溃, 也绝对不会丢数据
0的情况下, 是先把数据保存到MySQL的日志缓存区, 之后每秒写入到操作系统缓冲区并且同步到磁盘, 而2的情况是直接写到操作系统缓冲区,  然后每秒同步到磁盘
在0的情况下, 一旦MySQL崩溃, 那么其日志缓冲区就会丢失一秒内的数据, 而2的情况下, 因为数据是直接先写到OS缓冲区, 所以即使MySQL崩溃也不会影响操作系统

事务日志建议放在独立的目录, 甚至独立的磁盘分区, 利用独立的连续的磁盘空间, 并且扩大文件最大值, 减少日志的反复覆盖, 并且增加事务日志的文件数

innodb_log_group_home_dir=/data/mysql/trx_logs
innodb_log_files_in_group=3
innodb_log_file_size=503316480
mkdir -pv /data/mysql/trx_logs
chown -R mysql.mysql /data/mysql/

需要安全: 用1模式, 每次提交, 都写磁盘, 并且设置sync_binlog=1表示最高级别的容错
需要高性能: 用2比0好, MySQL坏的几率比操作系统坏的概率高

1.3 错误日志

mysqld启动和关闭过程中输出的事件信息
mysqld运行中产生的错误信息
event scheduler运行一个event时产生的日志信息
在主从复制架构中的从服务器上启动从服务器线程时产生的信息
对于mysql的报错, 最好查看错误日志, 记录的比较全

#错误日志的位置会根据配置文件中的指定位置生成
mysql> show variables like 'log_error';
+---------------+-----------------------+
| Variable_name | Value                 |
+---------------+-----------------------+
| log_error     | /data/mysql/mysql.log |
+---------------+-----------------------+
1 row in set (0.00 sec)

错误文件路径

show global variables like 'log_error';
log-error=/data/mysql/mysql.log
该路径需要事先手动创建出来, 并且修改权限为mysql

如果路径事先不存在或者没有修改属性, 那么mysql是启动不起来的, 这时错误日志就不会记录信息. 
此时如果想查看错误原因, 可以查看/var/log/messages, 或者用mysqld & 去启动数据库, mysqld启动数据库会把错误信息输出到屏幕上.

记录哪些警告信息到日志文件

mysql> show global variables like 'log_warnings';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| log_warnings  | 2     | # 5.7默认为2
+---------------+-------+
1 row in set (0.00 sec)

1.4 通用日志

默认不启用

开启后, 可以记录所有用户对mysql的所有sql操作, 包括错误操作, 日志文件会很大

可以用来分析用户操作的命令

可以将日志保存在文件, 也可以保存在表中

保存在文件:

#修改mysql配置文件
general-log=ON #开启
general-log-file=/data/mysql/general.log  #日志文件必须放在mysql账户用rwx权限的目录, 否则文件不会创建

2020-11-23T15:58:18.090516Z     2 Connect   root@localhost on  using Socket
2020-11-23T15:58:18.091505Z     2 Query select * from mysql.user
2020-11-23T16:00:03.414412Z     3 Connect   david@10.0.0.1 on  using TCP/IP
2020-11-23T16:00:05.303368Z     3 Query show databases

也可以将日志记录在表里, mysql库中, 有general_log表, 可以记录通用日志

general-log=on
log-output=table

general_log是服务器选项, 也是系统全局变量, 可以在配置文件修改永久保存, 也可以通过修改全局变量, 临时生效

范例: 通过通用日志查看执行的语句

general_log和log_output变量都要修改

mysql> select @@log_output;
+--------------+
| @@log_output |
+--------------+
| FILE         |
+--------------+
1 row in set (0.00 sec)

mysql> set global log_output='table';
Query OK, 0 rows affected (0.01 sec)

mysql> show global variables like 'log_output';

+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| log_output    | TABLE |
+---------------+-------+
1 row in set (0.00 sec)

mysql> select @@general_log;
+---------------+
| @@general_log |
+---------------+
|             0 |
+---------------+
1 row in set (0.00 sec)

mysql> set global general_log=1;
Query OK, 0 rows affected (0.00 sec)

mysql> select @@general_log;
+---------------+
| @@general_log |
+---------------+
|             1 |
+---------------+
1 row in set (0.00 sec)

mysql> select * from mysql.general_log\G
*************************** 1. row ***************************
  event_time: 2021-06-11 19:27:44.725911
   user_host: root[root] @ localhost []
   thread_id: 2
   server_id: 0
command_type: Query
    argument: show global variables like 'log_output'
*************************** 2. row ***************************
  event_time: 2021-06-11 19:27:46.964140
   user_host: root[root] @ localhost []
   thread_id: 2
   server_id: 0
command_type: Query
    argument: select @@general_log
*************************** 3. row ***************************
  event_time: 2021-06-11 19:27:55.440373
   user_host: root[root] @ localhost []
   thread_id: 2
   server_id: 0
command_type: Query
    argument: select * from mysql.general_log
3 rows in set (0.00 sec)

mysql> update students set age=22 where id-1;
ERROR 1046 (3D000): No database selected
mysql> update hellodb.students set age=22 where id=1;
ERROR 1054 (42S22): Unknown column 'id' in 'where clause'
mysql> update hellodb.students set age=22 where stuid=1;
Query OK, 1 row affected (0.01 sec)
Rows matched: 1  Changed: 1  Warnings: 0

mysql> select * from mysql.general_log\G
*************************** 1. row ***************************
  event_time: 2021-06-11 19:27:44.725911
   user_host: root[root] @ localhost []
   thread_id: 2
   server_id: 0
command_type: Query
    argument: show global variables like 'log_output'
*************************** 2. row ***************************
  event_time: 2021-06-11 19:27:46.964140
   user_host: root[root] @ localhost []
   thread_id: 2
   server_id: 0
command_type: Query
    argument: select @@general_log
*************************** 3. row ***************************
  event_time: 2021-06-11 19:27:55.440373
   user_host: root[root] @ localhost []
   thread_id: 2
   server_id: 0
command_type: Query
    argument: select * from mysql.general_log
*************************** 4. row ***************************
  event_time: 2021-06-11 19:28:20.020020
   user_host: root[root] @ localhost []
   thread_id: 2
   server_id: 0
command_type: Query
    argument: update students set age=22 where id-1
*************************** 5. row ***************************
  event_time: 2021-06-11 19:28:32.728082
   user_host: root[root] @ localhost []
   thread_id: 2
   server_id: 0
command_type: Query
    argument: update hellodb.students set age=22 where id=1
*************************** 6. row ***************************
  event_time: 2021-06-11 19:28:36.036307
   user_host: root[root] @ localhost []
   thread_id: 2
   server_id: 0
command_type: Query
    argument: update hellodb.students set age=22 where stuid=1
*************************** 7. row ***************************
  event_time: 2021-06-11 19:28:38.003917
   user_host: root[root] @ localhost []
   thread_id: 2
   server_id: 0
command_type: Query
    argument: select * from mysql.general_log
7 rows in set (0.00 sec)

范例: 对访问的语句按照访问次数进行排序

[19:34:21 root@mysql ~]#mysql -e 'select argument from mysql.general_log' | awk 'NR!=1{sql[$0]++}END{for(i in sql){print sql[i],i}}' | sort -nr
5 select @@version_comment limit 1
5 select argument from mysql.general_log
5 root@localhost on  using Socket
4 select * from mysql.general_log
4 #空行是因为mysql -e是非交互执行sql, 因此, 执行后会退出, 在general_log中记录quit命令, 并且argument为空, 因为, 每次用mysql -e执行命令才会出现空行
1 update students set age=22 where id-1
1 update hellodb.students set age=22 where stuid=1
1 update hellodb.students set age=22 where id=1
1 show global variables like 'log_output'
1 select @@general_log

[19:38:02 root@mysql ~]#mysql -e 'select argument from mysql.general_log' | sort | uniq -c | sort -nr
      8 select argument from mysql.general_log
      7 select @@version_comment limit 1
      7 root@localhost on  using Socket
      6 
      5 select * from mysql.general_log
      1 update students set age=22 where id-1
      1 update hellodb.students set age=22 where stuid=1
      1 update hellodb.students set age=22 where id=1
      1 show global variables like 'log_output'
      1 select @@general_log
      1 argument

1.5 慢查询日志

慢查询日志: 记录执行查询时长超出指定时长的操作

只要执行时间超过阈值的语句就会被记录, 不只是查询语句, 阈值看业务, 一般1s就很长了, 因为还要算上网络延迟, 和用户端下载等时间.

慢查询如何优化: 看看语句写的有没有问题, 针对查询的信息有没有创建索引, 查询有没有利用到索引.

慢查询相关变量:

slow_query_log=ON|OFF # 开启或关闭慢查询, 支持全局和会话级别, 只有全局设置才会生成慢查询文件
long_query_time=N # 慢查询的阈值, 单位是秒, 默认10秒
slow_query_log_file=HOSTNAME-slow.log # 慢查询日志文件, 默认生成以主机名命名的文件
log_slow_filter=admin,filesort,filesort_on_disk,full_join,full_scan,query_cache,query_cache_miss,tmp_table,tmp_table_on_disk
# 上述查询类型语句且查询时长超过long_query_time,则记录日志
log_queries_not_using_indexes=ON # 如果某个查询没有使用到索引或使用了全索引扫描, 不论是否达到慢查询阈值都会记录到慢查询日志, 默认OFF, 即不记录
log_slow_rate_limit=1 # 多少次慢查询才记录, mariadb特有
log_slow_verbosity=query_plan,explain # 记录内容
log_slow_queries=OFF #同slow_query_log, MariaDB 10.0/MySQL 5.6.1版本后已经删除

案例: 利用存储过程生成慢查询SQL

long-query-time=1
slow-query-log=ON
slow-query-log-file=mysql-slow.log

# Time: 2021-06-11T13:23:23.720152Z
# User@Host: root[root] @ localhost []  Id:    17
# Query_time: 146.970736  Lock_time: 0.000154 Rows_sent: 0  Rows_examined: 0
use test;
SET timestamp=1623417803;
call sp_testlog;

慢查询分析工具:

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

[21:26:12 root@mysql~]#mysqldumpslow -s c -t 10 /data/mysql/mysql-slow.log

Reading mysql slow query log from /data/mysql/mysql-slow.log
Count: 1  Time=146.97s (146s)  Lock=0.00s (0s)  Rows=0.0 (0), root[root]@localhost
  call sp_testlog

Died at /usr/local/mysql/bin/mysqldumpslow line 167, <> chunk 1.

1.6 使用profile工具

可以查看语句每一步执行的时间消耗

#开启后, 会显示语句执行详细的过程
set profiling=ON
#查看语句, 注意结果中的query_id值
show profiles;

范例: 利用profile工具分析查询语句

mysql> set profiling=ON;
Query OK, 0 rows affected, 1 warning (0.00 sec)

mysql> show profiles;
Empty set, 1 warning (0.00 sec)

mysql> select * from students where stuid=2;
+-------+------------+-----+--------+---------+-----------+
| StuID | Name       | Age | Gender | ClassID | TeacherID |
+-------+------------+-----+--------+---------+-----------+
|     2 | Shi Potian |  22 | M      |       1 |         7 |
+-------+------------+-----+--------+---------+-----------+
1 row in set (0.00 sec)

mysql> show profiles;
+----------+------------+--------------------------------------+
| Query_ID | Duration   | Query                                |
+----------+------------+--------------------------------------+
|        1 | 0.00011875 | select * from students where id=1    |
|        2 | 0.00086400 | SELECT DATABASE()                    |
|        3 | 0.01469875 | show databases                       |
|        4 | 0.00072700 | show tables                          |
|        5 | 0.00043675 | select * from students where id=1    |
|        6 | 0.00060350 | select * from students where stuid=1 |
|        7 | 0.00064725 | select * from students where stuid=2 |
+----------+------------+--------------------------------------+
7 rows in set, 1 warning (0.00 sec)

# 查询最后一条query_id=7

mysql> show profile for query 7;
+----------------------+----------+
| Status               | Duration |
+----------------------+----------+
| starting             | 0.000092 |
| Opening tables       | 0.000026 |
| System lock          | 0.000117 |
| checking permissions | 0.000018 |
| Opening tables       | 0.000019 |
| init                 | 0.000053 |
| System lock          | 0.000018 |
| optimizing           | 0.000017 |
| statistics           | 0.000145 |
| preparing            | 0.000021 |
| executing            | 0.000008 |
| Sending data         | 0.000030 |
| end                  | 0.000009 |
| query end            | 0.000011 |
| closing tables       | 0.000011 |
| freeing items        | 0.000030 |
| cleaning up          | 0.000026 |
+----------------------+----------+
17 rows in set, 1 warning (0.00 sec)

也可显示每一步使用cpu的情况

mysql> show profile cpu for query 7;
+----------------------+----------+----------+------------+
| Status               | Duration | CPU_user | CPU_system |
+----------------------+----------+----------+------------+
| starting             | 0.000092 | 0.000067 |   0.000021 |
| Opening tables       | 0.000026 | 0.000018 |   0.000006 |
| System lock          | 0.000117 | 0.000090 |   0.000029 |
| checking permissions | 0.000018 | 0.000012 |   0.000003 |
| Opening tables       | 0.000019 | 0.000014 |   0.000005 |
| init                 | 0.000053 | 0.000041 |   0.000013 |
| System lock          | 0.000018 | 0.000012 |   0.000004 |
| optimizing           | 0.000017 | 0.000013 |   0.000004 |
| statistics           | 0.000145 | 0.000147 |   0.000000 |
| preparing            | 0.000021 | 0.000018 |   0.000000 |
| executing            | 0.000008 | 0.000008 |   0.000000 |
| Sending data         | 0.000030 | 0.000030 |   0.000000 |
| end                  | 0.000009 | 0.000007 |   0.000000 |
| query end            | 0.000011 | 0.000012 |   0.000000 |
| closing tables       | 0.000011 | 0.000011 |   0.000000 |
| freeing items        | 0.000030 | 0.000030 |   0.000000 |
| cleaning up          | 0.000026 | 0.000024 |   0.000000 |
+----------------------+----------+----------+------------+
17 rows in set, 1 warning (0.00 sec)

2 二进制日志(备份)

用于备份
记录导致数据改变或潜在导致数据改变的SQL语句
记录已提交的日志
以二进制形式存到文件里
该日志与存储引擎种类无关, myisam和innodb都支持

功能: 通过"重放"日志文件中的事件来生成数据副本
注意: 建议二进制日志和数据文件分开存放

二进制日志记录三种格式:

1. 基于语句型记录: statement, 记录具体执行的每个语句
2. 基于行记录: row, 记录实际发生改变的数据, 日志量较大, 更加安全, 是5.6以后默认模式, 建议使用
3. 混合模式: mixed, 让系统自行判定该基于哪种方式进行
一般建议使用行型, row, 是因为一条DML语句有可能包含一个函数, 比如date(). 这时如果插入数据的话, 那么基于语句型, 就会只记录date()函数, 而后恢复数据时, 就是按照恢复数据时间点的date()值去恢复, 这样数据是不准确的
而基于row, 行型, 那么由date()函数, 会记录实际的时间值, 恢复也是按照这个时间值去恢复, 更加准确

举例:

当执行了 update students set time=now(); # 假如students表有100条记录

如果利用语句型记录: 那么只会记录命令本身: update students set time=now();, 并不会记录now()在执行适合的具体时间, 也不会记录一共修改了多少行数据.

日志信息: update students set time=now();

如果是行型, 会记录, 修改了哪些行, 并且把函数的具体值, 记录下来, 放在日志文件里.

日志信息:
update students set time=xxxx where stuid=1;
update students set time=xxxx where stuid=2;
update students set time=xxxx where stuid=n;
update students set time=xxxx where stuid=100;

这时如果某一天想要还原数据库, 语句型是无法准确还原的, 因为在还原时, 执行 update students set time=now(); 这时now()的日期是执行还原时的时期, 而且表中的记录也不一定是多少条了

所以行型, 记录的是对每一行真实的操作,改了哪行,改了什么,记录的更精确

行型缺点: 占用空间大

混合型: 两种综合, 系统自动决定哪个操作用行型还是语句型记录. mysql觉得哪个操作需要行型,那就用行型记录, 反之亦然.

MySQL 5.7以上默认基于行型

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

binlog_format是服务器选项, 可以在配置文件修改

# 行型记录update语句的格式
### UPDATE `hellodb`.`students`
### WHERE # where表示被修改的行, 原先的状态
###   @1=25
###   @2='Sun Dasheng'
###   @3=100
###   @4=2
###   @5=NULL
###   @6=NULL
### SET # 执行的修改操作
###   @1=25
###   @2='Sun Dasheng'
###   @3=18
###   @4=2
###   @5=NULL
###   @6=NULL

记录格式配置:


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

二进制日志文件的构成

有两类文件:
1. 日志文件: mysql-bin.文件名后缀, 二进制格式, 如: mysql-bin.000001
2. 索引文件: mysql-bin.index, 文本格式, 记录二进制文件名称

二进制日志默认不启用

只有当sql_log_bin和log_bin同时开启时, 才会生效

sql_log_bin=ON|OFF: session级和global级(global级看版本, 5.7里只是会话级)的系统变量, 非服务器选项 默认ON, 支持动态修改, 可以直接在mysql命令行临时开启或者关闭二进制log, 更适合临时调和数据恢复时关闭二进制
log_bin=/PATH/BIN_LOG_FILE: 是服务器选项, 也是global系统变量, 但不支持动态修改, 默认为OFF, 需要写到配置文件, 并且重启服务,通过修改服务器选项间接影响系统变量,更适合持久保存
通常, 先在配置文件中启动log_bin, 之后根据情况, 需要临时关闭二进制日志, 可以通过sql_log_bin, 临时修改变量去关闭, 调试完在开启.  在某个会话,关闭二进制日志后, 在该会话中所作的增删改操作不会被记录到二进制日志, 但是其他的没有关闭掉二进制日志的会话里, 增删改记录还是会被记录到二进制日志.
二进制日志要放到独立目录里, 比数据库目录还重要, 因为二进制日志就是备份, 数据库所有的增删改记录都保存在里面, 并且会陆续产生新的单独的二进制日志文件, 并且不会删除旧的二进制文件, 默认情况文件达到最大值时, 会自动生成新的二进制日志, 另外,重启服务也会生成新的二进制文件

其他二进制相关服务器变量

binlog_format=STATEMENT|ROW|MIXED # 记录二进制日志的格式
max_binlog_size=1073741824 # 单个二进制日志文件的最大体积, 到达最大值会自动滚动, 默认为1G, 不过, 文件达到上限时的大小未必为指定的精确值
binlog_cache_size=4m # 此变量确定在每次事务中保存二进制日志更改记录的缓存的大小(每次连接)
max_binlog_cache_size=512m # 限制用于缓存多事务查询的字节大小
sync_binlog=1|0 # 设定是否启动二进制日志即时同步磁盘功能, 默认为0, 由操作系统负责同步日志到磁盘
expire_logs_days=N # 二进制日志可以自动删除的天数, 默认为0, 既不自动删除

注意: MySQL5.7以后, 想要开启二进制, 需要在配置文件同时指定log-bin和server-id否则MySQL无法启动

log-bin=/data/mysql/mysql-bin   #写保存路径和文件前缀即可                                                                                                                      
server-id=1 #指明server-id

log_bin: 自动默认指定文件名, /var/lib/mysql/mysql-bin.000001, /var/lib/mysql/mysql-bin.index
log_bin=/PATH/TO/BIN_LOG_FILE: 手动指定二进制文件路径

mysql> select @@sql_log_bin;
+---------------+
| @@sql_log_bin |
+---------------+
|             1 | # 默认开启
+---------------+
1 row in set (0.00 sec)

二进制相关命令

查看mysql自行管理使用中的二进制日志文件列表, 及大小

SHOW [BINARY|MASTER] LOGS;

mysql> show binary logs;
+------------------+-----------+
| Log_name         | File_size |
+------------------+-----------+
| mysql-bin.000001 |       154 |
+------------------+-----------+
1 row in set (0.00 sec)

mysql> show master logs;
+------------------+-----------+
| Log_name         | File_size |
+------------------+-----------+
| mysql-bin.000001 |       154 |
+------------------+-----------+
1 row in set (0.00 sec)

mysql> show master status;
+------------------+----------+--------------+------------------+-------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set |
+------------------+----------+--------------+------------------+-------------------+
| mysql-bin.000001 |      472 |              |                  |                   |
+------------------+----------+--------------+------------------+-------------------+
1 row in set (0.00 sec)

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

生成新的二进制日志文件的四种方法:

默认情况文件达到最大值(设定变量)时, 会自动生成新的二进制日志, 默认1个G大小
重启服务也会生成新的二进制文件
mysqladmin flush-binary-log | flush-logs 也可主动触发生成新的二进制日志, 不过mysqladmin flush-logs是针对所有的mysql日志, 生成新的日志文件
在数据库里, flush logs; 也可刷新二进制日志

查看二进制文件内容, 在数据库内执行

show binlog events;

mysql [hellodb]> show binlog events in 'mysql-bin.000003'\G
...
*************************** 69. row ***************************
   Log_name: mysql-bin.000003
        Pos: 7810 #Pos: 记录了操作执行时被记录在了文件的哪个位置
 Event_type: Query
  Server_id: 1
End_log_pos: 8013  
       Info: use `hellodb`; INSERT INTO `teachers` VALUES (1,'Song Jiang',45,'M'),(2,'Zhang Sanfeng',94,'M'),(3,'Miejue Shitai',77,'F'),(4,'Lin Chaoying',93,'F')

#也可以跳过m条记录,再往后查看n条记录
#从Pos:8202记录开始, 跳过2条记录, 往后显示4条记录
MariaDB [hellodb]> show binlog events in 'mysql-bin.000003' from 8202 limit 2,4\G
*************************** 1. row ***************************
   Log_name: mysql-bin.000003
        Pos: 8366
 Event_type: Gtid
  Server_id: 1
End_log_pos: 8408
       Info: GTID 0-1-77
*************************** 2. row ***************************
   Log_name: mysql-bin.000003
        Pos: 8408
 Event_type: Query
  Server_id: 1
End_log_pos: 8696
       Info: use `hellodb`; CREATE TABLE `toc` (
  `ID` int(10) unsigned NOT NULL AUTO_INCREMENT,
  `CourseID` smallint(5) unsigned DEFAULT NULL,
  `TID` smallint(5) unsigned DEFAULT NULL,
  PRIMARY KEY (`ID`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8
*************************** 3. row ***************************
   Log_name: mysql-bin.000003
        Pos: 8696
 Event_type: Gtid
  Server_id: 1
End_log_pos: 8738
       Info: GTID 0-1-78
*************************** 4. row ***************************
   Log_name: mysql-bin.000003
        Pos: 8738
 Event_type: Query
  Server_id: 1
End_log_pos: 8850
       Info: use `hellodb`; /*!40000 ALTER TABLE `toc` DISABLE KEYS */
4 rows in set (0.000 sec)

二进制日志文件的增幅比数据库本身大小增幅还要大, 因为会记录每一条增删改命令, 并且会记录额外信息, 比如时间, Pos数据等. 因此要控制好二进制文件的大小, 否则会把磁盘空间占满. 因此, 二进制日志文件要放在独立分区, 独立目录, 定期清理. 按照业务,和备份策略清理, 比如两个月清理一次

expire_logs_days: 系统自动清理二进制日志时间, 清除的间隔要超过备份的间隔, 多留日志. 默认为0, 不自动清理.

mysql> select @@expire_logs_days;
+--------------------+
| @@expire_logs_days |
+--------------------+
|                  0 |
+--------------------+
1 row in set (0.00 sec)

Linux命令行查看二进制日志文件工具

mysqlbinlog [option] LOG_FILE
mysqlbinlog客户端命令和客户端默认字符集的选项冲突, 因此, 配置文件中要写
vim /etc/my.cnf
[mysql] # 如果写成[client], 那么执行mysqlbinlog会报错, 未知的变量:default-character-set
default-character-set=utf8mb4

位置id必须是日志里存在的Pos值, 不能自己随便写位置id

# 位置id不对, 会报错
'/*!*/;
ERROR: Error in Log_event::read_log_event(): 'read error', data_len: 556412672, event_type: 108
ERROR: Could not read entry at offset 1111: Error in log format or read error.

mysqlbinlog [OPTIONS] log_file # 需要指明路径
    --start-position=  # 指定开始Pos文件
    --stop-position= # 指定结束位置
    --start-datetime= # 指定从哪个时间点开始查看, 时间格式: YYYY-MM-DD hh:mm:ss
    --stop-datetime= # 指定结束时间
    --base64-output[=name]
    -v # 将base64编码的日志, 转换成sql语句
    -vvv

[16:52:04 root@mysql ~]#mysqlbinlog --start-position=256 /data/mysql/mysql-bin.000002
/*!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  #4是日志头部, 无论从哪个位置开始查看日志, 位置4都会显示
#200830 15:51:35 server id 1  end_log_pos 256 CRC32 0x30cec561  Start: binlog v 4, server v 10.3.17-MariaDB-log created 200830 15:51:35 at startup   #200830 15:51:35 事件发生的时间点, 可以指定起始,结束时间来查看
ROLLBACK/*!*/;
BINLOG '
Zz5LXw8BAAAA/AAAAAABAAAAAAQAMTAuMy4xNy1NYXJpYURCLWxvZwAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAABnPktfEzgNAAgAEgAEBAQEEgAA5AAEGggAAAAICAgCAAAACgoKAAAAAAAA
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAEEwQADQgICAoKCgFhxc4w
'/*!*/;
# at 256
#200830 15:51:35 server id 1  end_log_pos 299 CRC32 0x7bbd3452  Gtid list [0-1-44]
# at 299
#200830 15:51:35 server id 1  end_log_pos 342 CRC32 0x3e7223c1  Binlog checkpoint mysql-bin.000002
# at 342
#200830 16:05:08 server id 1  end_log_pos 389 CRC32 0x29187e05  Rotate to mysql-bin.000003  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*/;

如果想查看二进制里面的timpstamp的具体日期, 可以用 date -d @TIMESTAMP

恢复数据方法:

利用二进制日志备份, 可以把删除的数据恢复,但是还原时需要把二进制关掉, 否则导入时还会再生成二进制日志,数据就重复了

比如, 某一个库被删了,只要二进制日志还在, 确定好时间, 就可以将mysqlbinlog命令查看二进制日志结果重定向到以.sql命名的文件了, 再把该文件倒回数据库, 这样可以恢复数据.

缺点: 重新导入二进制日志的过程也会被记录到当前的二进制日志里. 造成数据重复, 恢复数据时, 在记录日志是没用的

解决方法: 导入二进制数据前, 把二进制关了, 利用会话级变量, sql_log_bin,临时关闭二进制日志, 导完了再开开. 注意, 再次导入时, 不能退回Linux命令行, 否则会话变量就失效了. 要在当前数据库会话窗口, 利用souce或者., 去导入文件, souce /data/backup.sql 或者 \. /data/mbackup.sql

利用二进制日志, 除非知道数据前后发生了哪些变化, 找到包含所有修改数据的二进制文件, 否则只用某一个二进制文件是无法完全还原数据的, 因为数据不一定存在同一个二进制日志里, 需要配合备份的操作

二进制日志的清除

reset master
删除所有二进制日志文件, 并重新生成一个空的日志文件, index文件重新计数, 文件名从1开始计数, 一般是master主机第一次启动时执行清除
测试环境完成测试, 准备上线时, 可以将二进制日志彻底清空

清除指定二进制日志
purge { binary | master} logs { to 'log_name'  | before datetime_expr }

purge binary logs to 'mysql-bin.000003'; #删除mysql-bin.000003之前的日志, 3不会被清理
purge binary logs before '2017-01-23';
purge binary logs before '2017-03-22 09:25:30';

范例: 利用二进制文件恢复误删除的数据库

1. 空数据库. 导入hellodb数据库
2. 更新学生表, 更新老师表
3. 删除数据库hellodb
4. 利用binlog进行恢复

安装mysql, 开启二进制

[02:04:29 root@mysql ~]#yum -y install mysql-server
[02:04:39 root@mysql ~]#vim /etc/my.cnf.d/mysql-server.cnf
log-bin
[02:05:32 root@mysql ~]#systemctl enable --now mysqld

-rw-r----- 1 mysql mysql      179 Jun 12 02:05  mysql-bin.000001
-rw-r----- 1 mysql mysql      156 Jun 12 02:05  mysql-bin.000002
-rw-r----- 1 mysql mysql       38 Jun 12 02:05  mysql-bin.index

mysql> show master logs;
+------------------+-----------+-----------+
| Log_name         | File_size | Encrypted |
+------------------+-----------+-----------+
| mysql-bin.000001 |       179 | No        |
| mysql-bin.000002 |       156 | No        |
+------------------+-----------+-----------+
2 rows in set (0.00 sec)

# binlog记录到了000002的Pos=156, 因此二进制记录位置会从156开始
mysql> show master status;
+------------------+----------+--------------+------------------+-------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set |
+------------------+----------+--------------+------------------+-------------------+
| mysql-bin.000002 |      156 |              |                  |                   |
+------------------+----------+--------------+------------------+-------------------+
1 row in set (0.00 sec)

导入数据库

02:09:39 root@mysql ~]#mysql < hellodb_innodb.sql

导入数据库, 查看binlog变化

# 涨到了10752
mysql> show master status;
+------------------+----------+--------------+------------------+-------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set |
+------------------+----------+--------------+------------------+-------------------+
| mysql-bin.000002 |    10752 |              |                  |                   |
+------------------+----------+--------------+------------------+-------------------+
1 row in set (0.00 sec)

进行数据更新

mysql> use hellodb;
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Database changed
mysql> update students set age = 20;
Query OK, 23 rows affected (0.01 sec)
Rows matched: 25  Changed: 23  Warnings: 0

mysql> update teachers set age = 50;
Query OK, 4 rows affected (0.00 sec)
Rows matched: 4  Changed: 4  Warnings: 0

查看binlog更新

mysql> show master logs;
+------------------+-----------+-----------+
| Log_name         | File_size | Encrypted |
+------------------+-----------+-----------+
| mysql-bin.000001 |       179 | No        |
| mysql-bin.000002 |     12394 | No        |
+------------------+-----------+-----------+
2 rows in set (0.00 sec)

sql> show master status;
+------------------+----------+--------------+------------------+-------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set |
+------------------+----------+--------------+------------------+-------------------+
| mysql-bin.000002 |    12394 |              |                  |                   |
+------------------+----------+--------------+------------------+-------------------+
1 row in set (0.00 sec)
# 此时二进制日志更新到了12394, 可作为结束位置

删除hellodb数据库

sql> drop database hellodb;
Query OK, 7 rows affected (0.07 sec)

导出从156到12394的二进制日志

[02:19:45 root@mysql ~]#mysqlbinlog -v --start-position=156 --stop-position=12394 /var/lib/mysql/mysql-bin.000002 > backup_hellodb.sql

mysql> set sql_log_bin=0;
mysql> source backup_hellodb.sql;

# 再次查看二进制日志, 看出没有增长
mysql> show master status;
+------------------+----------+--------------+------------------+-------------------+
| File             | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set |
+------------------+----------+--------------+------------------+-------------------+
| mysql-bin.000002 |    12584 |              |                  |                   |
+------------------+----------+--------------+------------------+-------------------+
1 row in set (0.00 sec)

# 修改的数据也重新执行了
mysql> select * from hellodb.teachers ;
+-----+---------------+-----+--------+
| TID | Name          | Age | Gender |
+-----+---------------+-----+--------+
|   1 | Song Jiang    |  50 | M      |
|   2 | Zhang Sanfeng |  50 | M      |
|   3 | Miejue Shitai |  50 | F      |
|   4 | Lin Chaoying  |  50 | F      |
+-----+---------------+-----+--------+
4 rows in set (0.00 sec)

mysql> select * from hellodb.students ;
+-------+---------------+-----+--------+---------+-----------+
| StuID | Name          | Age | Gender | ClassID | TeacherID |
+-------+---------------+-----+--------+---------+-----------+
|     1 | Shi Zhongyu   |  20 | M      |       2 |         3 |
|     2 | Shi Potian    |  20 | M      |       1 |         7 |
|     3 | Xie Yanke     |  20 | M      |       2 |        16 |

# 恢复后, 开启二进制日志

mysql> set sql_log_bin=1;
Query OK, 0 rows affected (0.00 sec)

总结: 本案例恢复时使用单独的二进制日志, 找出开始和结束位置, 可以轻松恢复数据, 不过实际工作中, 找出需要恢复的二进制日志很难, 因为不确定是什么时间, 哪条命令造成了误操作, 因为还需要配合备份文件进行恢复

4. MySQL 日志管理

1 日志管理

1.1 事务日志

1.2 事务日志性能优化

1.3 错误日志

1.4 通用日志

1.5 慢查询日志

1.6 使用profile工具

2 二进制日志(备份)

相关文章

网友评论

延伸阅读

深度阅读

栏目导航

热点阅读

数据库

mysql