MySQL日志体系详解

Posted on | In , | | 浏览 次
Words count in article: 8.2k | Reading time ≈ 34

前言

日志是MySQL数据库的重要组成部分。日志文件中记录着MySQL数据库运行期间发生的变化；也就是说用来记录MySQL数据库的客户端连接状况、SQL语句的执行情况和错误信息等。当数据库遭到意外的损坏时，可以通过日志查看文件出错的原因，并且可以通过日志文件进行数据恢复。

MySQL的日志体系有如下几种分类：

  1. 错误日志
  2. 查询日志
  3. 慢查询日志
  4. 事务日志(Redo log/undo log)
  5. 二进制日志
  6. 中继日志

其中标粗的事务日志和二进制日志，是重中之重。

1 错误日志

在默认情况下，MySQL的错误日志是开启的，且无法被禁止。在没有指定的情况下，它一般是存储在数据库的数据文件目录中，名称为hostname.err，其中，hostname为服务器主机名。

1.1 错误日志的内容

  1. 服务器启动和关闭过程中的信息，未必是错误信息，比如mysql是如何去初始化存储引擎的过程记录在错误日志里等等
  2. 服务器运行过程中的错误信息（或者告警信息），比如sock文件找不到，无法加载mysql数据库的数据文件，如果忘记初始化mysql或data dir路径找不到，或权限不正确等 都会记录在此
  3. 事件调度器运行一个事件时产生的信息，一旦mysql调度启动一个计划任务（event scheduler）的时候，它也会将相关信息记录在错误日志中
  4. 在从服务器上启动从服务器进程时产生的信息，在复制环境下，从服务器进程的信息也会被记录进错误日志

1.2 配置相关

1.2.1 开启错误日志

  1. 在/etc/my.cnf配置文件中设置：

    • 如果需要手动指定错误日志路径的话只需要在[mysqld]字段中增加相关配置：

  2. 如果没有在my.cnf配置文件中指定错误日志

    • MySQL会自动将错误日志文件存放在datadir（数据目录）下，名为hostname.err（hostname根据实际主机名变化）。

  3. 如果是通过YUM源进行安装

    • 错误日志会被配置在/var/log/mysqld.log中，这个也是由自动创建出的/etc/my.cnf所指定的。

1.2.2 设置错误日志时区

错误日志默认是使用utc时间，可以修改为系统时间方便查看

