本文从两个方面进行阐述,常规的日志文件(不区分存储引擎),第二就是讲innodb存储引擎的事务日志。 一、基本日志文件 1.1、基本日志文件分类: 1.2、错误日志 主要包括mysql的启动,运行,关闭过程进行记录。 默认情况下以服务器的主机名命名`hostname`.err,可以通过参数--log-error=[file_name]指定 查看错误日志:show variables like 'log_error'; 日志刷新方法: 1.3、一般查询日志 查询日志分为一般查询日志和慢查询日志,通过参数long_query_time指定时间的值对其进行判定,如果在参数设定时间内完成查询,则为一般查询日志(建议关闭,因为太多),否则为慢查询日志。 #参数设定 --general_log={0|1} :是否开启一般查询日志 --general_log_file=file_name :指定一般查询日志的路径,默认名为`hostname.log` log_output={TABLE|FILE|NONE} :设置一般查询日志和慢查询日志的输出格式,分别为(表|文件|不记录) 1.4、慢查询日志 查询超出变量 long_query_time 指定时间值的为慢查询。mysql记录慢查询日志是在查询执行完毕且已经完全释放锁之后才记录的,因此慢查询日志记录的顺序和执行的SQL查询语句顺序可能会不一致 查看慢查询日志:show variables like '%slow_query_log%'; 执行语句 mysql>select sleep(10); 然后通过cat查看lgh3-slow.log日志: 如果慢查询日志中有大量的数据,我们可以使用mysqldumpslow命令来查看分析慢日志文件: [root@lgh3 mysql]# 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 #top n -a don't abstract all numbers to N and strings to 'S' #归类时不要使用N替换数字,S替换字符串 -n NUM abstract numbers with at least n digits within names -g PATTERN grep: only consider stmts that include this string #匹配查询,同grep功能一样 -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 使用mysqldumpslow简单查看:明显省略掉了很多注释的东西 相关参数: #和慢查询的相关参数设定 log_throttle_queries_not_use_indexes=10,记录每分钟允许写入慢日志的次数,默认为0,表示不限制 long_query_time=10 # 指定慢查询超时时长(默认10秒),超出此时长的属于慢查询 log_output={TABLE|FILE|NONE} # 定义一般查询日志和慢查询日志的输出格式,默认为file log_slow_queries={yes|no} # 是否启用慢查询日志,默认不启用 slow_query_log={1|ON|0|OFF} # 也是是否启用慢查询日志,此变量和log_slow_queries修改一个另一个同时变化 slow_query_log_file=/mydata/data/hostname-slow.log #默认路径为库文件目录下主机名加上-slow.log log_queries_not_using_indexes=OFF # 查询没有使用索引的时候是否也记入慢查询日志 1.5、二进制日志文件 记录对mysql数据库执行了更改的所有操作,不包括select和show这样的操作,如果执行了update和delete这样的操作,但是没有引起数据库数据的任何变化,也可能被写入二进制日志文件中。 mysql还创建一个二进制日志索引文件,当二进制日志文件滚动的时候会向该文件中写入对应的信息。所以该文件包含所有使用的二进制日志文件的文件名。默认情况下该文件与二进制日志文件的文件名相同,扩展名为'.index'。可以通过参数--log-bin-index[=file_name]指定文件名 1.5.1、二进制日志文件的作用 1.5.2、查看二进制文 1.使用mysqlbinlog工具。 mysqlbinlog使用格式: mysqlbinlog [option] log-file1 log-file2... 常用选项: -d,--database=name:只查看指定数据库的日志操作 -o,--offset=#:忽略掉日志中的前n个操作命令 -r,--result-file=name:将输出的日志信息输出到指定的文件中,使用重定向也一样可以。 -s,--short-form:显示简单格式的日志,只记录一些普通的语句,会省略掉一些额外的信息如位置信息和时间信息以及基于行的日志。可以用来调试,生产环境千万不可使用 --set-charset=char_name:在输出日志信息到文件中时,在文件第一行加上set names char_name --start-datetime,--stop-datetime:指定输出开始时间和结束时间内的所有日志信息 --start-position=#,--stop-position=#:指定输出开始位置和结束位置内的所有日志信息 -v,-vv:显示更详细信息,基于row的日志默认不会显示出来,此时使用-v或-vv可以查看 使用mysqlbinlog命令对mysql-bin.000001日志进行查看,如下: [root@lgh3 mysql]# mysqlbinlog /data/binlog/mysql-bin.000001 /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/; /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/; DELIMITER /*!*/;# at 4 #190908 21:18:32 server id 1000 end_log_pos 123 CRC32 0x052f8ffd Start: binlog v 4, server v 5.7.24-log created 190908 21:18:32 at startup ROLLBACK/*!*/; BINLOG ' aKh1XQ/oAwAAdwAAAHsAAAAAAAQANS43LjI0LWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA AAAAAAAAAAAAAAAAAABoqHVdEzgNAAgAEgAEBAQEEgAAXwAEGggAAAAICAgCAAAACgoKKioAEjQA Af2PLwU= '/*!*/;# at 123#190908 21:18:32 server id 1000 end_log_pos 154 CRC32 0x927edf95 Previous-GTIDs # [empty] # at 154#190908 21:19:15 server id 1000 end_log_pos 219 CRC32 0xb05f419c Anonymous_GTID last_committed=0 sequence_number=1 rbr_only=no SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;# at 219#190908 21:19:15 server id 1000 end_log_pos 313 CRC32 0xaafce462 Query thread_id=2 exec_time=0 error_code=0 SET TIMESTAMP=1567991955/*!*/; SET @@session.pseudo_thread_id=2/*!*/; SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/; SET @@session.sql_mode=1075838976/*!*/; SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/; /*!\C utf8mb4 *//*!*/; SET @@session.character_set_client=45,@@session.collation_connection=45,@@session.collation_server=45/*!*/; SET @@session.lc_time_names=0/*!*/; SET @@session.collation_database=DEFAULT/*!*/;create database test/*!*/;# at 313#190908 21:19:53 server id 1000 end_log_pos 378 CRC32 0xdccfd8ec Anonymous_GTID last_committed=1 sequence_number=2 rbr_only=no SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;# at 378#190908 21:19:53 server id 1000 end_log_pos 497 CRC32 0x57a45727 Query thread_id=2 exec_time=0 error_code=0use `test`/*!*/; SET TIMESTAMP=1567991993/*!*/; create table gxt1(id int , name varchar(128))/*!*/;# at 497#190908 21:20:17 server id 1000 end_log_pos 562 CRC32 0x316b41e9 Anonymous_GTID last_committed=2 sequence_number=3 rbr_only=yes /*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/; SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;# at 562#190908 21:20:17 server id 1000 end_log_pos 634 CRC32 0x693ee549 Query thread_id=2 exec_time=0 error_code=0 SET TIMESTAMP=1567992017/*!*/; BEGIN /*!*/;# at 634#190908 21:20:17 server id 1000 end_log_pos 684 CRC32 0xde906285 Table_map: `test`.`gxt1` mapped to number 108# at 684#190908 21:20:17 server id 1000 end_log_pos 734 CRC32 0xa0fc1d34 Write_rows: table id 108 flags: STMT_END_F BINLOG ' 0ah1XRPoAwAAMgAAAKwCAAAAAGwAAAAAAAEABHRlc3QABGd4dDEAAgMPAgACA4VikN4= 0ah1XR7oAwAAMgAAAN4CAAAAAGwAAAAAAAEAAgAC//wBAAAACAB6aGFuZ3NhbjQd/KA= '/*!*/;# at 734#190908 21:20:17 server id 1000 end_log_pos 765 CRC32 0xc9208948 Xid = 10 COMMIT/*!*/;# at 765#190908 21:30:18 server id 1000 end_log_pos 812 CRC32 0xda645def Rotate to mysql-bin.000002 pos: 4SET @@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*/; 上面蓝色字体表示位置,红色表示时间。 SHOW BINARY LOGS ; SHOW MASTER LOGS ; show binlog events in 'mysql-bin.000001'; SHOW MASTER STATUS; 表示二进制文件已经记录到了第四个,位置为418. 1.5.3、二进制文件的删除 1.reset master将会删除所有日志,并让日志文件重新从000001开始。 2.PURGE { BINARY | MASTER } LOGS { TO 'log_name' | BEFORE datetime_expr } purge master logs before 'yyyy-mm-dd hh:mi:ss' 将会删除指定日期之前的所有日志。但是若指定的时间处在正在使用中的日志文件中,将无法进行purge。 3.使用--expire_logs_days=N选项指定过了多少天日志自动过期清空 1.5.4、相关参数 log-bin=on|off|file_name #或者指定路径log-bin=/data/binlog/mysql-bin表示开启并设定路径,msyql5.7开启该参数必须分配server_id,否则mysql不能启动 server_id=1000 #指定server_id max_binlog_size: #(默认1G)指定一个二进制文件的最大值,如果超过该值,则产生一个新的二进制日志文件(考虑到事务不可能跨两个binlog文件,所以有时binlog文件的实际大小不会等于设定值) binlog_cache_size: #(默认32k)存储所有未提交的二进制日志记录,用于缓存,当该事务提交了,则会写入到二进制日志文件中,如果该参数太小,可能)存储所有未提交的二进制日志记录,用于缓存,当该事务提交了,则会写入到二进制日志文件中,如果该参数太小,可能 #会写入到磁盘,影响性能,可以通过查看参数binlog_cache_disk_use,表示写磁盘的次数 sync_binlog: #默认情况下,二进制日志不是每次写都会写入二进制日志文件中,(可以理解为缓冲)如果数据库异常宕机,就会存在二进制日志文件缺少记录的情况,可以通过参数sync_binlog=[N]来进行配置,当N=1时表示同步写磁盘的方式写二进制文件,这是不使用操作系统的缓冲来写日志。 #N=0(默认),虽然设置sync_binlog=1理论上保证了同步,但是当使用innodb存储引擎时,会存在二进制记录了操作,但是事务由回滚了的情况, #可以通过参数innodb_support_xa=1来解决该问题,innodb_support_xa=1保证了二进制文件和存储引擎文件同步 binlog_do-db: #记录该数据库 binlog_ingnore-db: #忽略该数据库 log_slave-update: #如果当前数据库时复制中的slave角色,不会把从master获取到的二进制日志写入到自己的二进制文件中,如果需要,则需要开启 #这个参数,如果搭建master=>slave=>slave的架构复制,则必须开启此参数 binlog_format: #可以设置为如下的值 #statement:二进制日志文件都是记录的逻辑sql语句 #row:记录表行更改的情况,如果设置为该参数,可以将innodb存储引擎的事务隔离级别基本设置为READ COMMITTED,获得更好的并发,一般设置为row,虽然对磁盘和网络开销大一些,格式为二进制格式。使用mysqlbinlog工具查看 #mixed:mixed模式,默认使用statement配置 expire_logs_days : #指定自动删除二进制日志的时间,即日志过期时间 1.5.5、日志还原 方式一:直接还原 方式二:先导入到一个文件然后恢复 二、事务日志 innodb事务日志包括redo log和undo log。redo log是重做日志,提供前滚操作,undo log是回滚日志,提供回滚操作。 undo log不是redo log的逆向过程,其实它们都算是用来恢复的日志: 2.1、redo log redo log主要由重做日志缓冲(redo log buffer)和重做日志文件(redo log file)构成。缓冲数据存于内存,当机器异常或者服务异常会导致缓冲中的数据丢失,日志文件的数据存于磁盘,是持久化文件。 重做日志就是通过先写入缓冲,然后刷新到磁盘的操作,那怎么能够保证数据不会丢失呢? 我们可以通过参数innodb_flush_log_at_trx_commit进行控制,该参数有三个值,分别为0,1,2,在详细谅解这个参数之前,我们先了解下重做日志缓冲和重做日志文件的是如何同步的:确保每次日志都能写入到事务日志文件中,在每次将log buffer中的日志写入日志文件的过程中都会调用一次操作系统的fsync操作(即fsync()系统调用)。因为MySQL是工作在用户空间的,MySQL的log buffer处于用户空间的内存中。要写入到磁盘上的log file中(redo:ib_logfile0和ib_logfile1文件,undo:share tablespace或.ibd文件),中间还要经过操作系统内核空间的os buffer,调用fsync()的作用就是将OS buffer中的日志刷到磁盘上的log file中。如下图所示: 接下来继续看 innodb_flush_log_at_trx_commit的值的意义: 当设置为1的时候,事务每次提交都会将log buffer中的日志写入os buffer并调用fsync()刷到log file on disk中。这种方式即使系统崩溃也不会丢失任何数据,但是因为每次提交都写入磁盘,IO的性能较差。(推荐) redo log是用来数据的crash recovery的,这是数据库保障数据安全的重要功能之一,保存着innodb表中的修改记录,所以也叫日志文件,在innodb存储引擎中,默认有两个日志文件,新建数据库后,会有名为ib_logfile0和ib_logfile1两个文件,如果在启动数据库时,两个文件不存在,则innodb会根据参数创建。 日志文件是以类似循环的方式使用的,当第一个日志文件写满,会往第二个继续写,当所有日志文件写满,则会在第一个日志文件中清空一些空间出来,提供写空间,如下图所示: innodb中通过日志组来管理日志文件,是一个逻辑定义,它包含若干个日志文件,一组中的日志文件大小相等,大小通过参数设定。 日志组中的每个文件都有自己的格式,内部也是按照大小相同的页面切分,这里的页面大小是512字节,则是机械硬盘块的大小。这样的设计是为了提高数据写入的吞吐量和效率。并且日志将逻辑事务对数据库的分散随机写入转换为512字节整数倍的顺序写入,大大提高数据库写的性能,这也是数据库管理系统区别于文件管理系统的重要因素。 既然说每个日志有很多个512字节的块组成,那么我们了解下每个日志文件的构成,如下图所示: 如上图所示,一个日志文件包含很多个512字节的块,而每个块又分为三部分组成,分别为日志头,日志尾,和具体日志内容。其中日志头占用12字节,日志尾占用8字节,所以剩余的492字节为日志内容占用。 日志头包含4部分: 日志尾只有一个部分: log_block_trl_no ,该值和块头的 log_block_hdr_no 相等 接下来我们看看文件组:在每个组的第一个redo log file中,前2KB记录4个特定的部分,从2KB之后才开始记录log block。除了第一个redo log file中会记录,log group中的其他log file不会记录这2KB,但是却会腾出这2KB的空间。如下: 我们知道重做日志的构成以及其作用之后,那重做日志是什么时间点从缓冲中刷新到日志文件的呢?接下来看看日志刷盘的时机。 日志刷盘时机主要有: 1、log buffer空间用完, 上面提到的LSN称为日志的逻辑序列号(log sequence number),在innodb存储引擎中,lsn占用8个字节。LSN的值会随着日志的写入而逐渐增大。 可以通过:mysql> show engine innodb status\G;查看 其中: log sequence number就是当前的redo log(in buffer)中的lsn; 2.2、undo log undo log有两个作用:提供回滚和多个行版本控制(MVCC) 参考:感谢如下作者的优质文章 https://www.cnblogs.com/f-ck-need-u/p/9010872.html#auto_id_12 https://www.cnblogs.com/f-ck-need-u/p/9001061.html 《mysql运维内参》 《mysql技术内幕:innodb存储引擎》 来源:https://www./content-2-444751.html |
|