innodb中的REDO解析


在innodb存储引擎中,事务日志通过重做(redo)日志文件和innodb存储引擎的日志缓冲(innodb log buffer)来实现;当开始一个事务时,会记录该事务的一个LSN(Log sequence number),当事务执行是,会往innodb存储引擎的缓冲池里插入事务日志,当事务提交是,必须将innodb粗才能引擎的日志缓冲写入磁盘(默认的实现,即innodb_flush_log_at_trx_commit=1),也就是写数据前,需要先写日志,这种方式为预写日志方式(write-ahead logging,WAL).

INNODB存储引擎的预写日志方式来保证事务的完整性。这意味着磁盘上的存储的数据页和内存缓冲池中的页是不同步的,对于内粗缓冲中的页的修改,首先是写入重做日志文件,然后再写入磁盘。因此是一种异步的方式。可以通过show  engine innodb status来观察当前的磁盘和日志的差距;

mysql> create table z(a int,primary key(a)) engine=innodb;
Query OK, 0 rows affected (0.01 sec)

mysql>
mysql> create procedure load_test(count int) begin declare i int unsigned default 0;
    -> start transaction;
    -> while i<count do
    -> insert into z select i;
    -> set i=i+1;
    -> end while;
    -> commit;
    -> end;
    -> $$         
Query OK, 0 rows affected (0.05 sec)

mysql> delimiter ;
mysql> show engine innodb status\G;
*************************** 1. row ***************************
  Type: InnoDB
  Name:
Status:
=====================================
121130 15:41:01 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 12 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 224 1_second, 224 sleeps, 18 10_second, 66 background, 66 flush
srv_master_thread log flush and writes: 228
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 114, signal count 113
Mutex spin waits 6, rounds 180, OS waits 2
RW-shared spins 99, rounds 2970, OS waits 99
RW-excl spins 0, rounds 390, OS waits 13
Spin rounds per wait: 30.00 mutex, 30.00 RW-shared, 390.00 RW-excl
------------------------
LATEST DETECTED DEADLOCK
------------------------
121130 14:17:47
*** (1) TRANSACTION:
TRANSACTION 11F40, ACTIVE 71 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 320, 2 row lock(s)
MySQL thread id 80, OS thread handle 0x33d62740, query id 4152 localhost root statistics
select * from t3 where a=2 for update
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 0 page no 3132 n bits 80 index `PRIMARY` of table `test`.`t3` trx id 11F40 lock_mode X locks rec but not gap waiting
Record lock, heap no 3 PHYSICAL RECORD: n_fields 3; compact format; info bits 0
 0: len 4; hex 80000002; asc    ;;
 1: len 6; hex 000000011f35; asc      5;;
 2: len 7; hex e00000013a011d; asc    :  ;;

*** (2) TRANSACTION:
TRANSACTION 11F41, ACTIVE 42 sec starting index read
mysql tables in use 1, locked 1
3 lock struct(s), heap size 320, 2 row lock(s)
MySQL thread id 79, OS thread handle 0x33d62600, query id 4153 localhost root statistics
select * from t3 where a=1 for update
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 0 page no 3132 n bits 80 index `PRIMARY` of table `test`.`t3` trx id 11F41 lock_mode X locks rec but not gap
Record lock, heap no 3 PHYSICAL RECORD: n_fields 3; compact format; info bits 0
 0: len 4; hex 80000002; asc    ;;
 1: len 6; hex 000000011f35; asc      5;;
 2: len 7; hex e00000013a011d; asc    :  ;;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 0 page no 3132 n bits 80 index `PRIMARY` of table `test`.`t3` trx id 11F41 lock_mode X locks rec but not gap waiting
Record lock, heap no 2 PHYSICAL RECORD: n_fields 3; compact format; info bits 0
 0: len 4; hex 80000001; asc    ;;
 1: len 6; hex 000000011f35; asc      5;;
 2: len 7; hex e00000013a0110; asc    :  ;;