mysql > set global log_timestamps='SYSTEM'`

1.2.3 删除错误日志

在mysql5.5.7之前：数据库管理员可以删除很长时间之前的错误日志，以保证mysql服务器上的硬盘空间。mysql数据库中，可以使用mysqladmin命令开启新的错误日志。mysqladmin命令的语法如下：

mysqladmin –u root –pflush-logs

也可以使用登录mysql数据库中使用FLUSHLOGS语句来开启新的错误日志。

在mysql5.5.7之后：服务器将关闭此项功能。只能使用重命名原来的错误日志文件，手动冲洗日志创建一个新的：方式如下：

1
2
3
4
[root@stu18 data]# mv stu18.magedu.com.err  stu18.magedu.com.err.old
[root@stu18 data]#  mysqladmin flush-logs
[root@stu18 data]# ls
hellodb  myclass  mysql-bin.000003  mysql-bin.index           stu18.magedu.com.pid     ibda

或者手动清理掉错误日志

1
echo > /var/log/mysqld.log

1.3 查看错误日志和配置

查看log_error的配置：

1
2
3
4
5
6
7
mysql> show variables like 'log_error';
+---------------+---------------------+
| Variable_name | Value               |
+---------------+---------------------+
| log_error     | /var/log/mysqld.log |
+---------------+---------------------+
1 row in set (0.00 sec)

查看错误日志：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
[root@localhost mysql]# tailf /var/log/mysqld.log
130813  15:30:50  InnoDB: Starting shutdown...
130813  15:30:51  InnoDB: Shutdown completed;  log sequence number 1630920
130813 15:30:51  [Note] /usr/local/mysql/bin/mysqld: Shutdown complete
130813 15:30:52  mysqld_safe mysqld from pid file /mydata/data/stu18.magedu.com.pid ended
130813 15:30:53  mysqld_safe Starting mysqld daemon with databases from /mydata/data
130813 15:30:54  InnoDB: The InnoDB memory heap is disabled     #禁用了InnoDB memory的堆功能。
130813 15:30:54  InnoDB: Mutexes and rw_locks use GCC atomic builtins #Mutexes（互斥量）和rw_locks（行级锁）是GCC编译的是InnoDB内置的。
130813 15:30:54  InnoDB: Compressed tables use zlib 1.2.3     #默认压缩工具是zlib
130813 15:30:55  InnoDB: Initializing buffer pool, size = 128.0M    #InnoDB引擎的缓冲池（buffer pool）的值大小
130813 15:30:55  InnoDB: Completed initialization of buffer pool
130813 15:30:55  InnoDB: highest supported file format is Barracuda.
130813  15:30:57  InnoDB: Waiting for the  background threads to start
130813 15:30:58  InnoDB: 5.5.33 started; log sequence number 1630920
130813 15:30:58  [Note] Server hostname (bind-address): '0.0.0.0'; port: 3306
130813 15:30:58  [Note]   - '0.0.0.0' resolves to  '0.0.0.0';  #0.0.0.0会反解主机名，这里反解失败
130813 15:30:58  [Note] Server socket created on IP: '0.0.0.0'.
130813 15:30:58  [Note] Event Scheduler: Loaded 0 events    #事件调度器没有任何事件，因为没有装载。
130813 15:30:58  [Note] /usr/local/mysql/bin/mysqld: ready for connections. #mysql启动完成等待客户端的请求。
Version:  '5.5.33-log'  socket:  '/tmp/mysql.sock'  port: 3306  Source distribution  #创建一个本地sock用于本地连接。

2 查询日志

查询日志在MySQL中被称为general log(通用日志)，查询日志里的内容不要被”查询日志”误导，认为里面只存储select语句，其实不然，查询日志里面记录了数据库执行的所有命令，不管语句是否正确，都会被记录，因为本质上insert/update/delete语句中，都包含了查询操作:

  • insert的查询是为了避免数据冲突，如果此前插入过数据，当前插入的数据如果跟主键或唯一键的数据重复那肯定会报错
  • update时也会查询，因为更新的时候是更新某一块数据，要先根据where定位到更新的记录。
  • delete查询，只删除符合条件的数据，同样是根据where定位。

因此增删改查都会产生日志，在并发操作非常多的场景下，查询信息会非常多，那么如果都记录下来会导致IO非常大，影响MySQL性能，因此如果不是在调试环境下，是不建议开启查询日志功能的。

查询日志的开启有助于帮助我们分析哪些语句执行密集，执行密集的select语句对应的数据是否能够被缓存，同时也可以帮助我们分析问题，所以，我们可以根据自己的实际情况来决定是否开启查询日志。

2.1 查询日志配置相关

2.1.1 查看配置

所以如果你要判断MySQL数据库是否开启了查询日志，可以使用下面命令。general_log为ON表示开启查询日志，OFF表示关闭查询日志。

1
2
3
4
5
6
7
8
9
10
11
mysql> show variables like '%general_log%' or variables like '%log_output%';
+------------------+------------------------------+
| Variable_name    | Value                        |
+------------------+------------------------------+
| general_log      | OFF                          |
| general_log_file | /var/lib/mysql/DB-Server.log |
| log_output       | FILE                         |
+------------------+------------------------------+
2 rows in set (0.00 sec)

mysql>

其中：

  • 参数general_log用来控制开启、关闭MySQL查询日志
  • 参数general_log_file用来控制查询日志的位置
  • 如果开启了查询日志，参数log_output控制着查询日志的存储方式，log_output可以设置为以下4种值:
    1. FILE : 表示日志存储在文件中
    2. TABLE : 表示日志存储在mysql库中的general_log表中
    3. FILE, TABLE : 表示将日志同时存储在文件和general_log表中，改值会徒增很多IO压力，一般不会这样设置
    4. NONE : 表示不记录日志，即使general_log设置为ON， 如果log_output设置为NONE，也不会记录查询日志

log_output不仅控制查询日志的输出，也控制着慢查询日志的输出，即: log_output设置为FILE，就表示查询日志和慢查询日志都存放在文件中，设置为TABLE，查询日志和慢查询日志都存放在mysql库中的general_log表中

2.1.2 开启或关闭查询日志

  • 方法1: 在配置文件中设置(不推荐)
1
2
3
#可以在my.cnf里添加,1开启（0关闭）,当然了,这样要重启才能生效,有点多余了
general-log = 1
log_output='table'

然后重启MySQL实例

  • 方法2 : 通过命令设置
1
2
3
#也可以设置变量那样更改,1开启（0关闭）,即时生效,不用重启,首选当然是这样的了
set global general_log=1
set global log_output='table';

通过该方式设置，MySQL实例重启后，相关配置又恢复到默认值。如果只是短暂时间内使用，推荐使用命令行方式

2.1.3 修改查询日志名称或位置

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
mysql> show variables like 'general_log%';
+------------------+------------------------------+
| Variable_name    | Value                        |
+------------------+------------------------------+
| general_log      | ON                           |
| general_log_file | /var/lib/mysql/DB-Server.log |
+------------------+------------------------------+
2 rows in set (0.00 sec)

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

mysql> set global general_log_file='/u02/mysql_log.log';
Query OK, 0 rows affected (0.00 sec)

mysql> set global general_log='ON';
Query OK, 0 rows affected (0.02 sec)

2.2 查询日志的查看

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
mysql> select * from mysql.general_log;
+---------------------+---------------------------+-----------+-----------+--------------+----------------------------------+
| event_time          | user_host                 | thread_id | server_id | command_type | argument                         |
+---------------------+---------------------------+-----------+-----------+--------------+----------------------------------+
| 2017-07-06 12:32:05 | root[root] @ localhost [] |         1 |         1 | Query        | show variables like 'general%'   |
| 2017-07-06 12:32:28 | root[root] @ localhost [] |         1 |         1 | Query        | show variables like 'log_output' |
| 2017-07-06 12:32:41 | root[root] @ localhost [] |         1 |         1 | Query        | select * from MyDB.test          |
| 2017-07-06 12:34:36 | [root] @ localhost []     |         3 |         1 | Connect      | root@localhost on                |
| 2017-07-06 12:34:36 | root[root] @ localhost [] |         3 |         1 | Query        | KILL QUERY 1                     |
| 2017-07-06 12:34:36 | root[root] @ localhost [] |         3 |         1 | Quit         |                                  |
| 2017-07-06 12:34:51 | root[root] @ localhost [] |         1 |         1 | Query        | select * from mysql.general_log  |
+---------------------+---------------------------+-----------+-----------+--------------+----------------------------------+
7 rows in set (0.02 sec)

mysql>

2.3 查询日志的归档

1
2
3
4
5
mysql> system mv /var/lib/mysql/DB-Server.log  /var/lib/mysql/DB-Server.log.20170706

mysql> system mysqladmin flush-logs -p

Enter password:

或者你在shell中执行下面命令

1
2
3
4
5
[root@DB-Server mysql]# mv /var/lib/mysql/DB-Server.log  /var/lib/mysql/DB-Server.log.20170706

[root@DB-Server mysql]# mysqladmin flush-logs -p

Enter password:

3 慢查询日志

慢查询会导致CPU，IOPS，内存消耗过高。当数据库遇到性能瓶颈时，大部分时间都是由于慢查询导致的。 开启慢查询日志，可以让MySQL记录下查询超过指定时间的语句，之后运维人员通过定位分析，能够很好的优化数据库性能。

慢查询日志记录的慢查询不仅仅是执行比较慢的SELECT语句，还有INSERT，DELETE，UPDATE，CALL等DML操作，只要超过了指定时间，都可以称为”慢查询”，被记录到慢查询日志中。

默认情况下，慢查询日志是不开启的，只有手动开启了，慢查询才会被记录到慢查询日志中。

3.1 慢查询日志配置相关

3.1.1 查看配置

1
2
3
4
5
6
7
8
9
10
11
12
mysql> show variables like "%slow%" or variables like "%log_queries_not_using_indexes%";
+-------------------------------+-------------------------------------------------+
| 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           | /var/lib/mysql/iz2zeaf3cg1099kiidi06mz-slow.log |
| log_queries_not_using_indexes | ON                                              |
+-------------------------------+-------------------------------------------------+
5 rows in set (0.00 sec)

其中

  • slow_query_log：慢查询开关，表示是否打开慢查询日志
  • long_query_time：慢查询指定时间设置，表示”多长时间的查询”被认定为”慢查询”，单位是秒(s)，默认是10s，即超过10s的查询都被认定为慢查询。
  • log_queries_not_using_indexes：表示如果运行的SQL语句没有使用到索引，是否也被当作慢查询语句记录到慢查询记录中，OFF表示不记录，ON表示记录。
  • 如果开启了查询日志，参数log_output控制着查询日志的存储方式，log_output可以设置为以下4种值:
    1. FILE : 表示日志存储在文件中
    2. TABLE : 表示日志存储在mysql库中的general_log表中
    3. FILE, TABLE : 表示将日志同时存储在文件和general_log表中，改值会徒增很多IO压力，一般不会这样设置
    4. NONE : 表示不记录日志，即使general_log设置为ON， 如果log_output设置为NONE，也不会记录查询日志
  • slow_query_log_file：当使用文件存储慢查询日志时(log_output设置为”FILE”或者”FILE,TABLE”时)，制定慢查询日志存储在哪个文件中，默认的文件名是”主机名-slow.log”，存储目录为数据目录
  • log_throttle_queries_not_using_indexes: MySQL5.6.5版本新引入的参数，用来限制没有使用索引的语句每分钟记录到慢查询日志中的次数。在生产环境中，有可能有很多没有使用索引的语句，可能会导致慢查询日志快速增长。

log_output不仅控制查询日志的输出，也控制着慢查询日志的输出，即: log_output设置为FILE，就表示查询日志和慢查询日志都存放在文件中，设置为TABLE，查询日志和慢查询日志都存放在mysql库中的general_log表中

3.1.2 开启或关闭慢查询日志

  • 方法1: 在配置文件中设置(不推荐)
1
2
#可以在my.cnf里添加,1开启（0关闭）,当然了,这样要重启才能生效,有点多余了
slow_query_log=1

然后重启MySQL实例

  • 方法2 : 通过命令设置
1
2
3
4
5
6
7
8
9
10
11
#也可以设置变量那样更改,ON开启（OFF关闭）,即时生效,不用重启,首选当然是这样的了
mysql> set global slow_query_log='ON';
Query OK, 0 rows affected (0.00 sec)

# 设置慢查询时间
mysql> set global long_query_time=0.05;
Query OK, 0 rows affected (0.00 sec)

# 关闭慢查询
mysql> set global slow_query_log='OFF';
Query OK, 0 rows affected (0.00 sec)

通过该方式设置，MySQL实例重启后，相关配置又恢复到默认值。如果只是短暂时间内使用，推荐使用命令行方式

设置long_query_time这个阈值之后，MySQL数据库会记录运行时间超过该值的所有SQL语句，但对于运行时间正好等于 long_query_time 的情况，并不会被记录下。可以设置 long_query_time为0来捕获所有的查询

3.1.3 查看当前有多少条慢日志

如果你想查询有多少条慢查询记录，可以使用系统变量。

1
2
3
4
5
6
7
8
9
mysql> show global status like '%slow_queries%';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| Slow_queries  | 0     |
+---------------+-------+
1 row in set (0.00 sec)

mysql> `

