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來觀察當前的磁盤和日志的差距; [html] 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;