MySQL性能篇之日志管理

MySQL 支持丰富的日志类型，如下：

事务日志：transaction log

事务日志的写入类型为"追加"，因此其操作为"顺序IO"；通常也被称为：预写式日志 write ahead
logging
事务日志文件： ib_logfile0， ib_logfile1

错误日志 error log

通用日志 general log

慢查询日志 slow query log

二进制日志 binary log

中继日志 reley log，在主从复制架构中，从服务器用于保存从主服务器的二进制日志中读取的事件

事务日志

事务日志：transaction log

redo log：实现 WAL（Write Ahead Log) ,数据更新前先记录redo log

undo log：保存与执行的操作相反的操作,用于实现rollback

事务型存储引擎自行管理和使用，建议和数据文件分开存放

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=0|1|2

1 此为默认值，日志缓冲区将写入日志文件，并在每次事务后执行刷新到磁盘。 这是完全遵守ACID特性

0 提交时没有写磁盘的操作;而是每秒执行一次将日志缓冲区的提交的事务写入刷新到磁盘。这样可提供更好的性能，但服务器崩溃可能丢失最后一秒的事务

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

高并发业务行业最佳实践，是使用第三种折衷配置（=2）：

1.配置为2和配置为0，性能差异并不大，因为将数据从Log Buffer拷贝到OS cache，虽然跨越用户态与内核态，但毕竟只是内存的数据拷贝，速度很快

2.配置为2和配置为0，安全性差异巨大，操作系统崩溃的概率相比MySQL应用程序崩溃的概率，小很多，设置为2，只要操作系统不奔溃，也绝对不会丢数据

说明：

设置为1，同时sync_binlog = 1表示最高级别的容错
innodb_use_global_flush_log_at_trx_commit=0时，将不能用SET语句重置此变量（ MariaDB10.2.6 后废弃）

错误日志

错误日志

mysqld启动和关闭过程中输出的事件信息
mysqld运行中产生的错误信息
event scheduler运行一个event时产生的日志信息
在主从复制架构中的从服务器上启动从服务器线程时产生的信息

错误文件路径

SHOW GLOBAL VARIABLES LIKE 'log_error';
+---------------+-----------------------+
| Variable_name | Value                 |
+---------------+-----------------------+
| log_error     | /data/mysql/mysql.log |
+---------------+-----------------------+
1 row in set (0.00 sec)

记录哪些警告信息至错误日志文件

# CentOS7 mariadb 5.5 默认值为1
# CentOS8 mariadb 10.3 默认值为2
log_warnings=0|1|2|3... #MySQL5.7之前
log_error_verbosity=0|1|2|3... #MySQL8.0

范例

MariaDB [hellodb]> SHOW GLOBAL VARIABLES LIKE 'log_warnings';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| log_warnings | 2 |
+---------------+-------+
1 row in set (0.001 sec)

范例: MySQL8.0变量变化

mysql> SHOW GLOBAL VARIABLES LIKE 'log_error_verbosity';
+---------------------+-------+
| Variable_name       | Value |
+---------------------+-------+
| log_error_verbosity | 2     |
+---------------------+-------+
1 row in set (0.00 sec)

通用日志

通用日志：记录对数据库的通用操作，包括:错误的SQL语句

通用日志可以保存在：file（默认值）或table（mysql.general_log表）

通用日志相关设置

general_log=ON|OFF
general_log_file=HOSTNAME.log
log_output=TABLE|FILE|NONE

范例: 启用通用日志并记录至文件中

#默认没有启用通用日志
mysql> select @@general_log;
+---------------+
| @@general_log |
+---------------+
|             0 |
+---------------+
1 row in set (0.03 sec)

# 启用
mysql> set global general_log=1;
Query OK, 0 rows affected (0.13 sec)

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

# 默认通用日志存放在文件中
mysql> show global variables like 'log_output';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| log_output    | FILE  |
+---------------+-------+
1 row in set (0.00 sec)

# 通用日志存放的文件路径
mysql> select @@general_log_file;
+---------------------------+
| @@general_log_file        |
+---------------------------+
| /data/mysql/localhost.log |
+---------------------------+
1 row in set (0.00 sec)

范例：通用日志记录到表中

#修改通用日志，记录通用日志至mysql.general_log表中
mysql> show global variables like 'log_output';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| log_output    | TABLE |
+---------------+-------+
1 row in set (0.04 sec)