3.2 慢查询日志分析工具pt-query-digest

3.2.1 pt-query-digest的使用

pt-query-digest 是分析MySQL查询日志最有力的工具，该工具功能强大，它可以分析binlog，Generallog，slowlog，也可以通过show processlist或者通过 tcpdump 抓取的MySQL协议数据来进行分析，比 mysqldumpslow 更具体，更完善。

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

在windows下，下载tar.gz包，解压之后，使用perl命令运行

其命令格式如下：

1
2
3
4
5
6
7
8
9
10
11
12
13
pt-query-digest [OPTIONS] [FILES] [DSN]
--create-review-table  当使用--review参数把分析结果输出到表中时，如果没有表就自动创建。
--create-history-table  当使用--history参数把分析结果输出到表中时，如果没有表就自动创建。
--filter  对输入的慢查询按指定的字符串进行匹配过滤后再进行分析
--limit    限制输出结果百分比或数量，默认值是20,即将最慢的20条语句输出，如果是50%则按总响应时间占比从大到小排序，输出到总和达到50%位置截止。
--host  mysql服务器地址
--user  mysql用户名
--password  mysql用户密码
--history 将分析结果保存到表中，分析结果比较详细，下次再使用--history时，如果存在相同的语句，且查询所在的时间区间和历史表中的不同，则会记录到数据表中，可以通过查询同一CHECKSUM来比较某类型查询的历史变化。
--review 将分析结果保存到表中，这个分析只是对查询条件进行参数化，一个类型的查询一条记录，比较简单。当下次使用--review时，如果存在相同的语句分析，就不会记录到数据表中。
--output 分析结果输出类型，值可以是report(标准分析报告)、slowlog(Mysql slow log)、json、json-anon，一般使用report，以便于阅读。
--since 从什么时间开始分析，值为字符串，可以是指定的某个”yyyy-mm-dd [hh:mm:ss]”格式的时间点，也可以是简单的一个时间值：s(秒)、h(小时)、m(分钟)、d(天)，如12h就表示从12小时前开始统计。
--until 截止时间，配合—since可以分析一段时间内的慢查询。