*** WE ROLL BACK TRANSACTION (2)
------------
TRANSACTIONS
------------
Trx id counter 11F45
Purge done for trx's n:o < 11F35 undo n:o < 0
History list length 1433
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 11F41, not started
MySQL thread id 79, OS thread handle 0x33d62600, query id 4162 localhost root
show engine innodb status
---TRANSACTION 11F36, not started
MySQL thread id 77, OS thread handle 0x33d61e80, query id 4118 localhost root
---TRANSACTION 11F2B, not started
MySQL thread id 75, OS thread handle 0x33d61d40, query id 4077 192.168.0.69 root
---TRANSACTION 0, not started
MySQL thread id 74, OS thread handle 0x33d61fc0, query id 4070 192.168.0.69 root
---TRANSACTION 0, not started
MySQL thread id 23, OS thread handle 0x33d62380, query id 114 192.168.0.69 root
---TRANSACTION 11F40, ACTIVE 5065 sec
3 lock struct(s), heap size 320, 2 row lock(s)
MySQL thread id 80, OS thread handle 0x33d62740, query id 4152 localhost root
--------
FILE I/O
--------
I/O thread 0 state: waiting for i/o request (insert buffer thread)
I/O thread 1 state: waiting for i/o request (log thread)
I/O thread 2 state: waiting for i/o request (read thread)
I/O thread 3 state: waiting for i/o request (read thread)
I/O thread 4 state: waiting for i/o request (read thread)
I/O thread 5 state: waiting for i/o request (read thread)
I/O thread 6 state: waiting for i/o request (write thread)
I/O thread 7 state: waiting for i/o request (write thread)
I/O thread 8 state: waiting for i/o request (write thread)
I/O thread 9 state: waiting for i/o request (write thread)
Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 0 [0, 0, 0, 0] ,
 ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
Pending flushes (fsync) log: 0; buffer pool: 0
691 OS file reads, 1923 OS file writes, 1010 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 0, seg size 2, 0 merges
merged operations:
 insert 0, delete mark 0, delete 0
discarded operations:
 insert 0, delete mark 0, delete 0
Hash table size 553253, node heap has 6 buffer(s)
0.00 hash searches/s, 0.00 non-hash searches/s
---
LOG
---
Log sequence number 594246629
Log flushed up to  594246629
Last checkpoint at  594246629
0 pending log writes, 0 pending chkp writes
649 log i/o's done, 0.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 135987200; in additional pool allocated 0
Dictionary memory allocated 281610
Buffer pool size  8192
Free buffers      4305
Database pages    3881
Old database pages 1418
Modified db pages  0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 5, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 633, created 3248, written 5875
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 3881, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
1 read views open inside InnoDB
Main thread id 869673728, state: waiting for server activity
Number of rows inserted 105750, updated 0, deleted 0, read 59717
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

1 row in set (0.00 sec)

ERROR:
No query specified

mysql>


mysql> call load_test(10000);
Query OK, 0 rows affected (0.50 sec)

mysql> show engine innodb status\G;
*************************** 1. row ***************************
  Type: InnoDB
  Name:
Status:
=====================================
121130 15:43:06 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 3 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 231 1_second, 230 sleeps, 18 10_second, 66 background, 66 flush
srv_master_thread log flush and writes: 234
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 114, signal count 113
Mutex spin waits 6, rounds 180, OS waits 2
RW-shared spins 99, rounds 2970, OS waits 99
RW-excl spins 0, rounds 390, OS waits 13
Spin rounds per wait: 30.00 mutex, 30.00 RW-shared, 390.00 RW-excl
------------------------
LATEST DETECTED DEADLOCK
------------------------
121130 14:17:47
*** (1) TRANSACTION:
TRANSACTION 11F40, ACTIVE 71 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 320, 2 row lock(s)
MySQL thread id 80, OS thread handle 0x33d62740, query id 4152 localhost root statistics
select * from t3 where a=2 for update
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 0 page no 3132 n bits 80 index `PRIMARY` of table `test`.`t3` trx id 11F40 lock_mode X locks rec but not gap waiting
Record lock, heap no 3 PHYSICAL RECORD: n_fields 3; compact format; info bits 0
 0: len 4; hex 80000002; asc    ;;
 1: len 6; hex 000000011f35; asc      5;;
 2: len 7; hex e00000013a011d; asc    :  ;;

