详解MySQL的日志

2,827 阅读8分钟

MySQL日志

MySQL的日志记录了MySQL的日常操作和错误信息,通过这些日志我们可以知道MySQL内部发生的事情,可以为MySQL的优化和管理提供必要的信息。

MySQL的日志主要有:二进制日志、通用查询日志、慢查询日志、错误日志、事务日志等。

二进制日志

二进制日志用来记录操作MySQL数据库中的写入性操作(包括增删改,但不包括查询),操作语句以事件的形式进行保存,描述数据更改。

二进制的主要作用有两个:

  1. 复制,配置了主从复制的时候,主服务器会将其产生的二进制日志发送到slave端,slave端会利用这个二进制日志的信息在本地重做,实现主从同步。
  2. 恢复,因为二进制日志包含了备份以后的所有更新,因此可以用于最大限度地恢复数据库。因此,建议二进制日志单独保存到一个磁盘上,以便磁盘损坏以后进行数据恢复。   

查看二进制日志是否打开

二进制可以通过show variables like 'log_bin';查看是否已经打开。

下面的返回表示是关闭的:

mysql> show variables like 'log_bin';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| log_bin       | OFF   |
+---------------+-------+

Windows下配置MySQL二进制日志

  1. 首先确保MySQL Server已经安装,笔者是在Windows10操作系统安装的 MySQL5.7 64位的服务,MySQL服务名为:MySQL57

安装成功以后,查看MySQL版本:

C:\>mysql -V
mysql  Ver 14.14 Distrib 5.7.17, for Win64 (x86_64)
  1. 打开C:\ProgramData\MySQL\MySQL Server 5.7(注意目录不要搞错)目录下的my.ini文件,并在[mysqld]配置组下面加入如下配置:
# MySQL二进制日志配置
# bin log输出的目录及文件
log-bin="C:/1workspace/develop/db/mysql/mysql57/logs/binlog"
# bin log清理时间
expire_logs_days=7
# 每个bin log文件大小
max_binlog_size=200m
#binlog缓存大小
binlog_cache_size=10m
#最大binlog缓存大小
max_binlog_cache_size=20m
  1. 通过 管理员模式 打开cmd,重启MySQL服务:
C:\>net stop MySQL57
MySQL57 服务正在停止.
MySQL57 服务已成功停止。


C:\>net start MySQL57
MySQL57 服务正在启动 .
MySQL57 服务已经启动成功。
  1. 连接MySQL服务:
C:\>mysql -uroot -pmysqltao
  1. 下面显示MySQL的bin log已经开启:
mysql> show variables like 'log_bin';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| log_bin       | ON    |
+---------------+-------+

这时候你可以打开你配置的bin log路径,可以看到生成的二进制日志文件:binlog.000001,

以及一个二进制log的索引文件:binlog.index。

查看 bin log

每次重启MySQL都会生成一个新的binlog文件,通过show binary logs语句可以看到所有的binlog文件,返回的内容跟 binlog.index 文件里记录的binlog文件数是一样的。

现在有3个binglog文件:

mysql> show binary logs;
+---------------+-----------+
| Log_name      | File_size |
+---------------+-----------+
| binlog.000001 |       177 |
| binlog.000002 |       177 |
| binlog.000003 |       154 |
+---------------+-----------+

执行一条update语句:

update demo_java_db_1.t_user set name='Jack' where id=1;

再通过mysqlbinlog语句查看当前的binlog文件:

C:\1workspace\develop\db\mysql\mysql57\logs>mysqlbinlog binlog.000003
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#190704 17:19:28 server id 1  end_log_pos 123 CRC32 0xaf193fc6  Start: binlog v 4, server v 5.7.17-log created 190704 17:19:28 at startup
# Warning: this binlog is either in use or was not closed properly.
ROLLBACK/*!*/;
BINLOG '
oMQdXQ8BAAAAdwAAAHsAAAABAAQANS43LjE3LWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAACgxB1dEzgNAAgAEgAEBAQEEgAAXwAEGggAAAAICAgCAAAACgoKKioAEjQA
AcY/Ga8=
'/*!*/;
# at 123
#190704 17:19:29 server id 1  end_log_pos 154 CRC32 0xc916f3aa  Previous-GTIDs
# [empty]
# at 154
#190704 17:39:43 server id 1  end_log_pos 219 CRC32 0xcecca4bf  Anonymous_GTID  last_committed=0    sequence_number=1
SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
# at 219
#190704 17:39:43 server id 1  end_log_pos 287 CRC32 0xb6a3de97  Query   thread_id=7     exec_time=0 error_code=0
SET TIMESTAMP=1562233183/*!*/;
SET @@session.pseudo_thread_id=7/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=1344274432/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8 *//*!*/;
SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=33/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
BEGIN
/*!*/;
# at 287
#190704 17:39:43 server id 1  end_log_pos 358 CRC32 0xd1ce52d6  Table_map: `demo_java_db_1`.`t_user` mapped to number 115
# at 358
#190704 17:39:43 server id 1  end_log_pos 445 CRC32 0x7a57aa7a  Update_rows: table id 115 flags: STMT_END_F