3.2.2 pt-query-digest的结果

输出结果分为三部分

  1. 总体统计结果
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
# 该工具执行日志分析的用户时间，系统时间，物理内存占用大小，虚拟内存占用大小
# 343ms user time, 78ms system time, 0 rss, 0 vsz
# 工具执行时间
# Current date: Thu Mar 29 15:51:38 2018
# 运行分析工具的主机名
# Hostname: NB2015041602
# 被分析的文件名
# Files: /d/xampp/mysql/data/NB2015041602-slow.log
# 语句总数量，唯一的语句数量，QPS，并发数
# Overall: 5 total, 3 unique, 0.00 QPS, 0.05x concurrency ________________
# 日志记录的时间范围
# Time range: 2018-03-28 14:02:06 to 14:22:10
# 属性               总计      最小    最大    平均    95%  标准    中等
# Attribute          total     min     max     avg     95%  stddev  median
# ============     ======= ======= ======= ======= ======= ======= =======
# 语句执行时间
# Exec time            60s     10s     17s     12s     17s      3s     11s
# 锁占用时间
# Lock time            1ms       0   500us   200us   490us   240us       0
# 发送到客户端的行数
# Rows sent             50      10      10      10      10       0      10
# select语句扫描行数
# Rows examine     629.99k  45.43k 146.14k 126.00k 143.37k  39.57k 143.37k
# 查询的字符数
# Query size         2.81k     235   1.36k  575.40   1.33k  445.36  234.30
  1. 查询分组统计结果
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
# rank：所有语句的排序，默认按照查询时间降序排序，通过--order-by指定
# # query id：语句的id，（去掉多余空格和文本字符，计算hash值）
# response：总的响应时间
# time：该查询在本次分析中总的时间占比
# calls：执行次数，即本次分析总共有多少条这种类型的查询语句
# r/call：平均每次执行的响应时间
# v/m：响应时间variance-to-mean的比率
# item：查询对象