#general_log表是CSV格式的存储引擎
show table status like 'general_log'G

#general_log表是CSV的文本文件
[root@centos8 ~]#file /var/lib/mysql/mysql/general_log.CSV
/var/lib/mysql/mysql/general_log.CSV: ASCII text
[root@centos8 ~]#head /var/lib/mysql/mysql/general_log.CSV

MariaDB [mysql]> select * from mysql.general_logG

范例: 查找执行次数最多的前三条语句

MariaDB [mysql]> select argument,count(argument) num from mysql.general_log group by argument order by num desc limit 3;
+---------------------------+-----------------+
| argument | num |
+---------------------------+-----------------+
| select * from teachers    | 6 |
| select * from general_log | 4 |
| select * from students    | 3 |
+---------------------------+-----------------+
3 rows in set (0.002 sec)

范例:对访问的语句进行排序

[root@centos8 ~]# mysql -e 'select argument from mysql.general_log' | awk '{sql[$0]++}END{for(i in sql){print sql[i],i}}' | sort -nr

[root@centos8 ~]# mysql -e 'select argument from mysql.general_log' | sort | uniq -c |sort -nr

慢查询日志

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

慢查询相关变量

slow_query_log=ON|OFF #开启或关闭慢查询，支持全局和会话，只有全局设置才会生成慢查询文件
long_query_time=N #慢查询的阀值，单位秒,默认为10s
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 版后已删除

范例：

#slow_query_log选项即开启慢查询的开关，OFF为关闭，ON为开启
mysql> show variables like '%slow_query_log%';
+---------------------+--------------------------------+
| Variable_name       | Value                          |
+---------------------+--------------------------------+
| slow_query_log      | OFF                            |
| slow_query_log_file | /data/mysql/localhost-slow.log |
+---------------------+--------------------------------+
2 rows in set (0.04 sec)

# 开启
mysql> set global slow_query_log = ON;
Query OK, 0 rows affected (0.30 sec)

# 同样的，慢查询日志的文件名也可以重新指定，只需要设置set global slow_query_log_file = 文件名即可。

前面说过，慢查询日志只有当SQL语句响应时间超过一定阈值才会记录在日志中，那么这个阈值是多少，该如何设置呢？
可通过以下命令查看慢查询日志的阈值：
mysql> show variables like 'long_query_time%';
+-----------------+-----------+
| Variable_name   | Value     |
+-----------------+-----------+
| long_query_time | 10.000000 |
+-----------------+-----------+
1 row in set (0.00 sec)

可以看到，默认的阈值是10秒，该值同样可以通过设置来修改，如设置为0.1秒：
mysql> set global long_query_time = 0.1;
Query OK, 0 rows affected (0.03 sec)

范例：接下来通过案例的方式来演示慢查询日志：
我在当前数据库里有一张students表，表结构如下所示：

mysql> desc students;
+-----------+------------------+------+-----+---------+----------------+
| Field     | Type             | Null | Key | Default | Extra          |
+-----------+------------------+------+-----+---------+----------------+
| StuID     | int unsigned     | NO   | PRI | NULL    | auto_increment |
| Name      | varchar(50)      | NO   |     | NULL    |                |
| Age       | tinyint unsigned | NO   |     | NULL    |                |
| Gender    | enum('F','M')    | NO   |     | NULL    |                |
| ClassID   | tinyint unsigned | YES  |     | NULL    |                |
| TeacherID | int unsigned     | YES  |     | NULL    |                |
+-----------+------------------+------+-----+---------+----------------+
6 rows in set (0.00 sec)

# 分别做如下查询：
mysql> select * from students;
mysql> select sleep(1);
mysql> select stuid,sleep(2) from students;
mysql> select stuid,sleep(1) from students;

# 因为我们设置了阈值为0.1秒，因此后两条SQL应该都要记录在慢查询日志中，接下来验证是否如此：
通过如下命令，可查看慢查询SQL的条数：
mysql> show global status like '%slow_queries%';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| Slow_queries  | 3     |
+---------------+-------+
1 row in set (0.23 sec)

显示记录为3条，与实际情况一致。
通过show variables like '%slow_query_log%'命令，可以查看到日志的具体路径
mysql> show variables like '%slow_query_log%';
+---------------------+--------------------------------+
| Variable_name       | Value                          |
+---------------------+--------------------------------+
| slow_query_log      | ON                             |
| slow_query_log_file | /data/mysql/localhost-slow.log |
+---------------------+--------------------------------+
2 rows in set (0.00 sec)