BINLOG '
X8kdXRMBAAAARwAAAGYBAAAAAHMAAAAAAAEADmRlbW9famF2YV9kYl8xAAZ0X3VzZXIABQgPDw8P
CGAAYABgAGAAHtZSztE=
X8kdXR8BAAAAVwAAAL0BAAAAAHMAAAAAAAEAAgAF///wAQAAAAAAAAAFZmlyc3QGcHdkMTIzA01B
TvABAAAAAAAAAARKYWNrBnB3ZDEyMwNNQU56qld6
'/*!*/;
# at 445
#190704 17:39:43 server id 1  end_log_pos 476 CRC32 0x6e49c227  Xid = 42
COMMIT/*!*/;
SET @@SESSION.GTID_NEXT= 'AUTOMATIC' /* added by mysqlbinlog */ /*!*/;
DELIMITER ;
# End of log file
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;

通过binlog可以看到在 17:39:43改了demo_java_db_1库的t_user表。

通过binlog恢复数据

通过show binlog events命令可以查看binlog内记录的事件:

mysql> show binlog events in 'binlog.000003'\G
*************************** 1. row ***************************
   Log_name: binlog.000003
        Pos: 4
 Event_type: Format_desc
  Server_id: 1
End_log_pos: 123
       Info: Server ver: 5.7.17-log, Binlog ver: 4
*************************** 2. row ***************************
   Log_name: binlog.000003
        Pos: 123
 Event_type: Previous_gtids
  Server_id: 1
End_log_pos: 154
       Info:
*************************** 3. row ***************************
   Log_name: binlog.000003
        Pos: 154
 Event_type: Anonymous_Gtid
  Server_id: 1
End_log_pos: 219
       Info: SET @@SESSION.GTID_NEXT= 'ANONYMOUS'
*************************** 4. row ***************************
   Log_name: binlog.000003
        Pos: 219
 Event_type: Query
  Server_id: 1
End_log_pos: 287
       Info: BEGIN
*************************** 5. row ***************************
   Log_name: binlog.000003
        Pos: 287
 Event_type: Table_map
  Server_id: 1
End_log_pos: 358
       Info: table_id: 115 (demo_java_db_1.t_user)
*************************** 6. row ***************************
   Log_name: binlog.000003
        Pos: 358
 Event_type: Update_rows
  Server_id: 1
End_log_pos: 445
       Info: table_id: 115 flags: STMT_END_F
*************************** 7. row ***************************
   Log_name: binlog.000003
        Pos: 445
 Event_type: Xid
  Server_id: 1
End_log_pos: 476
       Info: COMMIT /* xid=42 */
*************************** 8. row ***************************
   Log_name: binlog.000003
        Pos: 476
 Event_type: Anonymous_Gtid
  Server_id: 1
End_log_pos: 541
       Info: SET @@SESSION.GTID_NEXT= 'ANONYMOUS'
*************************** 9. row ***************************
   Log_name: binlog.000003
        Pos: 541
 Event_type: Query
  Server_id: 1
End_log_pos: 609
       Info: BEGIN
*************************** 10. row ***************************
   Log_name: binlog.000003
        Pos: 609
 Event_type: Table_map
  Server_id: 1
End_log_pos: 680
       Info: table_id: 115 (demo_java_db_1.t_user)
*************************** 11. row ***************************
   Log_name: binlog.000003
        Pos: 680
 Event_type: Update_rows
  Server_id: 1
End_log_pos: 765
       Info: table_id: 115 flags: STMT_END_F
*************************** 12. row ***************************
   Log_name: binlog.000003
        Pos: 765
 Event_type: Xid
  Server_id: 1
End_log_pos: 796
       Info: COMMIT /* xid=69 */
*************************** 13. row ***************************
   Log_name: binlog.000003
        Pos: 796
 Event_type: Anonymous_Gtid
  Server_id: 1
End_log_pos: 861
       Info: SET @@SESSION.GTID_NEXT= 'ANONYMOUS'
*************************** 14. row ***************************
   Log_name: binlog.000003
        Pos: 861
 Event_type: Query
  Server_id: 1
End_log_pos: 929
       Info: BEGIN
*************************** 15. row ***************************
   Log_name: binlog.000003
        Pos: 929
 Event_type: Table_map
  Server_id: 1
End_log_pos: 1000
       Info: table_id: 115 (demo_java_db_1.t_user)
*************************** 16. row ***************************
   Log_name: binlog.000003
        Pos: 1000
 Event_type: Update_rows
  Server_id: 1
End_log_pos: 1085
       Info: table_id: 115 flags: STMT_END_F
*************************** 17. row ***************************
   Log_name: binlog.000003
        Pos: 1085
 Event_type: Xid
  Server_id: 1
End_log_pos: 1116
       Info: COMMIT /* xid=101 */
*************************** 18. row ***************************
   Log_name: binlog.000003
        Pos: 1116
 Event_type: Anonymous_Gtid
  Server_id: 1
End_log_pos: 1181
       Info: SET @@SESSION.GTID_NEXT= 'ANONYMOUS'