# Profile
# Rank Query ID           Response time Calls R/Call  V/M   Item
# ==== ================== ============= ===== ======= ===== ==============
#    1 0x96112A601F7BCCC0 32.9042 55.0%     3 10.9681  0.01 SELECT affiliatemerchant_list user_list
#    2 0x70885F9703A0E38D 17.2162 28.8%     1 17.2162  0.00 SELECT normalmerchant merchant_mapping normalmerchant_addinfo merchant_search_filter affiliatemerchant_list user_list
#    3 0x43D8527285567FC4  9.7367 16.3%     1  9.7367  0.00 SELECT affiliatemerchant_list user_list affiliatemerchant_list user_list
  1. 每一种查询的详细统计结果
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
# id：查询的id号，和上面的query id对应
# # databases：数据库名
# users：各个用户执行的次数（占比）
# query_time_distribution：查询时间分布，长短体现区间占比
# tables：查询中设计到的表
# explain：sql语句

# Query 1: 0.00 QPS, 0.03x concurrency, ID 0x96112A601F7BCCC0 at byte 2647
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.01
# Time range: 2018-03-28 14:03:31 to 14:19:54
# Attribute    pct   total     min     max     avg     95%  stddev  median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count         60       3
# Exec time     54     33s     11s     11s     11s     11s   243ms     11s
# Lock time     50   500us       0   500us   166us   490us   231us       0
# Rows sent     60      30      10      10      10      10       0      10
# Rows examine  69 438.42k 146.14k 146.14k 146.14k 146.14k       0 146.14k
# Query size    24     707     235     236  235.67  234.30       0  234.30
# String:
# Databases    database_base
# Hosts        localhost
# Users        root
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms
#    1s
#  10s+  ################################################################
# Tables
#    SHOW TABLE STATUS FROM `database_base` LIKE 'table_list1'\G
#    SHOW CREATE TABLE `database_base`.`table_list1`\G
#    SHOW TABLE STATUS FROM `database_base` LIKE 'user_list'\G
#    SHOW CREATE TABLE `database_base`.`user_list`\G
# EXPLAIN /*!50100 PARTITIONS*/
select SQL_CALC_FOUND_ROWS al.*, ul.Alias as userName
        FROM table_list1 al
        LEFT JOIN user_list ul ON ul.ID = al.UserId
         WHERE TRUE  AND (al.SupportCountrys LIKE '%%')
         limit 80, 10\G

