日志管理
错误日志
1# 查看错误日志路径
2mysql> select @@log_error;
3+----------------------------+
4| @@log_error |
5+----------------------------+
6| /data/mysql/data/mysql.log |
7+----------------------------+
二进制日志
作用：用于即时点的数据恢复、主从复制
配置二进制日志（默认没有开启）
1# 日志要和数据分开存放
2log_bin # 开关、设定存放位置
3server_id # 5.6单机不需要此参数，5.7必须要加
4
5[root@localhost ~]# mkdir /data/binlog -p
6[root@localhost ~]# chown -R mysql. /data/
7[root@localhost ~]# vim /etc/my.cnf
8[mysqld]
9user=mysql
10basedir=/application/mysql
11datadir=/data/mysql/data
12socket=/tmp/mysql.sock
13server_id=6
14port=3306
15log_error=/data/mysql/data/mysql.log
16log_bin=/data/binlog/mysql-bin
17server_id=6
18secure-file-priv=/tmp
19[mysql]
20socket=/tmp/mysql.sock
21
22[root@localhost ~]# /etc/init.d/mysqld restart
23Shutting down MySQL.. SUCCESS!
24Starting MySQL. SUCCESS!
25[root@localhost ~]# ls /data/binlog/
26mysql-bin.000001 mysql-bin.000002 mysql-bin.000003 mysql-bin.index
27
28
29# 查看binlog的位置
30mysql> show variables like '%log_bin%';
31+---------------------------------+------------------------------+
32| Variable_name | Value |
33+---------------------------------+------------------------------+
34| log_bin | ON |
35| log_bin_basename | /data/binlog/mysql-bin |
36| log_bin_index | /data/binlog/mysql-bin.index |
37| log_bin_trust_function_creators | OFF |
38| log_bin_use_v1_row_events | OFF |
39| sql_log_bin | ON |
40+---------------------------------+------------------------------+
binlog 记录了什么？
1记录了数据库中所有变更类的操作：DDL DCL DML
- 对于 DDL 和 DCL 语句，记录发生过的语句
- 对于 DML 语句（insert update delete）：必须是已经提交的事务。
1# 记录格式（5.6以后默认级别就是ROW模式） 2ROW RBR 行记录模式 逐行记录 日志量大且严谨 3STATEMENT SBR 语句记录模式 只记录语句本身 日志量小，可读性强（对于函数类的操作会出现记录错误的情况） 4MIXED MBR 混合记录模式 5 6 7# 查看二进制日志默认的存储格式 8mysql> select @@binlog_format; 9+-----------------+ 10| @@binlog_format | 11+-----------------+ 12| ROW | 13+-----------------+
二进制日志事件（event）
二进制日志的最小记录单元
对于 DDL，DCL，一个语句就是一个 event
对于 DML 来说，只记录已经提交的事务。
1 position号码
2begin; 120 - 340
3DML1 340 - 460
4DML2 460 - 550
5commit; 550 - 760
查看二进制日志
1# 查看数据库使用的二进制日志
2mysql> show binary logs;
3+------------------+-----------+
4| Log_name | File_size |
5+------------------+-----------+
6| mysql-bin.000001 | 177 |
7| mysql-bin.000002 | 177 |
8| mysql-bin.000003 | 177 |
9| mysql-bin.000004 | 177 |
10| mysql-bin.000005 | 154 |
11+------------------+-----------+
12
13# 查看数据库正在使用的二进制日志文件
14mysql> show master status;
15+------------------+----------+--------------+------------------+-------------------+
16| File | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set |
17+------------------+----------+--------------+------------------+-------------------+
18| mysql-bin.000005 | 154 | | | |
19+------------------+----------+--------------+------------------+-------------------+
20
21# 查看000005二进制日志的事件
22mysql> show binlog events in 'mysql-bin.000005';
23+------------------+-----+----------------+-----------+-------------+---------------------------------------+
24| Log_name | Pos | Event_type | Server_id | End_log_pos | Info |
25+------------------+-----+----------------+-----------+-------------+---------------------------------------+
26| mysql-bin.000005 | 4 | Format_desc | 6 | 123 | Server ver: 5.7.26-log, Binlog ver: 4 |
27| mysql-bin.000005 | 123 | Previous_gtids | 6 | 154 | |
28| mysql-bin.000005 | 154 | Anonymous_Gtid | 6 | 219 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' |
29| mysql-bin.000005 | 219 | Query | 6 | 322 | create database oldboy2 |
30+------------------+-----+----------------+-----------+-------------+---------------------------------------+
31
32Log_name 日志名
33Pos 事件开始的position ***
34Event_type 事件类型
35Server_id 发生在哪台机器的事件
36End_log_pos 事件结束的位置号 ***
37Info 事件内容 ***
38
39# 二进制日志内容查看
40[root@localhost binlog]# mysqlbinlog mysql-bin.000005
41
42# 普通查看
43[root@localhost binlog]# mysqlbinlog mysql-bin.000005 | grep -v "SET" >/tmp/aa.txt
44
45# 详细查看
46[root@localhost binlog]# mysqlbinlog --base64-output=decode-rows -vvv mysql-bin.000005
47
48# 按需截取二进制日志
49基于position号的截取：核心在于找起点和终点
50--start-position=###
51--stop-position=###
52
53截取
54[root@localhost binlog]# mysqlbinlog --start-position=219 --stop-position=322 /data/binlog/mysql-bin.000005 >/tmp/bin.sql
55
56恢复(mysql> drop database oldboy2;)
57mysql> drop database oldboy2;
58Query OK, 0 rows affected (0.00 sec)
59
60mysql> set sql_log_bin=0; # 进制恢复过程中再次产生日志信息（临时性的，只影响当前会话，关闭窗口就会消失）
61Query OK, 0 rows affected (0.00 sec)
62
63mysql> source /tmp/bin.sql
64
案例恢复详解
1create database test charset utf8mb4; #起始
2use test;
3
4create table t1 (id int);
5insert into t1 values(1);
6commit;
7insert into t1 values(2);
8commit;
9insert into t1 values(3);
10commit; # 结束
11
12drop database test;
13
14
15# 首先查询到建库语句的position
16mysql> show binlog events in 'mysql-bin.000005';
17+------------------+------+----------------+-----------+-------------+---------------------------------------+
18| Log_name | Pos | Event_type | Server_id | End_log_pos | Info |
19+------------------+------+----------------+-----------+-------------+---------------------------------------+
20| mysql-bin.000005 | 4 | Format_desc | 6 | 123 | Server ver: 5.7.26-log, Binlog ver: 4 |
21| mysql-bin.000005 | 123 | Previous_gtids | 6 | 154 | |
22| mysql-bin.000005 | 154 | Anonymous_Gtid | 6 | 219 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' |
23| mysql-bin.000005 | 219 | Query | 6 | 322 | create database oldboy2 |
24| mysql-bin.000005 | 322 | Anonymous_Gtid | 6 | 387 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' |
25| mysql-bin.000005 | 387 | Query | 6 | 478 | drop database oldboy2 |
26| mysql-bin.000005 | 478 | Anonymous_Gtid | 6 | 543 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' |
27| mysql-bin.000005 | 543 | Query | 6 | 653 | create database test charset utf8mb4 |
28| mysql-bin.000005 | 653 | Anonymous_Gtid | 6 | 718 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' |
29| mysql-bin.000005 | 718 | Query | 6 | 816 | use `test`; create table t1 (id int) |
30| mysql-bin.000005 | 816 | Anonymous_Gtid | 6 | 881 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' |
31| mysql-bin.000005 | 881 | Query | 6 | 953 | BEGIN |
32| mysql-bin.000005 | 953 | Table_map | 6 | 998 | table_id: 109 (test.t1) |
33| mysql-bin.000005 | 998 | Write_rows | 6 | 1038 | table_id: 109 flags: STMT_END_F |
34| mysql-bin.000005 | 1038 | Xid | 6 | 1069 | COMMIT /* xid=46 */ |
35| mysql-bin.000005 | 1069 | Anonymous_Gtid | 6 | 1134 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' |
36| mysql-bin.000005 | 1134 | Query | 6 | 1206 | BEGIN |
37| mysql-bin.000005 | 1206 | Table_map | 6 | 1251 | table_id: 109 (test.t1) |
38| mysql-bin.000005 | 1251 | Write_rows | 6 | 1291 | table_id: 109 flags: STMT_END_F |
39| mysql-bin.000005 | 1291 | Xid | 6 | 1322 | COMMIT /* xid=48 */ |
40| mysql-bin.000005 | 1322 | Anonymous_Gtid | 6 | 1387 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' |
41| mysql-bin.000005 | 1387 | Query | 6 | 1459 | BEGIN |
42| mysql-bin.000005 | 1459 | Table_map | 6 | 1504 | table_id: 109 (test.t1) |
43| mysql-bin.000005 | 1504 | Write_rows | 6 | 1544 | table_id: 109 flags: STMT_END_F |
44| mysql-bin.000005 | 1544 | Xid | 6 | 1575 | COMMIT /* xid=50 */ |
45| mysql-bin.000005 | 1575 | Anonymous_Gtid | 6 | 1640 | SET @@SESSION.GTID_NEXT= 'ANONYMOUS' |
46| mysql-bin.000005 | 1640 | Query | 6 | 1732 | drop database test |
47+------------------+------+----------------+-----------+-------------+---------------------------------------+
48
49
50# 找到发现position区间段是
51 543 - 1640
52
53# 截取日志
54[root@localhost binlog]# mysqlbinlog --start-position=543 --stop-position=1640 /data/binlog/mysql-bin.000005 >/tmp/bak.sql
55
56
57# 进行恢复
58mysql> set sql_log_bin=0;
59Query OK, 0 rows affected (0.00 sec)
60mysql> source /tmp/bak.sql
61
62# 恢复后查看数据进行验证
63mysql> show databases;
64+--------------------+
65| Database |
66+--------------------+
67| information_schema |
68| mysql |
69| oldboy |
70| oldboy2 |
71| performance_schema |
72| school |
73| sys |
74| test |
75| world |
76| zrblog |
77+--------------------+
7810 rows in set (0.00 sec)
79
80mysql> use test;
81Database changed
82mysql> select * from t1;
83+------+
84| id |
85+------+
86| 1 |
87| 2 |
88| 3 |
89+------+
903 rows in set (0.00 sec)
GTID
基于 position 号恢复需要多次截取，找起点和终点的过程是很复杂的。
什么是 GTID(全局事务编号:DDL DCL DML(begin->commit))
15.6版本新加的特性，5.7中做了加强
25.6中默认不开启，5.7中默认也不开启。
3GTID = source_id : transaction_id
开启 GTID 功能
1vim /etc/my.cnf
2gtid-mode=on
3enforce-gtid-consistency=true
查看 GTID
1create database gg;
2use gg;
3create table t1(id int);
4insert into t1 values(1);
5commit;
6insert into t1 values(2);
7commit;
8insert into t1 values(3);
9commit;
10
11mysql> show master status;
12+------------------+----------+--------------+------------------+------------------------------------------+
13| File | Position | Binlog_Do_DB | Binlog_Ignore_DB | Executed_Gtid_Set |
14+------------------+----------+--------------+------------------+------------------------------------------+
15| mysql-bin.000006 | 1212 | | | f98d1e0b-a7e4-11eb-8259-080027fb878b:1-5 |
16+------------------+----------+--------------+------------------+------------------------------------------+
17
18mysql> drop database gg;
19Query OK, 1 row affected (0.00 sec)
20
21mysql> show binlog events in 'mysql-bin.000006';
22+------------------+------+----------------+-----------+-------------+-------------------------------------------------------------------+
23| Log_name | Pos | Event_type | Server_id | End_log_pos | Info |
24+------------------+------+----------------+-----------+-------------+-------------------------------------------------------------------+
25| mysql-bin.000006 | 4 | Format_desc | 6 | 123 | Server ver: 5.7.26-log, Binlog ver: 4 |
26| mysql-bin.000006 | 123 | Previous_gtids | 6 | 154 | |
27| mysql-bin.000006 | 154 | Gtid | 6 | 219 | SET @@SESSION.GTID_NEXT= 'f98d1e0b-a7e4-11eb-8259-080027fb878b:1' |
28| mysql-bin.000006 | 219 | Query | 6 | 307 | create database gg |
29| mysql-bin.000006 | 307 | Gtid | 6 | 372 | SET @@SESSION.GTID_NEXT= 'f98d1e0b-a7e4-11eb-8259-080027fb878b:2' |
30| mysql-bin.000006 | 372 | Query | 6 | 465 | use `gg`; create table t1(id int) |
31| mysql-bin.000006 | 465 | Gtid | 6 | 530 | SET @@SESSION.GTID_NEXT= 'f98d1e0b-a7e4-11eb-8259-080027fb878b:3' |
32| mysql-bin.000006 | 530 | Query | 6 | 600 | BEGIN |
33| mysql-bin.000006 | 600 | Table_map | 6 | 643 | table_id: 108 (gg.t1) |
34| mysql-bin.000006 | 643 | Write_rows | 6 | 683 | table_id: 108 flags: STMT_END_F |
35| mysql-bin.000006 | 683 | Xid | 6 | 714 | COMMIT /* xid=10 */ |
36| mysql-bin.000006 | 714 | Gtid | 6 | 779 | SET @@SESSION.GTID_NEXT= 'f98d1e0b-a7e4-11eb-8259-080027fb878b:4' |
37| mysql-bin.000006 | 779 | Query | 6 | 849 | BEGIN |
38| mysql-bin.000006 | 849 | Table_map | 6 | 892 | table_id: 108 (gg.t1) |
39| mysql-bin.000006 | 892 | Write_rows | 6 | 932 | table_id: 108 flags: STMT_END_F |
40| mysql-bin.000006 | 932 | Xid | 6 | 963 | COMMIT /* xid=12 */ |
41| mysql-bin.000006 | 963 | Gtid | 6 | 1028 | SET @@SESSION.GTID_NEXT= 'f98d1e0b-a7e4-11eb-8259-080027fb878b:5' |
42| mysql-bin.000006 | 1028 | Query | 6 | 1098 | BEGIN |
43| mysql-bin.000006 | 1098 | Table_map | 6 | 1141 | table_id: 108 (gg.t1) |
44| mysql-bin.000006 | 1141 | Write_rows | 6 | 1181 | table_id: 108 flags: STMT_END_F |
45| mysql-bin.000006 | 1181 | Xid | 6 | 1212 | COMMIT /* xid=14 */ |
46| mysql-bin.000006 | 1212 | Gtid | 6 | 1277 | SET @@SESSION.GTID_NEXT= 'f98d1e0b-a7e4-11eb-8259-080027fb878b:6' |
47| mysql-bin.000006 | 1277 | Query | 6 | 1363 | drop database gg |
48+------------------+------+----------------+-----------+-------------+-------------------------------------------------------------------+
4923 rows in set (0.01 sec)
50
51# 正确截取方式
52[root@localhost binlog]# mysqlbinlog --skip-gtids --include-gtids='f98d1e0b-a7e4-11eb-8259-080027fb878b:1-5' /data/binlog/mysql-bin.000006 >/tmp/gtid.sql
53
54# 以下截取出来的gtid日志不能直接恢复，为啥呢？ 因为幂等性
55[root@localhost binlog]# mysqlbinlog --include-gtids='f98d1e0b-a7e4-11eb-8259-080027fb878b:1-5' /data/binlog/mysql-bin.000006 >/tmp/gtid.sql
56
57# 恢复数据
58mysql> set sql_log_bin=0;
59Query OK, 0 rows affected (0.00 sec)
60
61mysql> source /tmp/gtid.sql
62
63mysql> show databases;
64mysql> use gg;
65Database changed
66mysql> select * from t1;
67+------+
68| id |
69+------+
70| 1 |
71| 2 |
72| 3 |
73+------+
74
75# 跳过某些gtid不截取
762和4 2,4
772至4 2-4
78 mysqlbinlog --include-gtids='f98d1e0b-a7e4-11eb-8259-080027fb878b:1-5' /data/binlog/mysql-bin.000006 --exclude-gtids='f98d1e0b-a7e4-11eb-8259-080027fb878b:2' >/tmp/gtid.sql
79
80 mysqlbinlog --include-gtids='f98d1e0b-a7e4-11eb-8259-080027fb878b:1-5' /data/binlog/mysql-bin.000006 --exclude-gtids='f98d1e0b-a7e4-11eb-8259-080027fb878b:2,f98d1e0b-a7e4-11eb-8259-080027fb878b:4' >/tmp/gtid.sql
二进制日志其他操作
1# 临时关闭二进制日志（会话级别）做数据恢复之前可以使用
2set sql_log_bin=0;
3
4# 自动清理 :设置依据？ 至少是一个全备份的周期。企业建议2个全备份周期+1
5mysql> select @@expire_logs_days;
6+--------------------+
7| @@expire_logs_days |
8+--------------------+
9| 0 |
10+--------------------+
11临时设置
12mysql> set global expire_logs_days=8; # 7天是全备周期，所以可以设置为8天
13永久设置
14vim /etc/my.cnf
15expire_logs_days=8
16
17# 手工清理
18PURGE BINARY LOGS BEFORE now() - INTERVAL 3day; # 删除三天之前的日子
19PURGE BINARY LOGS TO 'mysql-bin.000010'; # 删除到那个日志文件为止
20
21删除数据库所有日志文件，并且从000001开始
22reset master; #非常危险，千万不要用，主从架构会崩溃
23
24# 日志滚动（从000001重新开始）
251.重启数据库
262.或者用 flush logs 命令
27mysql> show variables like '%max_binlog_size%'; #默认值是 1GB
28+-----------------+------------+
29| Variable_name | Value |
30+-----------------+------------+
31| max_binlog_size | 1073741824 |
32+-----------------+------------+
slowlog
开启慢日志（默认没开启）
1slow_query_log=1 #开关
2slow_query_log_file=/data/mysql/data/slow.log #位置
3long_query_time=0.1 #设定慢查询时间
4log_queries_not_using_indexes #没走索引的语句也记录
5
压测
1[root@localhost binlog]# mysqlslap --defaults-file=/etc/my.cnf --concurrency=100 --iterations=1 --create-schema='oldboy' --query="select * from oldboy.t100w where k2='xyMN'" engine=innodb --number-of-queries=2000 -uroot -p123 -verbose
2
查看慢日志
1[root@localhost binlog]# cat /data/mysql/data/slow.log
2/application/mysql/bin/mysqld, Version: 5.7.26-log (MySQL Community Server (GPL)). started with:
3Tcp port: 3306 Unix socket: /tmp/mysql.sock
4Time Id Command Argument
5# Time: 2021-05-07T08:27:33.281983Z
6# User@Host: root[root] @ localhost [] Id: 33
7# Query_time: 0.173121 Lock_time: 0.000015 Rows_sent: 257 Rows_examined: 257
8use oldboy;
9SET timestamp=1620376053;
10select * from oldboy.t100w where k2='xyMN';
11# Time: 2021-05-07T08:27:33.283401Z
12# User@Host: root[root] @ localhost [] Id: 47
13# Query_time: 0.259220 Lock_time: 0.087784 Rows_sent: 257 Rows_examined: 257
14SET timestamp=1620376053;
15select * from oldboy.t100w where k2='xyMN';
16# Time: 2021-05-07T08:27:33.288964Z
17
分析慢日志
1# mysqldumpslow 分析慢日志
2[root@localhost binlog]# mysqldumpslow -s c -t 10 /data/mysql/data/slow.log
3
4Reading mysql slow query log from /data/mysql/data/slow.log
5Count: 17 Time=0.18s (3s) Lock=0.02s (0s) Rows=257.0 (4369), root[root]@localhost
6 select * from oldboy.t100w where k2='S'
7
8# percona-toolkit 工具使用
9下载地址 https://www.percona.com/downloads/percona-toolkit/LATEST/
10percona-toolkit-3.3.1-1.el7.x86_64
11
12[root@localhost software]# yum install -y percona-toolkit-3.3.1-1.el7.x86_64.rpm
13[root@localhost software]# pt-query-digest /data/mysql/data/slow.log
14*******************************************************************
15 Using the default of SSL_verify_mode of SSL_VERIFY_NONE for client
16 is deprecated! Please set SSL_verify_mode to SSL_VERIFY_PEER
17 possibly with SSL_ca_file|SSL_ca_path for verification.
18 If you really don't want to verify the certificate and keep the
19 connection open to Man-In-The-Middle attacks please set
20 SSL_verify_mode explicitly to SSL_VERIFY_NONE in your application.
21*******************************************************************
22 at /usr/bin/pt-query-digest line 12054.
23*******************************************************************
24 Using the default of SSL_verify_mode of SSL_VERIFY_NONE for client
25 is deprecated! Please set SSL_verify_mode to SSL_VERIFY_PEER
26 possibly with SSL_ca_file|SSL_ca_path for verification.
27 If you really don't want to verify the certificate and keep the
28 connection open to Man-In-The-Middle attacks please set
29 SSL_verify_mode explicitly to SSL_VERIFY_NONE in your application.
30*******************************************************************
31 at /usr/bin/pt-query-digest line 12054.
32
33# A software update is available:
34
35# 100ms user time, 10ms system time, 28.86M rss, 241.93M vsz
36# Current date: Fri May 7 16:45:19 2021
37# Hostname: localhost.localdomain
38# Files: /data/mysql/data/slow.log
39# Overall: 17 total, 1 unique, 0 QPS, 0x concurrency _____________________
40# Time range: all events occurred at 2021-05-07T08:27:33
41# Attribute total min max avg 95% stddev median
42# ============ ======= ======= ======= ======= ======= ======= =======
43# Exec time 3s 102ms 420ms 200ms 266ms 70ms 189ms
44# Lock time 287ms 13us 126ms 17ms 87ms 37ms 18us
45# Rows sent 4.27k 257 257 257 257 0 257
46# Rows examine 4.27k 257 257 257 257 0 257
47# Query size 714 42 42 42 42 0 42
48
49# Profile
50# Rank Query ID Response time Calls R/Call V/M
51# ==== =================================== ============= ===== ====== ====
52# 1 0x617AC0C2E2FB389D0CF91886EB3F68F0 3.3916 100.0% 17 0.1995 0.02 SELECT oldboy.t?w
53
54# Query 1: 0 QPS, 0x concurrency, ID 0x617AC0C2E2FB389D0CF91886EB3F68F0 at byte 3959
55# This item is included in the report because it matches --limit.
56# Scores: V/M = 0.02
57# Time range: all events occurred at 2021-05-07T08:27:33
58# Attribute pct total min max avg 95% stddev median
59# ============ === ======= ======= ======= ======= ======= ======= =======
60# Count 100 17
61# Exec time 100 3s 102ms 420ms 200ms 266ms 70ms 189ms
62# Lock time 100 287ms 13us 126ms 17ms 87ms 37ms 18us
63# Rows sent 100 4.27k 257 257 257 257 0 257
64# Rows examine 100 4.27k 257 257 257 257 0 257
65# Query size 100 714 42 42 42 42 0 42
66# String:
67# Databases oldboy
68# Hosts localhost
69# Users root
70# Query_time distribution
71# 1us
72# 10us
73# 100us
74# 1ms
75# 10ms
76# 100ms ################################################################
77# 1s
78# 10s+
79# Tables
80# SHOW TABLE STATUS FROM `oldboy` LIKE 't100w'\G
81# SHOW CREATE TABLE `oldboy`.`t100w`\G
82# EXPLAIN /*!50100 PARTITIONS*/
83select * from oldboy.t100w where k2='xyMN'\G