*************************** 19. row ***************************
   Log_name: binlog.000003
        Pos: 1181
 Event_type: Query
  Server_id: 1
End_log_pos: 1249
       Info: BEGIN
*************************** 20. row ***************************
   Log_name: binlog.000003
        Pos: 1249
 Event_type: Table_map
  Server_id: 1
End_log_pos: 1320
       Info: table_id: 115 (demo_java_db_1.t_user)
*************************** 21. row ***************************
   Log_name: binlog.000003
        Pos: 1320
 Event_type: Update_rows
  Server_id: 1
End_log_pos: 1405
       Info: table_id: 115 flags: STMT_END_F
*************************** 22. row ***************************
   Log_name: binlog.000003
        Pos: 1405
 Event_type: Xid
  Server_id: 1
End_log_pos: 1436
       Info: COMMIT /* xid=107 */
22 rows in set (0.00 sec)
  • Log_name: 此条log存在那个文件中,从上面可以看出这2条log皆存在与mysql_bin.000001文件中。
  • Pos: log在bin-log中的开始位置
  • Event_type:log的类型信息
  • Server_id:可以查看配置中的server_id, 表示log是那个服务器产生, server_id可以在my.ini配置
  • End_log_pos:log在bin-log中的结束位置
  • Info: log的一些备注信息,可以直观的看出进行了什么操作

通过mysqlbinlog命令可以恢复数据,mysqlbinlog命令支持添加参数来恢复指定的事件:

mysqlbinlog --start-date="2019-07-04 18:00:00" --stop-date="2019-07-04 18:10:00" binlog.000003 |mysql -uroot -pmysqltao

错误日志

MySQL的错误日志记录了 mysqld 启动和停止时,以及服务器在运行过程中出现的任何严重错误。

与binlog一样,在my.ini文件配置:

# error log输出的目录及文件
log-error="C:/1workspace/develop/db/mysql/mysql57/logs/errorlog"

通用查询日志

通用查询日志能够存放到一个文本文件或者表中,全部连接和语句被记录到该日志文件或表,默认不开启该日志。

在my.ini文件[mysqld]组配置通用查询日志:

#通用查询日志输出格式 [none|file|table|file,table]
log_output=file
#是否启用通用查询日志[on|off]        
general_log=on
#通用查询日志位置及名字
general_log_file="C:/1workspace/develop/db/mysql/mysql57/logs/generallog"

慢查询日志

慢查询日志记录的是查询较慢的SQL语句的日志,可用于对执行时间较长、执行效率较低的SQL语句的性能优化。

  1. 临时开启慢查询日志:
set global slow_query_log = on; 

如果想关闭慢查询日志,只需要执行:

set global slow_query_log = off;

2.临时设置慢查询时间临界点

查询时间高于这个临界点的都会被记录到慢查询日志中。

所有执行时间超过1秒的sql都将被记录到慢查询日志:

set long_query_time = 1;
  1. 设置慢查询存储的方式
set globle log_output = file;

这里设置为了file,就是说慢查询日志是通过file保存,默认是none,我们还可以设置为table,如果是table则慢查询信息会保存到mysql库下的slow_log表中。

  1. 查询慢查询日志的开启状态和慢查询日志储存的位置
show variables like '%quer%';

补充:事务日志

事务日志是InnoDB引擎特有的日志,可以帮助提高事务的效率。

使用事务日志,存储引擎在修改表的数据时只需要修改其内存拷贝,再把改修改行为记录到持久在硬盘上的事务日志中,而不用每次都将修改的数据本身持久到磁盘。

事务日志采用追加的方式,因此写日志的操作是磁盘上一小块区域内的顺序I/O,而不像随机I/O需要在磁盘的多个地方移动磁头,所以采用事务日志的方式相对来说要快得多。

事务日志持久以后,内存中被修改的数据在后台可以慢慢的刷回到磁盘。目前大多数的存储引擎都是这样实现的,我们通常称之为预写式日志,修改数据需要写两次磁盘。

如果数据的修改已经记录到事务日志并持久化,但数据本身还没有写回磁盘,此时系统崩溃,存储引擎在重启时能够自动恢复这部分修改的数据。具有的恢复方式则视存储引擎而定。

查看事务日志参数:

mysql> SHOWGLOBAL VARIABLES LIKE '%log%';
+-----------------------------------------+-----------------------------------+
| Variable_name                           | Value                             |
+-----------------------------------------+-----------------------------------+
| innodb_flush_log_at_trx_commit          | 1             |
|innodb_locks_unsafe_for_binlog          |OFF                               |
| innodb_log_buffer_size                  | 8388608                           |
|innodb_log_file_size                    |5242880                           |
| innodb_log_files_in_group               | 2                      |
|innodb_log_group_home_dir               |./            |
|innodb_mirrored_log_groups              |1              |

总结

  • MySQL日志主要有:

错误日志、通用查询日志、慢查询日志、事务日志、二进制日志

  • MySQL日志的输出位置一般有三种方式:

file(文件),table(表)、none(不保存)

  • MySQL日志主要是用于:

异常监控、性能优化、数据恢复、主从同步


Wechat-westcall