3.2.3 pt-query-digest的命令

以下是使用pt-query-digest的示例:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
//直接分析慢查询文件
pt-query-digest  slow.log > slow_report.log

分析最近12小时内的查询
pt-query-digest  --since=12h  slow.log > slow_report2.log

分析指定时间范围内的查询
pt-query-digest slow.log --since '2017-01-07 09:30:00' --until '2017-01-07 10:00:00'> > slow_report3.log

分析含有select语句的慢查询
pt-query-digest --filter '$event->{fingerprint} =~ m/^select/i' slow.log> slow_report4.log

针对某个用户的慢查询
pt-query-digest --filter '($event->{user} || "") =~ m/^root/i' slow.log> slow_report5.log

查询所有全表扫描或full join的慢查询
pt-query-digest --filter '(($event->{Full_scan} || "") eq "yes") ||(($event->{Full_join} || "") eq "yes")' slow.log> slow_report6.log

把查询保存到query_review表
pt-query-digest --user=root –password=abc123 --review  h=localhost,D=test,t=query_review--create-review-table  slow.log

把查询保存到query_history表
pt-query-digest  --user=root –password=abc123 --review  h=localhost,D=test,t=query_history--create-review-table  slow.log_0001
pt-query-digest  --user=root –password=abc123 --review  h=localhost,D=test,t=query_history--create-review-table  slow.log_0002

通过tcpdump抓取的tcp协议数据，然后分析
tcpdump -s 65535 -x -nn -q -tttt -i any -c 1000 port 3306 > mysql.tcp.txt
pt-query-digest --type tcpdump mysql.tcp.txt> slow_report9.log

分析biglog
mysqlbinlog mysql-bin.000093 > mysql-bin000093.sql
pt-query-digest  --type=binlog  mysql-bin000093.sql > slow_report10.log

分析general log
pt-query-digest  --type=genlog  localhost.log > slow_report11.log

该工具可以将查询的剖析报告打印出来，可以分析结果输出到文件中，分析过程是先对查询语句的条件进行参数化，然后对参数化以后的查询进行分组统计，统计出各查询的执行时间，次数，占比等，可以借助分析结果找出问题进行优化。

3.3 慢查询日志分析工具mysqldumpslow

mysqldumpslow是mysql自身提供的日志分析工具，一般在mysql的bin目录下

帮助信息如下：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
$ mysqldumpslow.pl --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, 是表示按照何种方式排序
    c: 访问计数

    l: 锁定时间

    r: 返回记录

    t: 查询时间

    al:平均锁定时间

    ar:平均返回记录数

    at:平均查询时间

-t, 是top n的意思，即为返回前面多少条的数据；
-g, 后边可以写一个正则匹配模式，大小写不敏感的；

比如:
得到返回记录集最多的10个SQL。
mysqldumpslow -s r -t 10 /database/mysql/mysql06_slow.log

得到访问次数最多的10个SQL
mysqldumpslow -s c -t 10 /database/mysql/mysql06_slow.log

得到按照时间排序的前10条里面含有左连接的查询语句。
mysqldumpslow -s t -t 10 -g “left join” /database/mysql/mysql06_slow.log

另外建议在使用这些命令时结合 | 和more 使用 ，否则有可能出现刷屏的情况。
mysqldumpslow -s r -t 20 /mysqldata/mysql/mysql06-slow.log | more

