reference:MySQL技术内幕 Innodb存储引擎
Write-Ahead Logging ,WAL:预写日志方式
【1】Redo Log
在Innodb存储引擎中,事务日志是通过redo和innodb的存储引擎日志缓冲(Innodb log buffer)来实现的,当开始一个事务的时候,会记录该事务的lsn(log sequence number)号; 当事务执行时,会往InnoDB存储引擎的日志
的日志缓存里面插入事务日志;当事务提交时,必须将存储引擎的日志缓冲写入磁盘(通过innodb_flush_log_at_trx_commit来控制),也就是写数据前,需要先写日志。这种方式称为“预写日志方式”,
innodb通过此方式来保证事务的完整性。也就意味着磁盘上存储的数据页和内存缓冲池上面的页是不同步的,是先写入redo log,然后写入data file,因此是一种异步的方式。通过 show engine innodb status\G来观察之间的差距
-- 建立一张表z,然后建立一个往表导入数据的存储过程load_test。通过命令show engine innodb status观察当前的redo日志情况
create table z(a int, primary key(a))engine=innodb;
DELIMITER $$
DROP PROCEDURE IF EXISTS `test`.`load_test`$$
CREATE PROCEDURE load_test(COUNT INT)
BEGIN
DECLARE i INT UNSIGNED DEFAULT 0;
START TRANSACTION;
WHILE i < COUNT DO
REPLACE INTO z SELECT i; -- 用replace是因为需要重复调用,避免主键重复insert报错。
SET i=i+1;
END WHILE;
COMMIT;
END;
$$
......
---
LOG
---
Log sequence number 20499052099 当前的LSN
Log flushed up to 20499052099 表示刷新到redo log的LSN
Pages flushed up to 20499052099 表示刷新到磁盘的lsn
Last checkpoint at 20499052099
0 pending log writes, 0 pending chkp writes
373 log i/o's done, 0.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 137363456; in additional pool allocated 0
Dictionary memory allocated 1270857
Buffer pool size 8191
Free buffers 7562
Database pages 612
Old database pages 205
Modified db pages 0
Pending reads 0
......
mysql> call test.load_test(100000);
Query OK, 0 rows affected, 1 warning (6.28 sec)
mysql> show engine innodb status\G
......
---
LOG
---
Log sequence number 20504734913
Log flushed up to 20504734913
Pages flushed up to 20504734913
Last checkpoint at 20504734913
0 pending log writes, 0 pending chkp writes
398 log i/o's done, 0.38 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
......
看来Log sequence number和Log flushed up以及Pages flushed u3个还是一样的。
再多导入点数据,重新开启另外一个窗口看看innodb状态
mysql> call test.load_test(1000000);
mysql> show engine innodb status\G
......
---
LOG
---
Log sequence number 20527044411
Log flushed up to 20525763843
Pages flushed up to 20517902997
Last checkpoint at 20504829471
0 pending log writes, 0 pending chkp writes
432 log i/o's done, 1.26 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
这次看到的show engine innodb status的结果就不一样了,Log sequence number > Log flushed up > Pages flushed up > Last checkpoint,所以从这里也可以看出,先写redo日志,再写数据文件
在实际写比较频繁的productiion上面,这3个值都会是不一样的。
【2】Undo
undo的记录正好与redo的相反,insert变成delete,update变成相反的update,redo放在redo file里面。而undo放在一个内部的一个特殊segment上面,存储与共享表空间内(ibdata1或者ibdata2中)。
py_innodb_page_info.py
下载地址: wget http://david-mysql-tools.googlecode.com/svn-history/r15/trunk/py_innodb_page_type/py_innodb_page_info.py
[root@mysql data56]# python /root/py_innodb_page_info.py /data56/ibdata1
Traceback (most recent call last):
File "/root/py_innodb_page_info.py", line 3, in <module>
import mylib
ImportError: No module named mylib
[root@mysql data56]#
还需要下载 mylib.py和include.py文件,并和py_innodb_page_info.py放在一个目录之下
wget http://david-mysql-tools.googlecode.com/svn-history/r15/trunk/py_innodb_page_type/mylib.py
wget http://david-mysql-tools.googlecode.com/svn-history/r15/trunk/py_innodb_page_type/include.py
ps:有的时候network会断掉,要多执行几次wget去下载。
[root@mysql ~]# python /root/py_innodb_page_info.py /data56/ibdata1
Total number of page: 8960:
Insert Buffer Free List: 1035
Insert Buffer Bitmap: 1
System Page: 134
Transaction system Page: 1
Freshly Allocated Page: 4010
Undo Log Page: 1556
File Segment inode: 5
B-tree Node: 2217
File Space Header: 1
[root@mysql ~]#
[root@mysql ~]#
undo不是物理恢复,是逻辑恢复,因为它是通过执行相反的dml语句来实现的。而且不会回收因为insert和upate而新增加的page页的。
undo页的回收是通过master thread线程来实现的。
验证row模式下,生产的binlog传到从库上面,大概需要多久!
导出
time /usr/local/mysql56/bin/mysqldump --socket=/data56/mysql.sock -uroot -p123456 -P3307 --extended-insert=false --all-databases> /root/adb.sql
[root@mysql ~]# time /usr/local/mysql56/bin/mysqldump --socket=/data56/mysql.sock -uroot -p123456 -P3307 --extended-insert=false --all-databases> /root/adb.sql
Warning: Using a password on the command line interface can be insecure.
real 5m10.757s
user 2m42.137s
sys 0m11.346s
导入
time /usr/local/mysql56/bin/mysql --socket=/data56/mysql.sock -uroot -p123456 -P3307 < /root/adb.sql
在从库上面检查:
mysql> show slave status\G
*************************** 1. row ***************************
Slave_IO_State: Waiting for master to send event
Master_Host: 10.88.49.119
Master_User: repl
Master_Port: 3307
Connect_Retry: 60
Master_Log_File: mysql56-bin.000008
Read_Master_Log_Pos: 513272653
Relay_Log_File: mysql56-relay-bin.000019
Relay_Log_Pos: 103964146
Relay_Master_Log_File: mysql56-bin.000008
Slave_IO_Running: Yes
Slave_SQL_Running: Yes
Replicate_Do_DB:
Replicate_Ignore_DB:
Replicate_Do_Table:
Replicate_Ignore_Table:
Replicate_Wild_Do_Table:
Replicate_Wild_Ignore_Table:
Last_Errno: 0
Last_Error:
Skip_Counter: 0
Exec_Master_Log_Pos: 418536570
Relay_Log_Space: 513273109
Until_Condition: None
Until_Log_File:
Until_Log_Pos: 0
Master_SSL_Allowed: No
Master_SSL_CA_File:
Master_SSL_CA_Path:
Master_SSL_Cert:
Master_SSL_Cipher:
Master_SSL_Key:
Seconds_Behind_Master: 857
Master_SSL_Verify_Server_Cert: No
Last_IO_Errno: 0
Last_IO_Error:
Last_SQL_Errno: 0
Last_SQL_Error:
Replicate_Ignore_Server_Ids:
Master_Server_Id: 11901
Master_UUID: a6a1d870-80b5-11e2-84d2-00155d016a07
Master_Info_File: /data56/master.info
SQL_Delay: 0
SQL_Remaining_Delay: NULL
Slave_SQL_Running_State: System lock
Master_Retry_Count: 86400
Master_Bind:
Last_IO_Error_Timestamp:
Last_SQL_Error_Timestamp:
Master_SSL_Crl:
Master_SSL_Crlpath:
Retrieved_Gtid_Set:
Executed_Gtid_Set:
Auto_Position: 0
1 row in set (0.00 sec)
ps:Seconds_Behind_Master: 857,有延时的情况出现,可见在row模式下,import6G的单调insert的sql的时候,有延时。