*** (2) TRANSACTION:
TRANSACTION 11F41, ACTIVE 42 sec starting index read
mysql tables in use 1, locked 1
3 lock struct(s), heap size 320, 2 row lock(s)
MySQL thread id 79, OS thread handle 0x33d62600, query id 4153 localhost root statistics
select * from t3 where a=1 for update
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 0 page no 3132 n bits 80 index `PRIMARY` of table `test`.`t3` trx id 11F41 lock_mode X locks rec but not gap
Record lock, heap no 3 PHYSICAL RECORD: n_fields 3; compact format; info bits 0
 0: len 4; hex 80000002; asc    ;;
 1: len 6; hex 000000011f35; asc      5;;
 2: len 7; hex e00000013a011d; asc    :  ;;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 0 page no 3132 n bits 80 index `PRIMARY` of table `test`.`t3` trx id 11F41 lock_mode X locks rec but not gap waiting
Record lock, heap no 2 PHYSICAL RECORD: n_fields 3; compact format; info bits 0
 0: len 4; hex 80000001; asc    ;;
 1: len 6; hex 000000011f35; asc      5;;
 2: len 7; hex e00000013a0110; asc    :  ;;

*** WE ROLL BACK TRANSACTION (2)
------------
TRANSACTIONS
------------
Trx id counter 11F46
Purge done for trx's n:o < 11F35 undo n:o < 0
History list length 1433
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 11F45, not started
MySQL thread id 79, OS thread handle 0x33d62600, query id 34168 localhost root
show engine innodb status
---TRANSACTION 11F36, not started
MySQL thread id 77, OS thread handle 0x33d61e80, query id 4118 localhost root
---TRANSACTION 11F2B, not started
MySQL thread id 75, OS thread handle 0x33d61d40, query id 4077 192.168.0.69 root
---TRANSACTION 0, not started
MySQL thread id 74, OS thread handle 0x33d61fc0, query id 4070 192.168.0.69 root
---TRANSACTION 0, not started
MySQL thread id 23, OS thread handle 0x33d62380, query id 114 192.168.0.69 root
---TRANSACTION 11F40, ACTIVE 5190 sec
3 lock struct(s), heap size 320, 2 row lock(s)
MySQL thread id 80, OS thread handle 0x33d62740, query id 4152 localhost root
--------
FILE I/O
--------
I/O thread 0 state: waiting for i/o request (insert buffer thread)
I/O thread 1 state: waiting for i/o request (log thread)
I/O thread 2 state: waiting for i/o request (read thread)
I/O thread 3 state: waiting for i/o request (read thread)
I/O thread 4 state: waiting for i/o request (read thread)
I/O thread 5 state: waiting for i/o request (read thread)
I/O thread 6 state: waiting for i/o request (write thread)
I/O thread 7 state: waiting for i/o request (write thread)
I/O thread 8 state: waiting for i/o request (write thread)
I/O thread 9 state: waiting for i/o request (write thread)
Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 0 [0, 0, 0, 0] ,
 ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
Pending flushes (fsync) log: 0; buffer pool: 0
691 OS file reads, 1925 OS file writes, 1012 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 0, seg size 2, 0 merges
merged operations:
 insert 0, delete mark 0, delete 0
discarded operations:
 insert 0, delete mark 0, delete 0
Hash table size 553253, node heap has 6 buffer(s)
0.00 hash searches/s, 0.00 non-hash searches/s
---
LOG
---
Log sequence number 594751037
Log flushed up to  594751037
Last checkpoint at  594246629
0 pending log writes, 0 pending chkp writes
651 log i/o's done, 0.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 135987200; in additional pool allocated 0
Dictionary memory allocated 281610
Buffer pool size  8192
Free buffers      4305
Database pages    3881
Old database pages 1418
Modified d b pages  31
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 5, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 633, created 3248, written 5875
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
No buffer pool page gets since the last printout
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 3881, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
1 read views open inside InnoDB
Main thread id 869673728, state: sleeping
Number of rows inserted 115750, updated 0, deleted 0, read 59717
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

1 row in set (0.00 sec)

ERROR:
No query specified

mysql>

Log sequence number 表示当前的LSN;
Log flushed up表示刷新到重做日志文件的LSN,
Last checkpoint表示刷新到磁盘的LSN;

相关内容