如果不能执行，可以先安装perl，然后通过perl mysqldumpslow xxx.log

4 事务日志

事务日志包括redo log和undo log，在阐述二者之前，我们必须明确，redo log是InnoDB引擎的一类日志，而不是MySQL服务端的日志。它是InnoDB实现事务的重要机制。

具体内容详见本博客文章《【InnoDB详解四】redo log和undo log》

5 二进制日志

MySQL的二进制日志（binary log，简称binlog）是一个二进制文件，主要记录所有数据库表结构变更（例如CREATE、ALTER TABLE…）以及表数据修改（INSERT、UPDATE、DELETE…）的所有操作。二进制日志（binary log）中记录了对MySQL数据库执行更改的所有操作，并且记录了语句发生时间、执行时长、操作数据等其它额外信息，但是它不记录SELECT、SHOW等那些不修改数据的SQL语句。

它和InnoDB的redo log很像，但注意redo log是InnoDB的，是引擎级别的，binlog是MySQL级别的，换言之，不论MySQL使用什么存储引擎，它都会产生binlog。

5.1 binlog的作用

  1. 恢复（recovery）：某些数据的恢复需要二进制日志。例如，在一个数据库全备文件恢复后，用户可以通过二进制日志进行point-in-time的恢复。

  2. 复制（replication）：其原理与恢复类似，通过复制和执行二进制日志使一台远程的MySQL数据库（一般称为slave或者standby）与一台MySQL数据库（一般称为master或者primary）进行实时同步。

  3. 审计（audit）：用户可以通过二进制日志中的信息来进行审计，判断是否有对数据库进行注入攻击。

除了上面介绍的几个作用外，binlog对于事务存储引擎的崩溃恢复也有非常重要的作用。

在开启binlog的情况下，为了保证binlog与redo的一致性，MySQL将采用事务的两阶段提交协议。当MySQL系统发生崩溃时，事务在存储引擎内部的状态可能为prepared和commit两种。对于prepared状态的事务，是进行提交操作还是进行回滚操作，这时需要参考binlog：如果事务在binlog中存在，那么将其提交；如果不在binlog中存在，那么将其回滚，这样就保证了数据在主库和从库之间的一致性。

5.2 binlog的存储

为了管理所有的binlog文件，MySQL额外创建了一个base-name.index文件，它按顺序记录了MySQL使用的所有binlog文件。如果你想自定义index文件的名称，可以设置log_bin_index=file参数。千万不要在mysqld运行的时候手动修改index文件的内容，这样会使mysqld产生混乱。

5.3 binlog的开启

binlog默认关闭，如果想开启binlog，可以在MySQL配置文件中通过配置参数log-bin = [base-name]启动二进制日志。如果不指定base-name，则默认以主机名为二进制日志的文件名，并以自增的数字作为后缀，例如mysql-bin.000001，所在目录为数据库所在目录（datadir）。

顺序说一下，对于二进制文件当满足下面三种情况时会创建新的文件，文件后缀会自增。

  1. 文件大小达到max_binlog_size参数设置值时。
  2. 执行flush logs命令。
  3. 重启mysqld进程。

你可能会有顾虑，当文件后缀从000001增长到999999时会怎样？有网友测试过，当文件达到999999时又会回到000001，并不会有什么异常。

5.4 binlog格式

binlog格式分为: STATEMENT、ROW和MIXED三种，详情如下:

  1. STATEMENT

    • STATEMENT格式的binlog记录的是数据库上执行的原生SQL语句。
    • 这种方式有好处：
      • 好处就是相当简单，简单地记录和执行这些语句，能够让主备保持同步，在主服务器上执行的SQL语句，在从服务器上执行同样的语句。
      • 另一个好处是二进制日志里的时间更加紧凑，所以相对而言，基于语句的复制模式不会使用太多带宽，同时也节约磁盘空间。并且通过mysqlbinlog工具容易读懂其中的内容。
    • 这种方式也有坏处：
      • 坏处就是同一条SQL在主库和从库上执行的时间可能稍微或很大不相同，因此在传输的二进制日志中，除了查询语句，还包括了一些元数据信息，如当前的时间戳。
        • 即便如此，还存在着一些无法被正确复制的SQL。例如，使用INSERT INTO TB1 VALUE(CUURENT_DATE())这一条使用函数的语句插入的数据复制到当前从服务器上来就会发生变化。存储过程和触发器在使用基于语句的复制模式时也可能存在问题。
        • 另外一个问题就是基于语句的复制必须是串行化的。这要求大量特殊的代码，配置，例如InnoDB的next-key锁等。并不是所有的存储引擎都支持基于语句的复制。

  2. ROW

    • 从MySQL5.1开始支持基于行的复制，也就是基于数据的复制，基于行的更改。这种方式会将实际数据记录在二进制日志中。
    • 这种方式有好处：
      • 最大的好处是可以正确地复制每一行数据。一些语句可以被更加有效地复制
      • 另外就是几乎没有基于行的复制模式无法处理的场景，对于所有的SQL构造、触发器、存储过程等都能正确执行。
    • 这种方式也有坏处：
      • 主要的缺点就是二进制日志可能会很大，而且不直观，所以，你不能使用mysqlbinlog来查看二进制日志。也无法通过看二进制日志判断当前执行到那一条SQL语句了。