打开/data/mysql/localhost-slow.log，可以看到日志当中记录了时间超过阈值的那三条SQL语句：

范例: 慢查询分析工具mysqldumpslow

[root@centos8 ~]# mysqldumpslow --help
Usage: mysqldumpslow [ OPTS... ] [ LOGS... ]

Parse and summarize the MySQL slow query log. Options are

  --verbose    verbose
  --debug      debug
  --help       write this text to standard output

  -v           verbose
  -d           debug
  -s ORDER     what to sort by (al, at, ar, c, l, r, t), 'at' is default
                al: average lock time
                ar: average rows sent
                at: average query time
                 c: count
                 l: lock time
                 r: rows sent
                 t: query time  
  -r           reverse the sort order (largest last instead of first)
  -t NUM       just show the top n queries
  -a           don't abstract all numbers to N and strings to 'S'
  -n NUM       abstract numbers with at least n digits within names
  -g PATTERN   grep: only consider stmts that include this string
  -h HOSTNAME  hostname of db server for *-slow.log filename (can be wildcard),
               default is '*', i.e. match all
  -i NAME      name of server instance (if using mysql.server startup script)
  -l           don't subtract lock time from total time
  
[root@centos8 ~]# mysqldumpslow -s c -t 2 /var/lib/mysql/centos8-slow.log

常用选项说明：

-s 即order排序,后面可以有以下选项：
al 平均锁定时间
ar 平均返回记录时间
at 平均查询时间
c 计数
l 锁定时间
r 逆序排序
t 查询时间
-t，相当于top n，即返回前面n条语句
-g， 匹配正则表达式，大小写不敏感

范例：

[root@localhost ~]# mysqldumpslow -s r -t 3 -g 'select' /data/mysql/localhost-slow.log

范例：使用explain查询sql的执行计划

mysql> explain select stuid,name,age,teacherid from students;
+----+-------------+----------+------------+------+---------------+------+---------+------+------+----------+-------+
| id | select_type | table    | partitions | type | possible_keys | key  | key_len | ref  | rows | filtered | Extra |
+----+-------------+----------+------------+------+---------------+------+---------+------+------+----------+-------+
|  1 | SIMPLE      | students | NULL       | ALL  | NULL          | NULL | NULL    | NULL |   25 |   100.00 | NULL  |
+----+-------------+----------+------------+------+---------------+------+---------+------+------+----------+-------+
1 row in set, 1 warning (0.05 sec)

参数分析：

table：表示属于哪张数据表

type：最重要的参数，表示连接使用了何种类型。从最好到最差的连接类型为const，eq_reg，ref，range，index和ALL。

possible_keys：显示可能应用在这张表中的索引。如果为null，则表示没有可能的索引。

key：实际使用的索引。如果为null，则表示没有使用索引。

key_len：使用的索引的长度，在不损失精确性的情况下，长度越短越好。

ref：表示索引的哪一列被使用了，如果可能的话，是一个常数。

rows：Mysql认为必须检查的用来返回请求数据的行数。

二进制日志(备份)

记录导致数据改变或潜在导致数据改变的SQL语句

记录已提交的日志

不依赖于存储引擎类型

功能：通过"重放"日志文件中的事件来生成数据副本

注意：建议二进制日志和数据文件分开存放

二进制日志记录三种格式
基于"语句"记录：statement，记录语句，默认模式（ MariaDB 10.2.3 版本以下 ），日志量较少

基于"行"记录：row，记录数据，日志量较大，更加安全，建议使用的格式,MySQL8.0默认格式

混合模式：mixed,让系统自行判定该基于哪种方式进行，默认模式（ MariaDB10.2.4及版本以上）

格式配置

MariaDB [hellodb]> show variables like 'binlog_format';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| binlog_format | MIXED |
+---------------+-------+
1 row in set (0.001 sec)

# MySQL 8.0 默认使用ROW方式
mysql> show variables like 'binlog_format';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| binlog_format | ROW   |
+---------------+-------+
1 row in set (0.00 sec)

二进制日志相关的服务器变量：

