找個mysql客戶端,執行show engine innodb status獲得以下結果:css
詳細信息以下:html
**************************************node
=====================================
2016-09-20 16:39:40 0x7f8040116700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 26 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 6928 srv_active, 0 srv_shutdown, 1725110 srv_idle
srv_master_thread log flush and writes: 1732038
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 11501
OS WAIT ARRAY INFO: signal count 14653
RW-shared spins 0, rounds 28035, OS waits 9399
RW-excl spins 0, rounds 153048, OS waits 986
RW-sx spins 2611, rounds 47408, OS waits 573
Spin rounds per wait: 28035.00 RW-shared, 153048.00 RW-excl, 18.16 RW-sx
------------------------
LATEST DETECTED DEADLOCK
------------------------
2016-09-20 16:24:30 0x7f801efe6700
*** (1) TRANSACTION:
TRANSACTION 3348053, ACTIVE 0 sec inserting
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 1136, 2 row lock(s), undo log entries 1
MySQL thread id 10713, OS thread handle 140188808488704, query id 4311670 10.118.63.64 root update
INSERT INTO tt_rps_flight_mainline_info_init (
plan_send_batch_dt,
require_id,
line_id,
line_code,
conveyance_type,
src_zone_code,
depart_batch_code,
dest_zone_code,
plan_distribute_batch_dt,
plan_distribute_batch_code,
load_weight,
load_qty,
load_vol,
create_tm
)
VALUES ('2016-09-09','10000047160909',10000047,'010X020R1600',2,'010X','010X1400','020X','2016-09-09','020X2000',800.0,298,7.0,'2016-09-20') ON DUPLICATE KEY UPDATE
require_id ='10000047160909'
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 1668 page no 4 n bits 96 index require_id of table `omcssit`.`tt_rps_flight_mainline_info_init` trx id 3348053 lock_mode X locks gap before rec insert intention waiting
Record lock, heap no 12 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
0: len 14; hex 3130303030303438313630393137; asc 10000048160917;;
1: len 4; hex 80000031; asc 1;;mysql
*** (2) TRANSACTION:
TRANSACTION 3348048, ACTIVE 0 sec updating or deleting
mysql tables in use 1, locked 1
7 lock struct(s), heap size 1136, 7 row lock(s), undo log entries 1
MySQL thread id 10710, OS thread handle 140188252530432, query id 4311629 10.118.63.64 root update
INSERT INTO tt_rps_flight_mainline_info_init (
plan_send_batch_dt,
require_id,
line_id,
line_code,
conveyance_type,
src_zone_code,
depart_batch_code,
dest_zone_code,
plan_distribute_batch_dt,
plan_distribute_batch_code,
load_weight,
load_qty,
load_vol,
create_tm
)
VALUES ('2016-09-23','10000047160923',10000047,'010X020R1600',2,'010X','010X1400','020X','2016-09-23','020X2000',800.0,298,7.0,'2016-09-20') ON DUPLICATE KEY UPDATE
require_id ='10000047160923'
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 1668 page no 4 n bits 96 index require_id of table `omcssit`.`tt_rps_flight_mainline_info_init` trx id 3348048 lock_mode X locks gap before rec
Record lock, heap no 12 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
0: len 14; hex 3130303030303438313630393137; asc 10000048160917;;
1: len 4; hex 80000031; asc 1;;linux
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 1668 page no 4 n bits 96 index require_id of table `omcssit`.`tt_rps_flight_mainline_info_init` trx id 3348048 lock_mode X locks gap before rec insert intention waiting
Record lock, heap no 12 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
0: len 14; hex 3130303030303438313630393137; asc 10000048160917;;
1: len 4; hex 80000031; asc 1;;算法
*** WE ROLL BACK TRANSACTION (1)
------------
TRANSACTIONS
------------
Trx id counter 3348415
Purge done for trx's n:o < 3348405 undo n:o < 0 state: running but idle
History list length 1152
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 421667018339760, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421667018330640, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421667018327904, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421667018335200, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421667018320608, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421667018319696, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421667018322432, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421667018329728, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421667018321520, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421667018324256, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421667018323344, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421667018345232, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421667018334288, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421667018346144, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421667018343408, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421667018342496, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421667018340672, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421667018337024, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421667018333376, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421667018326080, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421667018337936, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421667018336112, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421667018331552, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421667018338848, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421667018326992, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421667018325168, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421667018332464, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421667018328816, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
--------
FILE I/O
--------
I/O thread 0 state: waiting for completed aio requests (insert buffer thread)
I/O thread 1 state: waiting for completed aio requests (log thread)
I/O thread 2 state: waiting for completed aio requests (read thread)
I/O thread 3 state: waiting for completed aio requests (read thread)
I/O thread 4 state: waiting for completed aio requests (read thread)
I/O thread 5 state: waiting for completed aio requests (read thread)
I/O thread 6 state: waiting for completed aio requests (write thread)
I/O thread 7 state: waiting for completed aio requests (write thread)
I/O thread 8 state: waiting for completed aio requests (write thread)
I/O thread 9 state: waiting for completed aio requests (write thread)
Pending normal aio reads: [0, 0, 0, 0] , aio writes: [0, 0, 0, 0] ,
ibuf aio reads:, log i/o's:, sync i/o's:
Pending flushes (fsync) log: 0; buffer pool: 0
9681 OS file reads, 106275 OS file writes, 66325 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 0.88 writes/s, 0.00 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 218, seg size 220, 1 merges
merged operations:
insert 26, delete mark 0, delete 0
discarded operations:
insert 0, delete mark 0, delete 0
Hash table size 553193, node heap has 4 buffer(s)
Hash table size 553193, node heap has 38 buffer(s)
Hash table size 553193, node heap has 4 buffer(s)
Hash table size 553193, node heap has 38 buffer(s)
Hash table size 553193, node heap has 5 buffer(s)
Hash table size 553193, node heap has 15 buffer(s)
Hash table size 553193, node heap has 18 buffer(s)
Hash table size 553193, node heap has 14 buffer(s)
0.00 hash searches/s, 0.00 non-hash searches/s
---
LOG
---
Log sequence number 11294369115
Log flushed up to 11294369115
Pages flushed up to 11294369115
Last checkpoint at 11294369106
0 pending log flushes, 0 pending chkp writes
35039 log i/o's done, 0.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total large memory allocated 2198863872
Dictionary memory allocated 4350175
Buffer pool size 131056
Free buffers 117742
Database pages 13178
Old database pages 4702
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 11, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 9524, created 3654, written 56445
0.00 reads/s, 0.00 creates/s, 0.88 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 13178, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
----------------------
INDIVIDUAL BUFFER POOL INFO
----------------------
---BUFFER POOL 0
Buffer pool size 16382
Free buffers 14669
Database pages 1693
Old database pages 604
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1283, created 410, written 9934
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: 1693, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 1
Buffer pool size 16382
Free buffers 14875
Database pages 1487
Old database pages 528
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1061, created 426, written 2942
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 1487, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 2
Buffer pool size 16382
Free buffers 14830
Database pages 1537
Old database pages 548
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 3, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 988, created 549, written 2304
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: 1537, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 3
Buffer pool size 16382
Free buffers 14661
Database pages 1705
Old database pages 610
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 2, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1228, created 477, written 7440
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 1705, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 4
Buffer pool size 16382
Free buffers 14615
Database pages 1751
Old database pages 626
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1310, created 441, written 7277
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 1751, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 5
Buffer pool size 16382
Free buffers 14653
Database pages 1716
Old database pages 613
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1240, created 476, written 16534
0.00 reads/s, 0.00 creates/s, 0.88 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 1716, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 6
Buffer pool size 16382
Free buffers 14754
Database pages 1609
Old database pages 573
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 6, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1158, created 451, written 5331
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: 1609, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
---BUFFER POOL 7
Buffer pool size 16382
Free buffers 14685
Database pages 1680
Old database pages 600
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 1256, created 424, written 4683
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: 1680, 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
0 read views open inside InnoDB
Process ID=51314, Main thread ID=140188844484352, state: sleeping
Number of rows inserted 353558, updated 150693, deleted 10356, read 720801965
4.23 inserts/s, 0.00 updates/s, 0.00 deletes/s, 42.69 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================sql
**************************************數據庫
innodb存儲引擎在show engine innodb status(老版本對應的是show innodb status)輸出中,顯示除了大量的內部信息,它輸出就是一個單獨的字符串,沒有行和列,內容分爲不少小段,每一段對應innodb存儲引擎不一樣部分的信息,其中有一些信息對於innodb開發者來講很是有用,可是,許多信息,若是你嘗試去理解,而且應用到高性能innodb調優的時候,你會發現它們很是有趣,甚至是很是有必要的。數組
輸出內容中包含了一些平均值的統計信息,這些平均值是自上次輸出結果生成以來的統計數,所以,若是你正在檢查這些值,那就要確保已經等待了至少30s的時間,使兩次採樣之間的積累足夠長的統計時間並屢次採樣,檢查計數器變化從而弄清其行爲,並非全部的輸出都會在一個時間點上生成,於是也不是全部的顯示出來的平均值會在同一時間間隔裏從新再計算。並且,innodb有一個內部復位間隔,而它是不可預知的,各個版本也不同。
這些輸出信息足夠提供給手工計算出大多數你想要的統計信息,有一款監控工具innotop能夠幫你計算出增量差值和平均值。下面,在你的mysql命令行敲下show engine innodb status;看着輸出跟着下面的步驟一步一步理解輸出信息是什麼含義:
注意:如下使用mysql5.5.24版本作解讀,mysql5.6.x和5.7.x輸出內容有些地方有調整。
1.第一段是頭部信息,它僅僅聲明瞭輸出的開始,其內容包括當前的日期和時間,以及自上次輸出以來通過的時長。
=====================================
160129 12:07:26 INNODB MONITOR OUTPUT
#第二行是當前日期和時間
=====================================
Per second averages calculated from the last 24 seconds
#第四行顯示的是計算出這一平均值的時間間隔,即自上次輸出以來的時間,或者是距上次內部復位的時長
2.從
innodb1.0.x開始,可使用命令show engine innodb status;來查看master thread的狀態信息:
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 30977173 1_second, 30975685 sleeps, 3090359 10_second, 166112 background, 165988 flush
#這行顯示主循環進行了30977173 1_second次,每秒掛起的操做進行了30975685 sleeps次(說明負載不是很大),10秒一次的活動進行了3090359 10_second次,1秒循環和10秒循環比值符合1:10,backgroup loop進行了166112 background次,flush loop進行了165988 flush次,若是在一臺很大壓力的mysql上,可能看到每秒運行次數和掛起次數比例小於1不少,這是由於innodb對內部進行了一些優化,當壓力大時間隔時間並不老是等待1秒,所以,不能認爲每秒循環和掛起的值老是相等,在某些狀況下,能夠經過二者之間的差值來比較反映當前數據庫的負載壓力。
srv_master_thread log flush and writes: 31160103
3.若是有高併發的工做負載,你就要關注下接下來的段(SEMAPHORES信號量),它包含了兩種數據:事件計數器以及可選的當前等待線程的列表,若是有性能上的瓶頸,可使用這些信息來找出瓶頸,不幸的是,想知道怎麼使用這些信息仍是有一點複雜,下面先給出一些解釋:
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 68581015, signal count 218437328
--Thread 140653057947392 has waited at btr0pcur.c line 437 for 0.00 seconds the semaphore:
S-lock on RW-latch at 0x7ff536c7d3c0 created in file buf0buf.c line 916
a writer (thread id 140653057947392) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file row0sel.c line 3097
Last time write locked in file /usr/local/src/soft/mysql-5.5.24/storage/innobase/buf/buf0buf.c line 3151
--Thread 140653677291264 has waited at btr0pcur.c line 437 for 0.00 seconds the semaphore:
S-lock on RW-latch at 0x7ff53945b240 created in file buf0buf.c line 916
a writer (thread id 140653677291264) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file row0sel.c line 3097
Last time write locked in file /usr/local/src/soft/mysql-5.5.24/storage/innobase/buf/buf0buf.c line 3151
Mutex spin waits 1157217380, rounds 1783981614, OS waits 10610359
RW-shared spins 103830012, rounds 1982690277, OS waits 52051891
RW-excl spins 43730722, rounds 602114981, OS waits 3495769
Spin rounds per wait: 1.54 mutex, 19.10 RW-shared, 13.77 RW-excl
內容比較多,下面分段依次解釋:
3.1.
OS WAIT ARRAY INFO: reservation count 68581015, signal count 218437328
#這行給出了關於操做系統等待數組的信息,它是一個插槽數組,innodb在數組裏爲信號量保留了一些插槽,操做系統用這些信號量給線程發送信號,使線程能夠繼續運行,以完成它們等着作的事情,這一行還顯示出innodb使用了多少次操做系統的等待:保留統計(reservation count)顯示了innodb分配插槽的頻度,而信號
計數(signal count)衡量的是線程經過數組獲得信號的頻度,操做系統的等待相對於空轉等待(spin wait)要昂貴些。
3.2.
--Thread 140653057947392 has waited at btr0pcur.c line 437 for 0.00 seconds the semaphore:
S-lock on RW-latch at 0x7ff536c7d3c0 created in file buf0buf.c line 916
a writer (thread id 140653057947392) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file row0sel.c line 3097
Last time write locked in file /usr/local/src/soft/mysql-5.5.24/storage/innobase/buf/buf0buf.c line 3151
--Thread 140653677291264 has waited at btr0pcur.c line 437 for 0.00 seconds the semaphore:
S-lock on RW-latch at 0x7ff53945b240 created in file buf0buf.c line 916
a writer (thread id 140653677291264) has reserved it in mode exclusive
number of readers 0, waiters flag 1, lock_word: 0
Last time read locked in file row0sel.c line 3097
Last time write locked in file /usr/local/src/soft/mysql-5.5.24/storage/innobase/buf/buf0buf.c line 3151
這部分顯示的是當前正在等待互斥量的innodb線程,在這裏能夠看到有兩個線程正在等待,每個都是以--Thread <數字> has waited...開始,這一段內容在正常狀況下應該是空的(即查看的時候沒有這部份內容),除非服務器運行着高併發的工做負載,促使innodb採起讓操做系統等待的措施,除非你對innodb源碼熟悉,不然這裏看到的最有用的信息就是發生線程等待的代碼文件名 /usr/local/src/soft/mysql-5.5.24/storage/innobase/buf/buf0buf.c line 3151。
在innodb內部哪裏纔是熱點?舉例來講,若是看到許多線程都在一個名爲buf0buf.c的文件上等待,那就意味着你的系統裏存在着
緩衝池競爭,這個輸出信息還顯示了這些線程等待了多少時間,其中waiters flag顯示了有多少個等待着正在等待同一個互斥量。 若是waiters flag爲0那就表示沒有線程在等待同一個互斥量(此時在waiters flag 0後面可能能夠看到wait is ending,表示這個互斥量已經被釋放了,但操做系統尚未把線程調度過來運行)。
你可能想知道innodb真正等待的是什麼,innodb使用了互斥量和信號量來保護代碼的臨界區,如:限定每次只能有一個線程進入臨界區,或者是當有活動的讀時,就限制寫入等。在innodb代碼裏有不少臨界區,在合適的條件下,它們均可能出如今那裏,經常能見到的一種情形是:獲取緩衝池分頁的訪問權的時候。
3.3.
在等待線程以後的部分信息以下,這部分顯示了更多的事件計數器,在每個情形中,都能看到innodb依靠操做系統等待的頻度:
Mutex spin waits 1157217380, rounds 1783981614, OS waits 10610359
#這行顯示的是跟互斥量相關的幾個計數器
RW-shared spins 103830012, rounds 1982690277, OS waits 52051891
#這行顯示讀寫的共享鎖的計數器
RW-excl spins 43730722, rounds 602114981, OS waits 3495769
#這行顯示讀寫的排他鎖的計數器
Spin rounds per wait: 1.54 mutex, 19.10 RW-shared, 13.77 RW-excl
innodb有着一個多階段等待的策略,首先,它會試着對鎖進行空轉等待,若是經歷了一個預設的空轉等待週期(設置innodb_sync_spin_loops配置變量命令)以後尚未成功,那就會退到更昂貴更復雜的等待數組中。
空轉等待的成本相對較低,可是它們要不停地檢查一個資源可否被鎖定,這種方式會消耗CPU週期,可是,這沒有聽起來那麼糟糕,由於當處理器在等待IO時,通常都有一些空閒的CPU週期可用,即便是沒有空閒的CPU週期,空等也要比其餘方式更加廉價一些。然而,當另一個線程能作一些事情的時候,空轉等待也還會把CPU獨佔着。
空轉等待的替代方案就是讓操做系統作上下文切換,這樣,當一個線程在等待時,另一個線程就能夠被運行,而後,經過等待數組裏的信號量發出信號,喚醒那個沉睡的線程,經過信號量來發送信號是比較有效的,可是上下文切換就很昂貴,這很快就會聚沙成塔,每秒鐘幾千次的切換會引起大量的系統開銷。
你能夠經過修改innodb_sync_spin_loops的值,試着在空轉等待與操做系統等待之間達成平衡,不要擔憂空轉等待,除非你在一秒裏看到幾十萬個空轉等待。此時,你能夠考慮performance_schema庫或者show engine innodb mutex;查看下相關信息。
4.下面這一段外鍵錯誤的信息通常不會出現,除非你服務器上發生了外鍵錯誤,有時問題在於事務在插入,更新或刪除一條記錄時要尋找父表或子表,還有時候是當innodb嘗試增長或刪除一個外鍵或者修改一個已經存在的外鍵時,發現表之間類型不匹配,這部分輸出對於調試與innodb不明確的外鍵錯誤發生的準確緣由很是有幫助,下面搞一個示例來看看:
4.1 建立父表:
mysql> create table parent(parent_id int not null,primary key(parent_id)) engine=innodb;
4.2 建立子表:
mysql> create table child(child_id int not null,key child_id(child_id),constraint i_child foreign key(child_id) references parent(parent_id)) engine=innodb;
4.3 插入數據:
mysql> insert into parent(parent_id) values(1);
mysql> insert into child(child_id) values(1);
4.5 有兩種基本的外鍵錯誤:
第一種:以某種可能違反外鍵約束關係的方法增長,更新,刪除數據,將致使第一類錯誤,如,在父表中刪除行時發生以下錯誤:
mysql> delete from parent;
ERROR 1451 (23000): Cannot delete or update a parent row: a foreign key constraint fails (`xiaoboluo`.`child`, CONSTRAINT `i_child` FOREIGN KEY (`child_id`) REFERENCES `parent` (`parent_id`))
錯誤信息至關明瞭,對全部由增長,刪除,更新不匹配的行致使的錯誤都會看到類似的信息,下面是show engine innodb status的輸出:
------------------------
LATEST FOREIGN KEY ERROR
------------------------
160128 1:17:06 Transaction:
#這行顯示了最近一次外鍵錯誤的日期和時間
TRANSACTION D203D6, ACTIVE 0 sec updating or deleting
mysql tables in use 1, locked 1
4 lock struct(s), heap size 1248, 2 row lock(s), undo log entries 1
MySQL thread id 20027, OS thread handle 0x7f0a4c0f8700, query id 1813996 localhost root updating
delete from parent
Foreign key constraint fails for table `xiaoboluo`.`child`:
,
#上面部分顯示了關於破壞外鍵約束的事務詳情。後邊部分顯示了發現錯誤時innodb正嘗試修改的準確數據,輸出中有許可能是轉換成可打印格式的行數據。
CONSTRAINT `i_child` FOREIGN KEY (`child_id`) REFERENCES `parent` (`parent_id`)
Trying to delete or update in parent table, in index `PRIMARY` tuple:
DATA TUPLE: 3 fields;
0: len 4; hex 80000001; asc ;;
1: len 6; hex 000000d203d6; asc ;;
2: len 7; hex 1e000001ca0110; asc ;;
But in child table `xiaoboluo`.`child`, in index `child_id`, there is a record:
PHYSICAL RECORD: n_fields 2; compact format; info bits 0
0: len 4; hex 80000001; asc ;;
1: len 6; hex 000013a99b3e; asc >;;
4.6 第二種:嘗試修改父表的表結構時發生的錯誤,這種錯誤就沒有那麼清楚了,這可能會讓調試更困難:
mysql> alter table parent modify parent_id int unsigned not null;
ERROR 1025 (HY000): Error on rename of './xiaoboluo/#sql-b695_4e3b' to './xiaoboluo/parent' (errno: 150)
查看show engine innodb status輸出信息:
------------------------
LATEST FOREIGN KEY ERROR
------------------------
160128 1:32:33 Error in foreign key constraint of table xiaoboluo/child:
there is no index in referenced table which would contain
the columns as the first columns, or the data types in the
referenced table do not match the ones in table. Constraint:
,
CONSTRAINT "i_child" FOREIGN KEY ("child_id") REFERENCES "parent" ("parent_id")
The index in the foreign key in table is "child_id"
for correct foreign key definition.
InnoDB: Renaming table `xiaoboluo`.<result 2 when explaining filename '#sql-b695_4e3b'> to `xiaoboluo`.`parent` failed!
上面的錯誤是數據類型不匹配,外鍵列必須有徹底相同的數據類型,包括任何的修飾符(如這裏父表多加了一個unsigned,這也是問題所在),當看到1025錯誤並不理解爲何時,最好查看下innodb status。在每次看到有新錯誤時,外鍵錯誤信息都會被重寫,percona toolkit中的pt-fk-error-logger工具能夠用表保存這些信息以供後續分析。
5.與外鍵錯誤同樣,這部分只有當服務器產生死鎖時纔會出現,死鎖信息一樣在每次有新的死鎖錯誤時被重寫,percona toolkit中的pt-deadlock-logger工具能夠用表保存這些信息以供後續分析
死鎖在等待關係圖裏是一個循環,就是一個鎖定了行的數據結構又在等待別的鎖,這個循環能夠任意地大,innodb會當即檢測到死鎖,由於每當有事務等待行鎖的時候,它都會去檢查等待關係圖裏是否有循環,死鎖的狀況可能會比較複雜,可是,這一部分只顯示了最近的兩個死鎖的狀況,它們在各自的事務裏執行的最後一條語句,以及它們在等待關係圖裏造成環鎖的信息。在這個循環裏你看不到其餘事務,也可能看不到在事務裏早先真正得到了鎖的語句,儘管如此,一般仍是能夠經過查看這些輸出結果來肯定究竟是什麼引發了死鎖。
在innodb裏實際上有兩種死鎖,第一種就是經常碰到的那種,它在等待關係圖裏是一個真正的循環,另一種就是在一個等待關係圖裏,因代價昂貴而沒法檢測它是否是包含了循環,若是innodb要在關係圖裏檢查超過100W個鎖,或者在檢查過程當中,innodb要重作200個以上的事務,那它會放棄,並宣佈這裏有一個死鎖,這些數值都是硬編碼在innodb代碼裏的常量,沒法配置(若是你NB能夠修改代碼而後從新編譯)。第二種死鎖報錯你能夠在輸出裏看到一條信息:TOO DEEP OR LONG SEARCH IN THE LOCK TABLE WAITS-FOR GRAPH
innodb不只會打印出事務和事務持有和等待的鎖,並且還有記錄自己,不幸的是,它至於可能超過爲輸出結果預留的長度(只能打印1M的內容且只能保留最近一次的死鎖信息),若是你沒法看到完整的輸出,此時能夠在任意庫下建立innodb_monitor或innodb_lock_monitor表,這樣innodb status信息會完整且每15s一次被記錄到錯誤日誌中。如:create table innodb_monitor(a int)engine=innodb;,不須要記錄到錯誤日誌中時就刪掉這個表便可。緩存
5.1 下面也搞一個示例來看看:
5.1.1 建表:
mysql> create table test_deadlock(id int unsigned not null primary key auto_increment,test int unsigned not null);
Query OK, 0 rows affected (0.02 sec)
5.1.2 插入測試數據:
mysql> insert into test_deadlock(test) values(1),(2),(3),(4),(5);
Query OK, 5 rows affected (0.00 sec)
Records: 5 Duplicates: 0 Warnings: 0
打開兩個會話終端:
5.1.3 會話1執行下面的SQL:
mysql> set autocommit=0;
Query OK, 0 rows affected (0.00 sec)
mysql> select * from test_deadlock where id=1 for update;
+----+------+
| id | test |
+----+------+
| 1 | 1 |
+----+------+
1 row in set (0.00 sec)
5.1.4 接着會話2執行下面的SQL:
mysql> set autocommit=0;
Query OK, 0 rows affected (0.00 sec)
mysql> select * from test_deadlock where id=2 for update;
+----+------+
| id | test |
+----+------+
| 2 | 2 |
+----+------+
1 row in set (0.00 sec)
5.1.5 回到會話1執行下面的SQL,會發生等待:
mysql> select * from test_deadlock where id=2 for update;
5.1.6 回到會話2執行下面的SQL,產生死鎖,會話2被回滾:
mysql> select * from test_deadlock where id=1 for update;
ERROR 1213 (40001): Deadlock found when trying to get lock; try restarting transaction
5.2 查看innodb status信息:
------------------------
LATEST DETECTED DEADLOCK
------------------------
160128 1:51:53
#這裏顯示了最近一次發生死鎖的日期和時間
*** (1) TRANSACTION:
TRANSACTION D20847, ACTIVE 141 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 376, 2 row lock(s)
MySQL thread id 20027, OS thread handle 0x7f0a4c0f8700, query id 1818124 localhost root statistics
select * from test_deadlock where id=2 for update
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 441 page no 3 n bits 72 index `PRIMARY` of table `xiaoboluo`.`test_deadlock` trx id D20847 lock_mode X locks rec but not gap waiting
Record lock, heap no 3 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
0: len 4; hex 00000002; asc ;;
1: len 6; hex 000000d20808; asc ;;
2: len 7; hex ad000001ab011d; asc ;;
3: len 4; hex 00000002; asc ;;
*** (2) TRANSACTION:
TRANSACTION D20853, ACTIVE 119 sec starting index read
mysql tables in use 1, locked 1
3 lock struct(s), heap size 1248, 2 row lock(s)
MySQL thread id 20081, OS thread handle 0x7f0a0f020700, query id 1818204 localhost root statistics
select * from test_deadlock where id=1 for update
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 441 page no 3 n bits 72 index `PRIMARY` of table `xiaoboluo`.`test_deadlock` trx id D20853 lock_mode X locks rec but not gap
Record lock, heap no 3 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
0: len 4; hex 00000002; asc ;;
1: len 6; hex 000000d20808; asc ;;
2: len 7; hex ad000001ab011d; asc ;;
3: len 4; hex 00000002; asc ;;
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 441 page no 3 n bits 72 index `PRIMARY` of table `xiaoboluo`.`test_deadlock` trx id D20853 lock_mode X locks rec but not gap waiting
Record lock, heap no 2 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
0: len 4; hex 00000001; asc ;;
1: len 6; hex 000000d20808; asc ;;
2: len 7; hex ad000001ab0110; asc ;;
3: len 4; hex 00000001; asc ;;
*** WE ROLL BACK TRANSACTION (2)
這部份內容比較多,下面分段逐一進行解釋:
5.2.1 下面這部分顯示的是死鎖的第一個事務的信息:
*** (1) TRANSACTION:
TRANSACTION D20847, ACTIVE 141 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 376, 2 row lock(s)
MySQL thread id 20027, OS thread handle 0x7f0a4c0f8700, query id 1818124 localhost root statistics
select * from test_deadlock where id=2 for update
TRANSACTION D20847, ACTIVE 141 sec starting index read:
這行表示事務D20847,ACTIVE 141 sec表示事務處於活躍狀態141s,starting index read表示正在使用索引讀取數據行
mysql tables in use 1, locked 1
#這行表示事務D20847正在使用1個表,且涉及鎖的表有1個
LOCK WAIT 3 lock struct(s), heap size 376, 2 row lock(s)
#這行表示在等待3把鎖,佔用內存376字節,涉及2行記錄,若是事務已經鎖定了幾行數據,這裏將會有一行信息顯示出鎖定結構的數目(注意,這跟行鎖是兩回事)和堆大小,堆的大小指的是爲了持有這些行鎖而佔用的內存大小,Innodb是用一種特殊的位圖表來實現行鎖的,從理論上講,它可將每個鎖定的行表示爲一個比特,經測試顯示,每一個鎖一般不超過4比特
MySQL thread id 20027, OS thread handle 0x7f0a4c0f8700, query id 1818124 localhost root statistics
#這行表示該事務的線程ID信息,操做系統句柄信息,鏈接來源、用戶
select * from test_deadlock where id=2 for update
#這行表示事務涉及的SQL
5.2.2 下面這一部分顯示的是當死鎖發生時,第一個事務正在等待的鎖等信息:
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
#這行信息表示第一個事務正在等待鎖被授予
RECORD LOCKS space id 441 page no 3 n bits 72 index `PRIMARY` of table `xiaoboluo`.`test_deadlock` trx id D20847 lock_mode X locks rec but not gap waiting
Record lock, heap no 3 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
0: len 4; hex 00000002; asc ;;
1: len 6; hex 000000d20808; asc ;;
2: len 7; hex ad000001ab011d; asc ;;
3: len 4; hex 00000002; asc ;;
RECORD LOCKS space id 441 page no 3 n bits 72 index `PRIMARY` of table `xiaoboluo`.`test_deadlock` trx id D20847 lock_mode X locks rec but not gap waiting
#這行信息表示等待的鎖是一個record lock,空間id是441,頁編號爲3,大概位置在頁的72位處,鎖發生在表xiaoboluo.test_deadlock的主鍵上,是一個X鎖,可是不是gap lock。 waiting表示正在等待鎖
Record lock, heap no 3 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
#這行表示record lock的heap no 位置
#這部分剩下的內容只對調試纔有用。
0: len 4; hex 00000002; asc ;;
1: len 6; hex 000000d20808; asc ;;
2: len 7; hex ad000001ab011d; asc ;;
3: len 4; hex 00000002; asc ;;
5.2.3 下面這部分是事務二的狀態:
*** (2) TRANSACTION:
TRANSACTION D20853, ACTIVE 119 sec starting index read
#事務2處於活躍狀態119s
mysql tables in use 1, locked 1
#正在使用1個表,涉及鎖的表有1個
3 lock struct(s), heap size 1248, 2 row lock(s)
#涉及3把鎖,2行記錄
MySQL thread id 20081, OS thread handle 0x7f0a0f020700, query id 1818204 localhost root statistics
select * from test_deadlock where id=1 for update
#第二個事務的SQL
5.2.4 下面這部分是事務二的持有鎖信息:
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 441 page no 3 n bits 72 index `PRIMARY` of table `xiaoboluo`.`test_deadlock` trx id D20853 lock_mode X locks rec but not gap
Record lock, heap no 3 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
0: len 4; hex 00000002; asc ;;
1: len 6; hex 000000d20808; asc ;;
2: len 7; hex ad000001ab011d; asc ;;
3: len 4; hex 00000002; asc ;;
RECORD LOCKS space id 441 page no 3 n bits 72 index `PRIMARY` of table `xiaoboluo`.`test_deadlock` trx id D20853 lock_mode X locks rec but not gap
Record lock, heap no 3 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
#從這兩行持有鎖信息計息後面幾行調試信息上看,就是事務1正在等待的鎖。
5.2.5 下面這部分是事務二正在等待的鎖,從下面的信息上看,等待的是同一個表,同一個索引,同一個page上的record lock X鎖,可是heap no位置不一樣,即不一樣的行上的鎖:
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 441 page no 3 n bits 72 index `PRIMARY` of table `xiaoboluo`.`test_deadlock` trx id D20853 lock_mode X locks rec but not gap waiting
Record lock, heap no 2 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
0: len 4; hex 00000001; asc ;;
1: len 6; hex 000000d20808; asc ;;
2: len 7; hex ad000001ab0110; asc ;;
3: len 4; hex 00000001; asc ;;
*** WE ROLL BACK TRANSACTION (2) #這個表示事務2被回滾,由於兩個事務的回滾開銷同樣,因此選擇了後提交的事務進行回滾,若是兩個事務回滾的開銷不一樣(undo 數量不一樣),那麼就回滾開銷最小的那個事務。
當一個事務持有了其餘事務須要的鎖,同時又想得到其餘事務持有的鎖時,等待關係圖上就會產生循環,Innodb不會顯示全部持有和等待的鎖,可是,它顯示了足夠的信息來幫你肯定,查詢操做正在使用哪些索引,這對於你肯定可否避免死鎖有極大的價值。
若是能使兩個查詢對同一個索引朝同一個方向進行掃描,就能下降死鎖的數目,由於,查詢在同一個順序上請求鎖的時候不會建立循環,有時候,這是很容易作到的,如:要在一個事務裏更新許多條記錄,就能夠在應用程序的內存裏把它們按照主鍵進行排序,而後,再用一樣的順序更新到數據庫裏,這樣就不會有死鎖發生,可是在另外一些時候,這個方法也是行不通的(若是有兩個進程使用了不一樣的索引區間操做同一張表的時候)。
6. 下面這部分包含了一些關於innodb事務的總結信息,緊隨其後的是當前活躍事務列表,如:
------------
TRANSACTIONS
------------
Trx id counter 4E0132AD
Purge done for trx's n:o < 4E01090B undo n:o < 0
History list length 1853
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 4E0131D3, not started
MySQL thread id 26208218, OS thread handle 0x7fec7c582700, query id 5274800318 10.207.162.69 gdsser
---TRANSACTION 4E01323F, not started
MySQL thread id 26208217, OS thread handle 0x7fec7c1b3700, query id 5274800938 10.207.162.69 gdsser
....................
---TRANSACTION 4E0132AC, ACTIVE 0 sec preparing
2 lock struct(s), heap size 376, 1 row lock(s), undo log entries 1
MySQL thread id 26208200, OS thread handle 0x7fec567e0700, query id 5274801557 10.207.162.69 gdsser
commit
---TRANSACTION 4E0110E7, ACTIVE 188 sec
mysql tables in use 1, locked 0
MySQL thread id 26208154, OS thread handle 0x7fec7c235700, query id 5274800671 10.143.90.228 root Sending data
SELECT /*!40001 SQL_NO_CACHE */ * FROM `m_flowskillpoint`
Trx read view will not see trx with id >= 4E0110E8, sees < 4E0108EE
---TRANSACTION 4E0108EF, ACTIVE 233 sec fetching rows
mysql tables in use 1, locked 0
MySQL thread id 26208131, OS thread handle 0x7fec578e3700, query id 5274801341 10.143.90.228 root Sending data
SELECT /*!40001 SQL_NO_CACHE */ * FROM `m_flowsilver`
Trx read view will not see trx with id >= 4E0108F0, sees < 4E0108EC
---TRANSACTION 4E0108EE, ACTIVE 233 sec fetching rows
mysql tables in use 1, locked 0
MySQL thread id 26208132, OS thread handle 0x7fec7c78a700, query id 5274797797 10.143.90.228 root Sending data
SELECT /*!40001 SQL_NO_CACHE */ * FROM `m_flowmail`
Trx read view will not see trx with id >= 4E0108EF, sees < 4E0108EC
這部份內容比較多,下面分段逐一進行解釋:
6.1.
Trx id counter 4E0132AD
#這行表示當前事務ID,這是一個系統變量,每建立一個新事務都會增長
Purge done for trx's n:o < 4E01090B undo n:o < 0
#這是innodb清除舊MVCC行時所用的事務ID,將這個值和當前事務ID進行比較,就能夠知道有多少老版本的數據未被清除。這個數字多大才能夠安全的取值沒有硬性和速成的規定,若是數據沒作過任何更新,那麼一個巨大的數字也不意味着有未清除的數據,由於實際上全部事務在數據庫裏查看的都是同一個版本的數據(此時只是事務ID在增長,而數據沒有變動),另外一方面,若是有不少行被更新,那每一行就會有一個或多個版本留在內存裏,減小此類開銷的最好辦法就是確保事務已完成就當即提交,不要讓它長時間地處於打開狀態,由於一個打開的事務即便不作任何操做,也會影響到innodb清理舊版本的行數據。 undo n:o < 0這個是innodb清理進程正在使用的撤銷日誌編號,爲0 0時說明清理進程處於空閒狀態。
History list length 1853
#歷史記錄的長度,即位於innodb數據文件的撤銷空間裏的頁面的數目,若是事務執行了更新並提交,這個數字就會增長,而當清理進程移除舊版本數據時,它就會減小,清理進程也會更新Purge done for.....這行中的數值。
6.2.
頭部信息以後就是一個事務列表,當前版本的mysql還不支持嵌套事務,所以,在某個時間點上,每一個客戶端鏈接可以擁有的事務數量是有一個上限的,並且每個事務只能屬於單一鏈接(即一個事務只能使用單個線程執行,不能使用多個線程)。在輸出信息裏,每個事務至少佔有兩行內容,如:
---TRANSACTION 4E0131D3, not started
#每一個事務的第一行以事務的ID和狀態開始,not started表示這個事務已經提交而且沒有再發起影響事務的語句,可能恰好空閒
MySQL thread id 26208218, OS thread handle 0x7fec7c582700, query id 5274800318 10.207.162.69 gdsser
#而後每一個事務的第二行是一些線程等信息,MySQL thread id <數字>部分和是hi用show full processlist;命令看到的id列相同。緊隨其後的是一個內部查詢id和一些鏈接信息,這些信息一樣與show full processlist中的輸出相同。
---TRANSACTION 4E01323F, not started
MySQL thread id 26208217, OS thread handle 0x7fec7c1b3700, query id 5274800938 10.207.162.69 gdsser
6.3.
上面是not started狀態的事務信息,下面來看看爲ACTIVE狀態的事務信息:
---TRANSACTION 4E0110E7, ACTIVE 188 sec
#這行顯示次事務處於活躍狀態已經188s,可能的全部狀態有not started,active,prepared和committed in memory,一旦事務日誌落盤了就會變成not started狀態。在時間後面會顯示出當前事務正在作什麼(在這裏爲空沒有顯示出來),在源代碼中有超過30個字符串常量能夠顯示在時間後面,如:fetching,preparing,rows,adding foreign keys等等
mysql tables in use 1, locked 0
#該事務用到的表數和涉及表鎖的表數,Innodb通常不會鎖定表,但對有些語句會鎖定,若是mysql服務器在高於innodb層之上將表鎖定,這裏也是可以顯示出來的,若是事務已經鎖定了幾行數據,這裏將會有一行信息顯示出鎖定結構的數目(注意,這跟行鎖是兩回事)和和堆大小,如:2 lock struct(s), heap size 376, 1 row lock(s), undo log entries 1,堆的大小指的是爲了持有這些行鎖而佔用的內存大小,Innodb是用一種特殊的位圖表來實現行鎖的,從理論上講,它可將每個鎖定的行表示爲一個比特,經測試顯示,每一個鎖一般不超過4比特。
MySQL thread id 26208154, OS thread handle 0x7fec7c235700, query id 5274800671 10.143.90.228 root Sending data
#與show processlist輸出結果大部分相同
SELECT /*!40001 SQL_NO_CACHE */ * FROM `m_flowskillpoint`
#若是事務正在運行一個查詢,那麼這裏就會顯示事務涉及的SQL,注意:有些版本可能只顯示其中一小段,而不是完整的SQL
Trx read view will not see trx with id >= 4E0110E8, sees < 4E0108EE
#這行顯示了事務的讀視圖,它代表了由於版本關係而產生的對於事務可見和不可見兩種類型的事務ID的範圍,在這裏,兩個數字之間有一個事務的間隙,這個間隙裏的事務多是不可見的,innodb在執行查詢時,對於那些事務ID正好在這個間隙的行,還會檢查其可見性。
注:若是事務正在等待一個鎖,那麼在查詢SQL文本後面將能夠看到這個鎖的信息,在上文的死鎖例子裏,這樣的信息看到過不少了,不幸的是,輸出信息並無說出這個鎖正被其餘哪一個事務持有,不過能夠經過information_schema庫下的innodb_trx,innodb_lock_waits,innodb_locks三個表來查明這一點。若是輸出信息裏有不少個事務,innodb可能會限制要打印出來的事務數目,以避免輸出信息增加得太大,這時就會看到...truncated...提示。
7.FILE I/O部分顯示的是I/O輔助線程的狀態,還有性能計數器的狀態,以下:
--------
FILE I/O
--------
I/O thread 0 state: waiting for i/o request (insert buffer thread)
#insert buffer thread
I/O thread 1 state: waiting for i/o request (log thread)
#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: doing file i/o (read thread) ev set
#以上爲默認的4個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)
#以上爲默認的4個write thread
Pending normal aio reads: 128 [0, 0, 0, 128] , aio writes: 0 [0, 0, 0, 0] ,
#讀線程和寫線程掛起操做的數目等,aio的意思是異步I/O
ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
#insert buffer thread掛起的fsync()操做數目等
Pending flushes (fsync) log: 0; buffer pool: 0
#log thread掛起的fsync()操做數目等
146246831 OS file reads, 760501349 OS file writes, 247143684 OS fsyncs
#這行顯示了讀,寫和fsync()調用執行的數目,在你的機器環境負載下這些絕對值可能會有所不一樣,所以更重要的是監控它們過去一段時間內是如何改變的。
1 pending preads, 0 pending pwrites
#這行顯示了當前被掛起的讀和寫操做數
145.49 reads/s, 783677 avg bytes/read, 28.75 writes/s, 10.67 fsyncs/s
#這行顯示了在頭部顯示的時間(指的是第1部分的時間)段內的每秒平均值。
注:三行掛起讀寫線程、緩衝池線程、日誌線程的統計信息的值是檢測I/O受限的應用的一個好方法,若是這些I/O大部分有掛起操做,那麼負載可能I/O受限。在linux系統下使用參數:innodb_read_io_threads和innodb_write_io_threads兩個變量來配置讀寫線程的數量,默認爲各4個線程。
insert buffer thread:負責插入緩衝合併,如:記錄被從插入緩衝合併到表空間中
log thread:負責異步刷事務日誌
read thread:執行預讀操做以嘗試預先讀取innodb預感須要的數據
write thread:刷新髒頁緩衝
8.這部分顯示了insert buffer和adaptive hash index兩個部分的結構的狀態
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 12, free list len 27559, seg size 27572, 18074934 merges
#這行顯示了關於size(size 12表明了已經合併記錄頁的數量)、free list(表明了插入緩衝中空閒列表長度)和seg size大小(seg size 27572顯示了當前insert buffer的長度,大小爲27572*16K=440M左右)的信息。18074934 merges表明合併插入的次數
merged operations:
#這個標籤
下的一行信息insert,delete mark,delete分別表示merge操做合併了多少個insert buffer,delete buffer,purge buffer
insert 81340470, delete mark 8893610, delete 818579
discarded operations:
#這個標籤下的一行信息表示當change buffer發生merge時表已經被刪除了,就不須要再將記錄合併到輔助索引中了
insert 0, delete mark 0, delete 0
Hash table size 87709057, node heap has 10228 buffer(s)
#這行顯示了自使用哈希索引的狀態,其中,Hash table size 87709057表示AHI的大小,node heap has 10228 buffer(s)表示AHI的使用狀況
1741.05 hash searches/s, 539.48 non-hash searches/s
#這行顯示了在頭部第1部分說起的時間內Innodb每秒完成了多少哈希索引操做,1741.05 hash searches/s表示每秒使用AHI搜索的狀況,539.48 non-hash searches/s表示每秒沒有使用AHI搜索的狀況(由於哈希索引只能用於等值查詢,而範圍查詢,模糊查詢是不能使用哈希索引的。),經過hash searches: non-hash searches的比例大概能夠了解使用哈希索引後的效率,哈希索引查找與非哈希索引查找的比例僅供參考,自適應哈希索引沒法配置,可是能夠經過innodb_adaptive_hash_index=ON|OFF參數來選擇是否須要這個特性。
innodb從1.0.x開始引入change buffer,能夠視爲insert buffer的升級,從這個版本開始,innodb能夠對DML操做(insert,delete,update)都進行緩衝,他們分別是insert buffer,delete buffer,purge buffer,固然和以前insert buffer同樣,change buffer適用對象仍然是非惟一索引的輔助索引,由於沒有update buffer,因此對一條記錄進行update的操做能夠分爲兩個過程:
A:將記錄標記爲刪除
B:真正將記錄刪除
所以,
delete buffer對應update 操做的第一個過程,即將記錄標記爲刪除,purge buffer對應update的第二個過程,即將記錄真正地刪除
9.這部分顯示了關於innodb事務日誌(重作日誌)子系統的統計:
---
LOG
---
Log sequence number 1351392990515
#這行顯示了當前最新數據產生的日誌序列號
Log flushed up to 1351392989504
#這行顯示了日誌已經刷新到哪一個位置了(已經落盤到事務日誌中的日誌序列號)
Last checkpoint at 1351373900020
#這行顯示了上一次檢查點的位置(一個檢查點表示一個數據和日誌文件都處於一致狀態的時刻,而且能用於恢復數據),若是上一次檢查點落後與上一行太多,而且差別接近於事務日誌文件的大小,Innodb會觸發「瘋狂刷」,這對性能而言很是糟糕。
0 pending log writes, 0 pending chkp writes
#這行顯示了當前掛起的日誌讀寫操做,能夠將這行的值與第7部分FILE I/O對應的值作比較,以瞭解你的I/O有多少是因爲日誌系統引發的。
286879989 log i/o's done, 15.92 log i/o's/second
#這行顯示了日誌操做的統計和每秒日誌I/O數,能夠將這行的值與第7部分FILE I/O對應的值作比較,以瞭解你的I/O有多少是因爲日誌系統引發的。
9.這部分顯示了關於innodb緩衝池及其如何使用內存的統計:
9.1.
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 45357793280; in additional pool allocated 0
#這行顯示了由innodb分配的總內存,以及其中多少是額外內存池分配,額外內存池僅分配了其中很小一部份內存,由內部內存分配器分配,如今的innodb版本通常使用操做系統的內存分配器,但老版本使用本身的,這是因爲在那個時代有些操做系統並未提供一個很是好的內存分配實現。
Dictionary memory allocated 12681573
Buffer pool size 2705015
#從這行開始的下面4行顯示緩衝池度量值,以頁爲單位,度量值有總的緩衝池大小,空閒頁數,分配用來存儲數據庫頁的頁數,以及髒數據庫頁數。這行顯示了緩衝池總共有多少個頁,即即2705015*16K,共有43G的緩衝池
Free buffers 5
#這行顯示了緩衝池空閒頁數
Database pages 2694782
#這行顯示了分配用來存儲數據庫頁的頁數,即,表示LRU列表中頁的數量,包含young sublist和old sublist
Old database pages 994651
#這行顯示了LRU中的old sublist部分頁的數量
Modified db pages 10610
#這行顯示髒數據庫頁數
Pending reads 128
#這行顯示了掛起讀的數量
Pending writes: LRU 0, flush list 0, single page 0
#這行顯示了掛起寫的數量
#注意,這裏掛起的讀和寫操做並不與FILE I/O部分的值匹配,由於Innodb可能合併許多的邏輯讀寫操做到一個物理I/O操做中,LRU表明最近使用到的被掛起數量,它是經過沖刷緩衝中不常用的頁來釋放空間以供給常用的頁的一種方法,沖刷列表flush list存放着檢查點處理須要沖刷的舊頁被掛起的數量,單頁single page被掛起的數量(single page寫是獨立的頁面寫,不會被合併)。
Pages made young 3014373561, not young 0
#這行顯示了LRU列表中頁移動到LRU首部的次數,由於該服務器在運行階段改變沒有達到innodb_old_blocks_time閥值的值,所以not young爲0
6960.42 youngs/s, 0.00 non-youngs/s
#表示每秒
young和non-youngs這兩類操做的次數
Pages read 2946570833, created 43450158, written 574214278
#這行顯示了innodb被讀取,建立,寫入了多少頁,讀/寫頁的值是指的從磁盤讀到緩衝池的數據,或者從緩衝池寫到磁盤中的數據,建立頁指的是innodb在緩衝池中分配但沒有從數據文件中讀取內容的頁,由於它並不關心內容是什麼(如,它們可能屬於一個已經被刪除的表)
6960.54 reads/s, 4.42 creates/s, 9.33 writes/s
#這行顯示了對應上面一行的每秒read,create,write的頁數
Buffer pool hit rate 955 / 1000, young-making rate 45 / 1000 not 0 / 1000
#這行顯示了緩衝池的命中率,它用來衡量innodb在緩衝池中查找到所需頁的比例,它度量自上次Innodb狀態輸出後到本次輸出這段時間內的命中率,所以,若是服務器自那之後一直很安靜,你將會看到No buffer pool page gets since the last printout。它對於度量緩存池的大小並無用處。
Pages read ahead 6928.54/s, evicted without access 8.21/s, Random read ahead 0.00/s
#這行顯示了頁面預讀,隨機預讀的每秒頁數
LRU len: 2694782, unzip_LRU len: 0
#innodb1.0.x開始支持壓縮頁的功能,將原來16K的頁壓縮爲1K,2K,4K,8K,而因爲頁的大小發生了變化,LRU列表也有了些改變,對於非16K的頁,是經過unzip_LRU列表進行管理的,能夠看到unzip_LRU len爲0表示沒有使用壓縮頁.
I/O sum[60790]:cur[30], unzip sum[0]:cur[0]
對於壓縮頁的表,每一個表的壓縮比例可能不一樣,可能存在有的表頁大小爲8K,有的表頁大小爲2K的狀況,unzip_LRUs 怎樣從緩存池中分配內存的呢?
首先,在unzip_LRU列表中對不一樣壓縮頁大小的頁進行分別管理,其次,經過夥伴算法進行內存的分配,例如:須要從緩存池中申請頁爲4K的大小,其過程以下:
a:檢查4K的unzip_LRU列表,檢查是否有可用的空閒頁
b:如有,則直接使用
c:若沒有,檢查8K的unzip_LRU列表
d:若可以獲得空閒頁,將頁分紅2個4K的頁,存放到4K的unzip_LRU列表
e:若不能獲得空閒頁,從LRU列表中申請一個16K的頁,將頁分紅1個8K,2個4K的頁,分別存放到各自大小對應的unzip_LRU列表中。
注:可能出現Free buffers和Database pages之和不等於Buffer pool size,由於緩衝池中的頁肯會被分配給自適應哈希索引,lock信息,insert buffer等,而這部分頁不須要LRU算法進行維護,所以不在LRU列表中。
9.2.若是innodb buffer pool使用參數innodb
_buffer_pool_instances=num設置了大於1個緩衝池實例,那麼就會按照這個參數把innodb_buffer_pool_size=xxx平分爲num份。每份的信息顯示相似以下,這部分的內容和9.1小節內容相似,就再也不多說。
----------------------
INDIVIDUAL BUFFER POOL INFO
----------------------
---BUFFER POOL 0
Buffer pool size 541003
Free buffers 1
Database pages 538965
Old database pages 198933
Modified db pages 2190
Pending reads 128
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 603372180, not young 0
1441.81 youngs/s, 0.00 non-youngs/s
Pages read 589705199, created 8703138, written 116954697
1441.61 reads/s, 0.75 creates/s, 1.83 writes/s
Buffer pool hit rate 955 / 1000, young-making rate 45 / 1000 not 0 / 1000
Pages read ahead 1436.98/s, evicted without access 0.87/s, Random read ahead 0.00/s
LRU len: 538965, unzip_LRU len: 0
I/O sum[12158]:cur[6], unzip sum[0]:cur[0]
---BUFFER POOL 1
Buffer pool size 541003
Free buffers 1
Database pages 538959
Old database pages 198931
Modified db pages 2025
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 602366394, not young 0
1481.35 youngs/s, 0.00 non-youngs/s
Pages read 588738997, created 8708171, written 113209540
1480.56 reads/s, 0.83 creates/s, 1.92 writes/s
Buffer pool hit rate 958 / 1000, young-making rate 42 / 1000 not 0 / 1000
Pages read ahead 1473.73/s, evicted without access 1.96/s, Random read ahead 0.00/s
LRU len: 538959, unzip_LRU len: 0
I/O sum[12158]:cur[6], unzip sum[0]:cur[0]
10.這部分顯示了其餘各項的innodb統計:
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
#這行顯示了innodb內核內有多少個線程,隊列中有多少個線程,隊列中的查詢是innodb爲限制併發執行的線程數量而不運行進入內核的線程。查詢在進入隊列以前會休眠等待。
5 read views open inside InnoDB
#這行顯示了有多少打開的innodb讀視圖,讀視圖是包含事務開始點的數據庫內容的MVCC快照,你能夠看看某特定事務在第6部分TRANSACTIONS是否有讀視圖
Main thread process no. 4368, id 140653691242240, state: sleeping
#這行顯示了內核的主線程狀態
Number of rows inserted 3429012215, updated 153529675, deleted 112310240, read 3739562987410
#這行顯示了多少行被插入,更新和刪除,讀取
428.52 inserts/s, 7.21 updates/s, 0.46 deletes/s, 1047933.92 reads/s
#這行顯示了對應上面一行的每秒平均值,若是想查看innodb有多少工做量在進行,那麼這兩行是很好的參考值
----------------------------
END OF INNODB MONITOR OUTPUT
#要注意了,若是看不到這行輸出,多是有大量事務或者是有一個大的死鎖截斷了輸出信息
============================
注:內核的主線程狀態可能的狀態值有以下一些:
A:doing background drop tables
B:doing insert buffer merge
C:flushing buffer pool pages
D:making checkpoint
E:purging
F:reserving kernel mutex
G:sleeping
H:suspending
I:waiting for buffer pool flush to end
J:waiting for server activity