现在对于ROW格式的二进制日志基本是标配了，主要是因为它的优势远远大于缺点。并且由于ROW格式记录行数据，所以可以基于这种模式做一些DBA工具，比如数据恢复，不同数据库之间数据同步等。

  1. MIXED

    • MIXED也是MySQL默认使用的二进制日志记录方式，但MIXED格式默认采用基于语句的复制，一旦发现基于语句的无法精确的复制时，就会采用基于行的复制。比如用到UUID()、USER()、CURRENT_USER()、ROW_COUNT()等无法确定的函数。

6 中继日志

relay log是复制过程中产生的日志，很多方面都跟binary log差不多，区别是: relay log是从库服务器I/O线程将主库服务器的二进制日志读取过来记录到从库服务器本地文件，然后从库的SQL线程会读取relay-log日志的内容并应用到从库服务器上。

6.1 中继日志参数

  • max_relay_log_size
    标记relay log 允许的最大值，如果该值为0，则默认值为max_binlog_size(1G)；如果不为0，则max_relay_log_size则为最大的relay_log文件大小；

  • relay_log
    定义relay_log的位置和名称，如果值为空，则默认位置在数据文件的目录，文件名为host_name-relay-bin.nnnnnn（By default, relay log file names have the form host_name-relay-bin.nnnnnn in the data directory）；

  • relay_log_index
    同relay_log，定义relay_log的位置和名称；

  • relay_log_info_file
    设置http://relay-log.info的位置和名称（http://relay-log.info记录MASTER的binary_log的恢复位置和relay_log的位置）

  • relay_log_purge
    是否自动清空不再需要中继日志时。默认值为1(启用)。

  • relay_log_recovery
    当slave从库宕机后，假如relay-log损坏了，导致一部分中继日志没有处理，则自动放弃所有未执行的relay-log，并且重新从master上获取日志，这样就保证了relay-log的完整性。默认情况下该功能是关闭的，将relay_log_recovery的值设置为 1时，可在slave从库上开启该功能，建议开启。

  • relay_log_space_limit
    防止中继日志写满磁盘，这里设置中继日志最大限额。但此设置存在主库崩溃，从库中继日志不全的情况，不到万不得已，不推荐使用；

  • sync_relay_log
    这个参数和sync_binlog是一样的，当设置为1时，slave的I/O线程每次接收到master发送过来的binlog日志都要写入系统缓冲区，然后刷入relay log中继日志里，这样是最安全的，因为在崩溃的时候，你最多会丢失一个事务，但会造成磁盘的大量I/O。当设置为0时，并不是马上就刷入中继日志里，而是由操作系统决定何时来写入，虽然安全性降低了，但减少了大量的磁盘I/O操作。这个值默认是0，可动态修改。

  • sync_relay_log_info
    这个参数和sync_relay_log参数一样，当设置为1时，slave的I/O线程每次接收到master发送过来的binlog日志都要写入系统缓冲区，然后刷入http://relay-log.info里，这样是最安全的，因为在崩溃的时候，你最多会丢失一个事务，但会造成磁盘的大量I/O。当设置为0时，并不是马上就刷入http://relay-log.info 里，而是由操作系统决定何时来写入，虽然安全性降低了，但减少了大量的磁盘I/O操作。这个值默认是0，可动态修改。

0%