MySQL 中的日志主要包括了:错误日志、查询日志、慢查询日志、事务日志、二进制日志,在此,介绍下一些常见的配置,以及 BinLog 相关内容。
简介
MySQL 的日志子系统主要包括 error log
、binlog
、general log
三种类型的日志,可以通过如下命令查看与日志相关的配置参数。
mysql> SHOW GLOBAL VARIABLES LIKE '%log%';
错误日志 (error log)
默认情况下错误日志大概记录以下几个方面的信息:
- 服务器启动和关闭过程中的信息;
- 服务器运行过程中的错误信息;
- 事件调度器运行一个事件时产生的信息;
- 在从服务器上启动服务器进程时产生的信息。
[mysqld]
log_error = localhost.err # 使用datadir相对路径,如果没有err后缀会自动添加
log_error = /PAHT/TO/LOG/ # 指定绝对路径,默认是hostname.err,主机名可以为空
log_warnings = 1 # 是否将警告信息记录进错误日志,0(禁用),1(启用)
# >1(建新连接时产生的"失败的连接"和"拒绝访问"类的错误信息)
设置完后,可通过 SHOW VARIABLES LIKE 'log_error'
查看具体路径;在 5.5.7 前,可以通过 FLUSH LOGS
保存老的日志,并开辟新的日志文件;之后只能 mv
之后再 FLUSH LOGS
。
mysql> flush logs;
$ mysqladmin flush-logs
$ mysqladmin refresh
查询日志 (general log)
记录了客户端的连接、关闭、发送的 SQL 请求,当怀疑客户端有问题,且想查看客户端发送的 SQL 请求时可以打开该日志;线上不建议使用。
[mysqld]
general_log = OFF # 是否开启一般查询日志
log_output = FILE # 日志输出对象,FILE(文件),TALBE(表),NONE(不记录)
general_log_file = hostname.log # 查询日志文件名
慢查询日志 (slow qurey log)
用来记录慢查询,当超过了 long_query_time
指定的时间之后,会输出到 slow_query_log_file
指定的文件中。这里的语句执行时长为实际的执行时间,而非在 CPU 上的执行时长,对于负载较重的服务器上更容易产生慢查询。
slow_query_log = OFF # 是否记录超过long_query_time时间的慢查询
log_output = FILE # 同上,可作用于查询日志和慢查询日志
# 如果是TABLE,会在mysql库下生成general_log和slow_log
slow_query_log_file = slow.log # 设定文件格式的慢查询日志的存储路径
long_query_time = 10.000000 # 区别慢查询与一般查询的语句执行时间长度
log_queries_not_using_indexes = ON # 记录没有使用索引的SQL
log_slow_admin_statements = ON # 记录表管理语句
log_slow_slave_statements = ON # 记录主备复制时,超时的SQL
expire_logs_days = 0 # 超出此天数的二进制日志文件将被自动删除
min_examined_row_limit = 100 # 查询检查返回少于该参数指定行的SQL不被记录到慢查询日志
log_throttle_queries_not_using_indexes = 0 # 每分钟允许记录到slow log的且未使用索引的SQL语句次数
对于慢查询日志,可以通过 MySQL 自带的 mysqldumpslow
命令行查看。
二进制日志 (binary log)
log_bin = mysql-bin # 启用二进制日志记录功能,静态变量(设置需重启)
log_bin_index = mysql-bin.index # 二进制索引文件的路径与名称
binlog-format = ROW # binlog的记录格式,包括ROW|STATEMENT|MIXED三种
sync_binlog = 1 # 日志缓存刷新时机,详见下面介绍
max_binlog_size = 1073741824 # 指定单个二进制日志文件的最大值,默认1GB
log_slave_updates = OFF # (备库)是否将接收到的记录到本地binlog,用于级联复制
expire_logs_days = 3 # 实现自动删除binlog,保留3天
binlog_cache_size = 1M # 为每个会话分配的binlog内存大小
max_binlog_cache_size = 184467440737 # 设置binlog最大可用内存
注意,max_binlog_size
并不能严格控制 Binlog 的大小,尤其是 Binlog 比较靠近最大值而又遇到一个比较大事务时,为了保证事务的完整性,不可能做切换日志的动作,只能将该事务的所有 SQL 都记录进当前日志,直到事务结束
中继日志 (relay log)
relay_log = relay-log # 开启中继日志
relay_log_index = relay-log.index # 中继日志索引文件的名称
relay_log_info_repository = FILE # 中继日志位置写入对象,FILE(文件) TABLE(表slave_relay_log_info)
relay_log_info_file = relay-log.info # 记录中继日志的文件和事件位置以及二进制的文件和事件位置
relay_log_recovery = ON # (备库)relaylog自动修复,避免网络等造成损坏,导致主从停止
relay_log_purge = ON # (备库)启动自动清除中继日志
master_info_repository = TABLE # (备库)保存主机相关信息master.info(FILE)
# slave_master_info(TABLE)
relay_log_info_repository = TABLE # (备库)记录relaylog相关信息relay-log.info(FILE)
# slave_relay_log_info(TABLE)
log_slave_updates = OFF # (备库)是否将接收到的记录到本地binlog,用于级联复制
对于 relay_log_recovery
参数,当 slave 从库宕机后,假如 relay-log 损坏,会导致一部分中继日志没有处理,则自动放弃所有未执行的 relay-log,并且重新从 master 上获取日志,从而保证 relay-log 的完整性。
Binlog
这个是比较重要的日志,该日志用于记录所有更新了数据的所有语句,可以用于实时备份,或者 master/slave 复制,如果要打开该功能需要重启。
[mysqld]
log-bin=mysql-bin
binlog_format=mixed
对于过期不需要的 binlog,为了节省空间,可以手工删除或自动删除,相关的 SQL 命令有。
----- 常用操作
mysql> SET sql_log_bin=ON; ← 启用(ON)或禁用(OFF)当前会话的binlog记录
mysql> SET GLOBAL expire_logs_days = 10; ← 设置binlog过期时间
mysql> SHOW BINARY LOGS; ← 查找当前有哪些二进制日志文件
mysql> SHOW BINLOG EVENTS IN 'mysql-bin.000001'; ← 查看日志详细信息
mysql> FLUSH LOGS; ← 切换到新的binlog
mysql> SHOW MASTER LOGS; ← 同上,查看master的binlog日志
mysql> SHOW MASTER STATUS; ← 查看master二进制日志文件的状态信息
mysql> SHOW SLAVE HOSTS; ← 显示当前注册的slave的列表
← 需要--report-host参数指定
----- 日志手动清理,可以指定master/binary
mysql> RESET MASTER; ← 删除master的binlog
mysql> RESET SLAVE; ← 删除slave的中继日志
mysql> PURGE MASTER LOGS BEFORE '2012-03-30 17:20:00'; ← 指定日期删除
mysql> PURGE BINARY LOGS TO 'mysql-bin.000018'; ← 指定文件删除
mysql> PURGE MASTER LOGS BEFORE DATE_SUB( NOW( ), INTERVAL 3 DAY);
$ mysqlbinlog mysql-bin.000003 | less ← 查看日志文件的内容
$ mysqlbinlog --start-datetime='2015-08-05 00:00:00' --stop-datetime='2015-08-05 10:00:00' \
--database=db_name mysql-bin.000001
$ mysqlbinlog --start-postion=107 --stop-position=1000 --database=db_name mysql-bin.000001
----- 从远程服务器读取
$ mysqlbinlog -u username -p password -h127.1 -P3306 --read-from-remote-server \
--start-datetime='2015-08-05 00:00:00' --stop-datetime='2015-08-05 10:00:00' mysql-bin.000001
$ mysqlbinlog --base64-output=decode-rows mysql-bin.000003
其中,与之相关的文件有 mysql-bin.NUM
、mysql-bin.index
;后者以文本格式保留了未被 purge 的 binlog 文件;前者为真正的 binlog 文件,以二进制形式存在,可以通过 mysqlbinlog 读取。
配置
对于 binlog 的配置项可以参考如下,只列举了部分常用的。
cache
会为每个 session 分配 binlog_cache_size
大小的内存,在事务过程中用来保存 binlog 缓存;如果没有大事务,DML 操作不频繁,那么可以适当的调小一点。
max_binlog_cache_size # 设置binlog最大可用内存
binlog_cache_size = 1M # 为每个会话分配的binlog内存大小
上述参数可通过状态 binlog_cache_use
和 binlog_cache_disk_use
来帮助设置合理的区间值。
binlog_cache_use
使用缓存binlog的次数
binlog_cache_disk_use
超过binlog_cache_size值,导致缓存不足,从而使用临时文件来保存事务的次数
当 binlog_cache_disk_use
比较大时,可以考虑适当的调高 binlog_cache_size
对应的值;当执行多语句的事务时,如果所有会话使用的内存超过 max_binlog_cache_size
的值时,会报如下错误:
Multi-statement transaction required more than 'max_binlog_cache_size' bytes of storage;
increase this mysqld variable and try again
磁盘刷新
可以通过 sync_binlog 参数设置刷盘的时机,该值将直接影响 MySQL 的性能和日志的完整性。
sync_binlog=0
事务提交后,仅是将 binlog_cache 中的数据写入 Binlog 文件,但不执行fsync
之类的磁盘同步操作通知文件系统将缓存刷新到磁盘,而让文件系统自行决定什么时候来做同步,此时性能最好。sync_binlog=N
在执行了 N 次事务提交后,MySQL 将执行一次fsync
之类的磁盘同步指令,此时文件系统将 Binlog 文件缓存刷新到磁盘。
默认值是 0,即不作任何强制性的磁盘刷新指令,这时性能是最好的,但风险也是最大的;一旦系统 Crash,在文件系统缓存中的所有 Binlog 信息都会丢失。
文件格式
有三种格式,也对应了 MySQL 的复制技术,分别是:基于SQL语句的复制 (Statement-Based Replication, SBR),基于行的复制 (Row-Based Replication, RBR),混合模式复制 (Mixed-Based Replication, MBR)。
可以通过如下 SQL 查看当前 binlog 的格式,包括了三种:STATEMENT
、ROW
、MIXED
;默认采用的是 MIXED
。
mysql> SHOW VARIABLES LIKE 'binlog_format'; ← 查看binlog格式
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| binlog_format | MIXED |
+---------------+-------+
1 row in set (0.01 sec)
mysql> SET GLOBAL binlog_format = 'STATEMENT'; ← 设置格式,还可以为ROW,MIXED
Query OK, 0 rows affected (0.03 sec)
mysql> FLUSH LOGS; ← 切换日志
Query OK, 0 rows affected (0.03 sec)
mysql> SHOW BINARY LOGS; ← 查看binlog日志
+-----------------+-----------+
| Log_name | File_size |
+-----------------+-----------+
| mysql-bin.000001| 409 |
| mysql-bin.000002| 346 |
+-----------------+-----------+
2 rows in set (0.00 sec)
mysql> SHOW BINLOG EVENTS; ← 查看执行的SQL
mysql> SHOW BINLOG EVENTS IN 'mysql-bin.000002'; ← 查看指定binlog文件的内容
mysql> SHOW BINLOG EVENTS FROM 213; ← 指定位置binlog的内容
下面简单介绍上述的不同 binlog 日志格式。
Statement
MySQL 5.0 之前仅支持基于语句的复制,也叫做逻辑复制 (Logical Replication);主会记录下执行的 SQL,然后,备从中继日志中读取事件,并执行它,这些 SQL 语句与主执行的语句一样。
优点:
最先实现,技术比较成熟;
可以方便的显示SQL语句,日志可用于安全审计;
DDL语句总是被记录成statement,即便你设置的是row模式;
生成文件较小;
事件类型是:0x02(Query_log_event);
方便mysqlbinlog处理;
主从版本可以不一样,从服务器版本可以比主服务器版本高;
缺点:
部分UPDATE语句无法复制,尤其是包含不确定操作的时候,如RAND();
一些元数据信息,存储过程和触发器等就可能会出错;
使用以下函数的语句也无法被复制,也就是Unsafe/non-deterministic statements:
* User-defined functions (UDF)
* UUID(), FOUND_ROWS(), RAND(), USER(), LOAD_FILE()
* Updates using LIMIT
* SYSDATE() (除非启动时启用了 --sysdate-is-now 选项)
数据表必须和主服务器保持一致,否则可能会导致复制出错;
另外,基于语句的复制必须是串行化的,从而导致大量特殊的代码、配置等。
Row
在 5.1 之后被引入,该方式会在二进制日志中记录下实际数据的改变,优点就是可以对任何语句都能正确工作,一些语句的效率更高;主要的缺点就是二进制日志可能会很大,而且不直观。
优点:
对于非确定性函数:UUID等,都是安全的;
事件类型为 Table_map, Write_rows, Update_rows, Delete_rows
任何情况都可以被复制,这对复制来说是最安全可靠的;
执行 INSERT,UPDATE,DELETE 语句时锁更少;
从服务器上采用多线程来执行复制成为可能;
缺点:
文件大了很多,尤其是一条语句更新全表的情况;
只有DML语句才能记录成row模式;
无法从binlog查看复制语句;
Mixed
前两者的结合,默认以 statment
格式记录,当遇到 non-deterministic statements
语句时,自动转换成 row
模式。
总结
对于 INSERT,UPDATE,DELETE 之类的直接操作表的情况,则日志格式根据 binlog_format 的设定而记录;而对于 GRANT,REVOKE,SET PASSWORD 等语句来说,均采用 SBR 模式记录。
Binlog 解析
其中 mysql-bin.index
没什么需要详细解释的;下面,着重看下二进制 binlog 文件,文件格式有以下特点:
binlog
由event
组成,event
是binlog
的最小逻辑单元;- 文件头的头四个字节为固定的
BINLOG_MAGIC (fe 62 69 6e)
,后三个为ASCII
码的bin
; - 接着的四字节是
descriptor event (FORMAT_DESCRIPTION_EVENT)
,记录了版本信息等; - 文件末尾是
log-rotation event (ROTATE_EVENT)
,记录了下个 binlog 文件名; - 上述两个 event 中间是各种不同的 event,每个 event 代表数据库中不同的操作。
对于 binlog 可以直接利用 hexdump -C
命令读取 mysql-bin.NNNNNN
文件的内容;当然,也可以通过 mysqlbinlog --hexdump
命令查看;其中示例如下。
$ hexdump -C mysql-bin.000001
00000000 fe 62 69 6e ca f0 78 58 0f ea 0c 00 00 77 00 00 |.bin..xX.....w..|
00000010 00 7b 00 00 00 00 00 04 00 35 2e 37 2e 31 36 2d |.{.......5.7.16-|
00000020 64 65 62 75 67 2d 6c 6f 67 00 00 00 00 00 00 00 |debug-log.......|
00000030 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
00000040 00 00 00 00 00 00 00 00 00 00 00 ca f0 78 58 13 |.............xX.|
00000050 38 0d 00 08 00 12 00 04 04 04 04 12 00 00 5f 00 |8............._.|
00000060 04 1a 08 00 00 00 08 08 08 02 00 00 00 0a 0a 0a |................|
00000070 2a 2a 00 12 34 00 01 e8 74 31 a6 ca f0 78 58 23 |**..4...t1...xX#|
00000080 ea 0c 00 00 1f 00 00 00 9a 00 00 00 80 00 00 00 |................|
00000090 00 00 00 00 00 00 a5 0a 43 ae 10 f3 78 58 04 ea |........C...xX..|
000000a0 0c 00 00 2f 00 00 00 c9 00 00 00 00 00 04 00 00 |.../............|
000000b0 00 00 00 00 00 6d 79 73 71 6c 2d 62 69 6e 2e 30 |.....mysql-bin.0|
000000c0 30 30 30 30 32 f4 b1 f2 56 |00002...V|
000000c9
在开始+结尾的两个事件中间,是各种其他的 event 。
实例解析
接下来,看看执行如下 SQLs 所生成的不同格式的 binlog 。
FLUSH LOGS;
USE test;
DROP TABLE foobar;
CREATE TABLE foobar (id INT PRIMARY KEY, name VARCHAR(20), gmt_create TIMESTAMP);
INSERT INTO foobar VALUES(1, "Andy", NOW()), (2, "Carter", NOW());
UPDATE foobar SET name = "Devin" WHERE id = 1;
DELETE FROM foobar WHERE id = 1;
FLUSH LOGS;
可以通过 mysqlbinlog
解析 binlog
日志,其中内容可以参考如下。
######################### Statement-Based Replication, SBR
# at 979
#150809 20:52:54 server id 1 end_log_pos 1126 CRC32 0x1044160e Query thread_id=6 exec_time=0 error_code=0
SET TIMESTAMP=1486817574/*!*/;
INSERT INTO foobar VALUES(1, "Andy", NOW()), (2, "Carter", NOW())
######################### Row-Based Replication, RBR
/*!*/;
# at 1765
#170211 21:23:05 server id 1 end_log_pos 1819 CRC32 0xd5c8e00d Table_map: `test`.`foobar` mapped to number 108
# at 1819
#170211 21:23:05 server id 1 end_log_pos 1884 CRC32 0x2e610487 Update_rows: table id 108 flags: STMT_END_F
BINLOG '
ORCfWBMBAAAANgAAABsHAAAAAGwAAAAAAAEABHRlc3QABmZvb2JhcgADAw8RAxQAAAIN4MjV
ORCfWB8BAAAAQQAAAFwHAAAAAGwAAAAAAAEAAgAD///4AQAAAARBbmR5WJ8QLPgBAAAABURldmlu
WJ8QOYcEYS4=
'
详细介绍:
* 位于文件中的位置
"at 979" 为事件的起点,从第196字节开始;"end_log_pos 1126"说明以第1126字节处结束;
* 时间戳
事件发生的时间"150809 20:52:54";
* 服务器的标识
服务器的标识id "server id 1",可以在配置文件中通过server-id参数设置;
* 事件执行时间
事件执行花费的时间"exec_time=0";
* 错误码
该事件执行的错误码为"error_code=0";
二进制解析
仍然是上述的示例,首先可以查看下关于 MySQL Internals Manual – Binlog Event 中的介绍,主要是关于 event 格式的介绍。
Binlog Event header
头部信息通常是在每个事件的开始,根据版本不同一般为 13/19 字节,只要版本大于 1 均为 19 字节,其头部的格式如下:
字节数 解析
4 从1970.1.1以来的秒数,小端存储
1 事件类型,通过enum Log_event_type定义
4 服务器ID,在配置文件中通过server-id指定,用于循环复制过滤事件
4 整个事件的大小,包括了头部+事件体等
4 下个事件的偏移量
2 flags,通过类似LOG_EVENT_XXX_F宏定义,例如LOG_EVENT_ARTIFICIAL_F
接下来就是事件体了,不同的事件显然定义不同,关于具体的格式可以参考 Binlog Event .
实例解析
$ hexdump mysql-bin.000024 -C -n 100
00000000 fe 62 69 6e 57 7f ad 58 0f ea 0c 00 00 77 00 00 |.binW..X.....w..|
00000010 00 7b 00 00 00 00 00 04 00 35 2e 37 2e 31 36 2d |.{.......5.7.16-|
00000020 64 65 62 75 67 2d 6c 6f 67 00 00 00 00 00 00 00 |debug-log.......|
00000030 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
00000040 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 13 |................|
00000050 38 0d 00 08 00 12 00 04 04 04 04 12 00 00 5f 00 |8............._.|
00000060 04 1a 08 00 |....|
00000064
fe 62 69 6e binlog的Magic Number,通过宏BINLOG_MAGIC定义,在open_binlog()中写入
事件的头部信息
57 7f ad 58 从1970.1.1以来的秒数,小端存储为0x58ad7f57
0f 日志类型
ea 0c 00 00 server-id,也就是0x0cea(3306)
77 00 00 00 整个事件的大小,0x77(119)
7b 00 00 00 下个事件的偏移量,0x7b(123)
00 00 Flag
文件开始是以一个FORMAT_DESCRIPTION_EVENT事件开始
04 00 binlog版本信息,v4
35 2e 37 2e ... 50字节,服务器版本信息,通过MYSQL_SERVER_VERSION宏定义,可通过SELECT version()查看
... ...
----- 可以根据mysqlbinlog查看偏移量
$ hexdump mysql-bin.000024 -C -s 520 -n 200
Tips: 有时候我们想查看某个 event 具体的二进制内容,此时可以通过 mysqlbinlog 查看具体 SQL 的偏移量,也就是 at NNN
中的数字。
Binlog 源码解析
如上 binlog 是由许多 event 组成,具体的类型是通过 enum Log_event_type
进行定义的,当然,可以直接查看当前包含的类型。
enum Log_event_type
{
UNKNOWN_EVENT= 0,
START_EVENT_V3= 1,
QUERY_EVENT= 2,
STOP_EVENT= 3,
ROTATE_EVENT= 4,
INTVAR_EVENT= 5,
LOAD_EVENT= 6,
SLAVE_EVENT= 7,
CREATE_FILE_EVENT= 8,
APPEND_BLOCK_EVENT= 9,
EXEC_LOAD_EVENT= 10,
DELETE_FILE_EVENT= 11,
... ...
};
需要注意的是,上面的部分 event 已经被弃用,但是为了兼容性,实际还保存着;这里只介绍几个比较常见的事件类型:
GTID_LOG_EVENT
在 GTID 模式下,每个事务的 GTID 序号被记录到这种 EVENT 中;TABLE_MAP_EVENT
用于记录库名、表名以及字段类型,利用这些元数据,可用于后续事件的数据解析;
在 ROW 模式下,每次执行 INSERT
、UPDATE
、DELETE
之前,都有 TABLE_MAP_EVENT
事件,用于映射元数据信息;
初始化
与 binlog 相关的代码主要在 sql/binlog.cc
文件中,其中会初始化一个实例,代码如下。
MYSQL_BIN_LOG mysql_bin_log(&sync_binlog_period, WRITE_CACHE);
第一个参数 sync_binlog_period
也就是 sync_binlog
的设置值。
参考
关于日志内容,详细介绍可以参考官方文档 MySQL Server Logs,而 binlog 相关还可以参考官方文档 MySQL Internals Manual - The Binary Log,以及 Binary Logging Options and Variables 。
对于 binlog 日志格式,事件格式介绍,事件分类等,可以参考 MySQL Internals Manual - Replication Protocol 。