sql_log_bin=ON|OFF：#是否记录二进制日志，默认ON，支持动态修改，系统变量，而非服务器选项
log_bin=/PATH/BIN_LOG_FILE：#指定文件位置；默认OFF，表示不启用二进制日志功能，上述两项都开
启才可以
binlog_format=STATEMENT|ROW|MIXED：#二进制日志记录的格式，mariadb5.5默认STATEMENT
max_binlog_size=1073741824：#单个二进制日志文件的最大体积，到达最大值会自动滚动，默认为1G
#说明：文件达到上限时的大小未必为指定的精确值
binlog_cache_size=4m #此变量确定在每次事务中保存二进制日志更改记录的缓存的大小（每次连接）
max_binlog_cache_size=512m #限制用于缓存多事务查询的字节大小。
sync_binlog=1|0：#设定是否启动二进制日志即时同步磁盘功能，默认0，由操作系统负责同步日志到磁盘
expire_logs_days=N：#二进制日志可以自动删除的天数。 默认为0，即不自动删除

二进制日志文件的构成

有两类文件
1.日志文件：mysql|mariadb-bin.文件名后缀，二进制格式,如： on.000001,mariadb-bin.000002

2.索引文件：mysql|mariadb-bin.index，文本格式,记录当前已有的二进制日志文件列表

二进制日志相关配置

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

SHOW {BINARY | MASTER} LOGS

查看使用中的二进制日志文件

SHOW MASTER STATUS

在线查看二进制文件中的指定内容

SHOW BINLOG EVENTS [IN 'log_name'] [FROM pos] [LIMIT [offset,] row_count]

范例：

show binlog events in 'mysql-bin.000001' from 6516 limit 2,3

范例:

MariaDB [hellodb]> SHOW BINLOG EVENTS;

MariaDB [hellodb]> SHOW BINLOG EVENTS in 'mysql-bin.000002' from 614 limit 2,3G

MariaDB [hellodb]> SHOW BINLOG EVENTS in 'mysql-bin.000002' from 614 limit 2,3G

mysqlbinlog：二进制日志的客户端命令工具，支持离线查看二进制日志

命令格式：

mysqlbinlog [OPTIONS] log_file…
--start-position=# 指定开始位置
--stop-position=#
--start-datetime= #时间格式：YYYY-MM-DD hh:mm:ss
--stop-datetime=
--base64-output[=name]
-v -vvv

范例：

[root@localhost ~]# mysqlbinlog --start-position=678 --stop-position=752 /var/lib/mysql/mariadbbin.
000003 -v
mysqlbinlog --start-datetime="2021-05-17 20:30:10" --stop-datetime="221-05-
17 20:35:22" mariadb-bin.000003 -vvv

二进制日志事件的格式：

# at 328
#210517 16:31:40 server id 1 end_log_pos 431 Query thread_id=1
exec_time=0 error_code=0
use `mydb`/*!*/;
SET TIMESTAMP=1446712300/*!*/;
CREATE TABLE tb1 (id int, name char(30))
/*!*/;
事件发生的日期和时间：210517 16:31:40
事件发生的服务器标识：server id 1
事件的结束位置：end_log_pos 431
事件的类型：Query
事件发生时所在服务器执行此事件的线程的ID：thread_id=1
语句的时间戳与将其写入二进制文件中的时间差：exec_time=0
错误代码：error_code=0
事件内容：
GTID：Global Transaction ID，mysql5.6以mariadb10以上版本专属属性：GTID

清除指定二进制日志

PURGE { BINARY | MASTER } LOGS { TO 'log_name' | BEFORE datetime_expr }

范例：

PURGE BINARY LOGS TO 'mariadb-bin.000003'; #删除mariadb-bin.000003之前的日志
PURGE BINARY LOGS BEFORE '2021-05-16';
PURGE BINARY LOGS BEFORE '2021-05-17 09:25:30';

删除所有二进制日志，index文件重新记数

RESET MASTER [TO #]; #删除所有二进制日志文件，并重新生成日志文件，文件名从#开始记数，默认从1开始，一般是master主机第一次启动时执行，MariaDB 10.1.6开始支持TO #

切换日志文件：

FLUSH LOGS;

范例: 切换二进制日志

[root@centos8 ~]#mysqladmin flush-binary-log
[root@centos8 ~]#mysqladmin flush-logs
[root@centos8 ~]#mysql
MariaDB [hellodb]> flush logs;