SHOWENGINE INNODB STATUS詳細介紹

時間 2020-07-17

標籤 showengine innodb status 詳細介紹欄目 MySQL 简体版

原文原文鏈接

SHOWENGINE INNODB STATUS詳細介紹html

不少人用過SHOW ENGINE INNODB STATUS來查看服務器信息以及定位問題，但它的輸出內容比較複雜難懂。而網上也基本沒有這方面的介紹材料– 特別是中文資料。node

本文接下來詳細介紹這些信息的含義，也包含一些信息產生的來龍去脈。但願能對你有所幫助，也但願各位看客對於文中的錯誤加以指正。mysql

Header

這部分簡單的打印，輸出的時間，以及自從上次輸出的間隔時間。sql

1 =====================================數據庫

2 07091310:31:48 INNODB MONITOR OUTPUT服務器

3 =====================================併發

4 Persecond averages calculated from the last 49 secondsapp

SEMAPHORES

若是你有一個高併發的系統，你須要關注這一部分的輸出。異步

它由兩部分組成，event counters, 和可選項輸出,即當前等待的事件(current waits)。async

下面給出了一個示例輸出。

1 ----------

2 SEMAPHORES

3 ----------

4 OSWAIT ARRAY INFO: reservation count 13569, signal count 11421

5 --Thread1152170336 has waited at ./../include/buf0buf.ic line 630 for 0.00 seconds

the semaphore:

6 Mutexat 0x2a957858b8 created file buf0buf.c line 517, lock var 0

7 waitersflag 0

8 waitis ending

9 --Thread1147709792 has waited at ./../include/buf0buf.ic line 630 for 0.00 seconds

the semaphore:

10 Mutexat 0x2a957858b8 created file buf0buf.c line 517, lock var 0

11 waitersflag 0

12 waitis ending

13 Mutexspin waits 5672442, rounds 3899888, OS waits 4719

14 RW-sharedspins 5920, OS waits 2918; RW-excl spins 3463, OS waits 3163

第4行表示，OS WAIT的信息，reservation count表示Innodb產生了多少次OS WAIT, signal count表示，進行OS WAIT的線程，接收到多少次信號（singal）被喚醒。

若是你看到signal的數值很大，一般是幾十萬，上百萬。就代表，多是不少I/O的等待，或是Innodb爭用(contention)問題。關於爭用問題，可能與OS的進程調度有關，你可嘗試減小innodb_thread_concurrency參數。

在接下來，下面的介紹以前，有必要明白什麼是OS Wait,什麼是spin wait。

要明白這個，首先你要明白Innodb如何處理互斥量(Mutexes)，以及什麼是兩步得到鎖(two-step approach)。首先進程，試圖得到一個鎖，若是此鎖被它人佔用。它就會執行所謂的spin wait,即所謂循環的查詢」鎖被釋放了嗎？」。若是在循環過程當中，一直未獲得鎖釋放的信息，則其轉入OS WAIT，即所謂線程進入掛起(suspended)狀態。直到鎖被釋放後，經過信號(singal)喚醒線程。

Mutex spin waits 是線程沒法獲取鎖，而進入的spin wait
rounds 是spin wait進行輪詢檢查Mutextes的次數
OS waits 是線程放棄spin-wait進入掛起狀態

Spin wait的消耗遠小於OS waits。Spinwait利用cpu的空閒時間，檢查鎖的狀態，OS Wait會有所謂content switch，從CPU內核中換出當前執行線程以供其它線程使用。你能夠經過innodb_sync_spin_loops參數來平衡spin wait和os wait。

http://dev.mysql.com/doc/refman/5.6/en/innodb-parameters.html#sysvar_innodb_sync_spin_loops

5-12行，顯示的是具體爭用（contention）等待的事件，這個要求你對於MySQL的代碼比較熟悉。

如示例，buf0buf.c實際上表示服務器有buffer pool爭用的狀況。

13-14顯示了更詳細的鎖（Mutexes）的信息，如RW-shared表示共享鎖，RW-excl表示排它鎖

LATEST DETECTED DEADLOCK

當你服務器發生了死鎖的狀況時，這部分會顯示出來。死鎖一般的緣由很複雜，可是這一部分只會顯示最後兩個發生死鎖的事務，儘管可能也有其它事務也包含在死鎖過程當中。不過，儘管信息被刪減了，一般你也可以經過這些信息找出死鎖的緣由。

下面給出了一個例子：

1 ------------------------

2 LATESTDETECTED DEADLOCK

3 ------------------------

4 07091311:14:21

5 ***(1) TRANSACTION:

6 TRANSACTION0 3793488, ACTIVE 2 sec, process no 5488, OS thread id 1141287232

startingindex read

7 mysqltables in use 1, locked 1

8 LOCKWAIT 4 lock struct(s), heap size 1216

9 MySQLthread id 11, query id 350 localhost baron Updating

10 UPDATEtest.tiny_dl SET a = 0 WHERE a <> 0

11 ***(1) WAITING FOR THIS LOCK TO BE GRANTED:

12 RECORDLOCKS space id 0 page no 3662 n bits 72 index `GEN_CLUST_INDEX` of table

`test/tiny_dl`trx id 0 3793488 lock_mode X waiting

13 Recordlock, heap no 2 PHYSICAL RECORD: n_fields 4; compact format; info bits 0

14 0:len 6; hex 000000000501 ...[ omitted ] ...

16 ***(2) TRANSACTION:

17 TRANSACTION0 3793489, ACTIVE 2 sec, process no 5488, OS thread id 1141422400

startingindex read, thread declared inside InnoDB 500

18 mysqltables in use 1, locked 1

19 4lock struct(s), heap size 1216

20 MySQLthread id 12, query id 351 localhost baron Updating

21 UPDATEtest.tiny_dl SET a = 1 WHERE a <> 1

22 ***(2) HOLDS THE LOCK(S):

23 RECORDLOCKS space id 0 page no 3662 n bits 72 index `GEN_CLUST_INDEX` of table

`test/tiny_dl`trx id 0 3793489 lock mode S

24 Recordlock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0

25 0:... [ omitted ] ...

27 ***(2) WAITING FOR THIS LOCK TO BE GRANTED:

SHOW INNODB STATUS | 571

28 RECORDLOCKS space id 0 page no 3662 n bits 72 index `GEN_CLUST_INDEX` of table

`test/tiny_dl`trx id 0 3793489 lock_mode X waiting

29 Recordlock, heap no 2 PHYSICAL RECORD: n_fields 4; compact format; info bits 0

30 0:len 6; hex 000000000501 ...[ omitted ] ...

32 *** WE ROLL BACK TRANSACTION (2)

第4行顯示了死鎖發生的時間。第5-10行，顯示了第一個死鎖的第一個事務，下一節我會繼續詳細說明它的意思。

11-15行顯示了死鎖發生時事務1等待的鎖。14行，能夠忽略，顯示的信息只有在調試Innodb時有用。重要的是12行，它說明了事務想得到test.tiny_dl 表的GEN_CLUST_INDEX* 索引對應的X 排它鎖（有必要說明一下，Innodb的鎖是與索引相關的，具體能夠看個人博客關於Innodb鎖的介紹）。

16-21行顯示了事務2的狀態，22-26顯示了事務2得到的鎖，27-31顯示了事務2等待的鎖。

Innodb不會顯示當前事務全部得到的，以及等待的鎖，但它給予了足夠的信息，如當前查詢使用的索引，它會幫助你定位問題以及如何避免死鎖。固然，這類信息一般不是那麼的直觀，你能夠經過打印出了SQL語句，以及索引等信息，找到問題代碼，進行分析。

32行，顯示了它選擇哪個事務回滾，以免無限期的死鎖等待。關於這點，Innodb有一個內在的死鎖檢測機制，當死鎖等待超過必定時間後，就會回滾其中一個事務。innodb_lock_wait_timeout可配置死鎖的等待超時時間。

TRANSACTIONS

這一部分包含Innodb 事務（transactions）的統計信息，還有當前活動的事務列表。

接下來，先介紹開始的統計部分

1 ------------

2 TRANSACTIONS

3 ------------

4 Trx id counter 080157601

5 Purge done fortrx's n:o <0 80154573 undo n:o <0 0

6 History listlength 6

7 Total number oflock structs in row lock hash table 0

第4行顯示的是當前的transaction id, 這個ID是一個系統變量隨時每次新的transaction產生而增長。

第5行顯示的正在進行清空（purge）操做的transaction ID。你能夠經過查看第4和第5行ID的區別，明白沒有被purge的事務落後的狀況。關於什麼是purge操做，我在下面進行了詳細說明。

第6行，記錄了undo spaces內unpurged的事務的個數。

（注：有心人也許會計算4,5行ID之差，與第6行的這個數值比較，可能會發現徹底不匹配。這點我也困惑了一段時間。實際上是這樣，事務的ID並非按順序purge的，因此有可能ID大於第5行當前purge的ID的事務，已經在前面被purge了。Purge的原則就是記錄沒有被其它事務繼續使用了。）

第7行，英文的原文解釋以下，這個我沒弄明白。the number of lock structs. Each lock struct usually holds many row locks,so this is not the same as the number of rows locked.

什麼是purge操做

要明白什麼清空（purge）操做，你得明白什麼是事務的多版本控制，即MVCC(multi-version concurrency control)。Innodb爲了實現MVCC，須要在表空間內保存老版本的記錄信息，這些信息存儲於回滾段中（rollback segment），所謂回滾段，在物理存儲上是UNDO log的記錄。

Purge到底作了些什麼？其實它就至關於一個垃圾收集器。取個例子，當用戶下一個命令，如「DELETE FROM t WHERE c = 1;」, InnoDB 不會立刻刪除對應的記錄，它會作以下三件事情:

它標記此記錄爲刪除（經過刪除標記位）
存儲原始的記錄到UNDO log
更新記錄列DB_TRX_ID和DB_ROLL_PTR（這些列是Innodb在原記錄列上增長的）。DB_TRX_ID記錄了最後操做記錄的事務ID。DB_ROLL_PTR也叫回滾指針(rollback pointer)，指向UNDO log 記錄，此UNDO Log記錄了原始記錄的信息，這些信息能夠用來重建原始記錄（如發生了rollback的狀況）。若是操做是插入，還會有一個DB_ROW_ID，這個指明瞭新記錄的行號.

當事務提交後，那些標記了刪除的記錄，以及UNDOLog中的記錄並不會立刻清除，這些記錄信息能夠被其它事務所重用，或是共享。只有當沒有任何事務共享這些記錄的時候，這些記錄纔會被清除（purge）。這就是所謂purge操做。而爲了提升數據庫的操做效率，purge操做是由另外的線程異步完成。這就是爲什麼前面你所看到的爲什麼存在unpurged的事務的緣由。

接下來，是事務的列表，以下有一個例子。

1 ---TRANSACTION0 80157600, ACTIVE 4 sec, process no 3396, OS thread id 1148250464,

thread declared inside InnoDB 442

2 mysqltables in use 1, locked 0

3 MySQLthread id 8079, query id 728899 localhost baron Sending data

4 selectsql_calc_found_rows * from b limit 5

5 Trxread view will not see trx with id>= 0 80157601, sees <0 80157597

第 1 行顯示了事務ID。ACTIVE 4 sec表示事務處於ACTIVE狀態已經4秒鐘了。其它可能的狀態還包括「not started,」「active,」「prepared,」 and 「committedin memory」(once it commits to disk, the state willchange to 「not started」)

「threaddeclared inside InnoDB 442」表示，這個thread處於Innodb內核，還有422個tickets可使用。有一個參數，innodb_concurrency_tickets能夠配置一個thread可用的tickets數。

何謂tickets數呢？當Innodb內部線程達到innodb_thread_concurrency上限時，新的thread就須要在thread隊列內排隊等待進行Innodb內核執行。Thread tickets可讓已經進行Innodb內核的線程，能夠執行屢次（即屢次執行一個時間片週期），這個次數由tickets來決定。直到用完tickets，此線程纔會換出內核進入隊列。這樣作的用處是避免所謂threadthrashing問題，避免線程不停的從內核中換入換出。

一個常見的例子是，若是你有執行時間長的SQL語句在指定tickets內還沒法完成，這樣就會被換出內核。如此增長的thread的context switch的開銷是驚人的。在這種狀況下，可考慮增大tickets的值。

第2行，顯示了當前事務鎖定的數據表

第3行顯示了thread id,這個值與是在show full processlist 命令顯示的進程ID是同樣的。

第4行顯示了當前事務執行的SQL語句。

第5行，顯示了MVCC,多版本併發控制的信息，代表了哪些其它事務能夠看到此記錄，哪些不能。

FILE I/O

FILE I/O部分顯示了I/O Helper thread的狀態，包括一些統計信息

1 --------

2 FILEI/O

3 --------

4 I/Othread 0 state: waiting for i/o request (insert buffer thread)

5 I/Othread 1 state: waiting for i/o request (log thread)

6 I/Othread 2 state: waiting for i/o request (read thread)

7 I/Othread 3 state: waiting for i/o request (write thread)

8 Pendingnormal aio reads: 0, aio writes: 0,

9 ibufaio reads: 0, log i/o's: 0, sync i/o's: 0

10 Pendingflushes (fsync) log: 0; buffer pool: 0

11 17909940OS file reads, 22088963 OS file writes, 1743764 OS fsyncs

12 0.20 reads/s, 16384 avg bytes/read, 5.00 writes/s, 0.80fsyncs/s

4-7行顯示了I/O helper thread 的狀態.

8-10行顯示了各個I/O helper thread的pending operations, pending的log和buffer pool thread的fsync()調用。關於什麼是fsync()調用，以及爲什麼有fsync調用，我會專門再拿出一章來講明。請你們等待個人博客後繼更新。

11行顯示了reads, writes, and fsync()調用次數。

12行顯示了每秒的統計信息

第8-9行能夠用來檢測I/O-bound問題，若是出現不少pending operations，頗有可能你的服務器出現了I/O-bound問題。其中縮略詞「aio」表示「異步I/O(asynchronous I/O).」

INSERT BUFFER AND ADAPTIVE HASHINDEX

1 -------------------------------------

2 INSERTBUFFER AND ADAPTIVE HASH INDEX

3 -------------------------------------

4 Ibuffor space 0: size 1, free list len 887, seg size 889, is not empty

5 Ibuffor space 0: size 1, free list len 887, seg size 889,

6 2431891inserts, 2672643 merged recs, 1059730 merges

7 Hashtable size 8850487, used cells 2381348, node heap has 4091 buffer(s)

8 2208.17 hash searches/s, 175.05 non-hash searches/s

第4行顯示了insertbuffer的一些信息，包括free list, segment size

其中space 0，表示可能有多個insert buffer, 如space 0, space 1等。但實際上MySQL並無多個insert buffer,因此你能看到4,5行是重複的。這算是一個多餘的輸出。在新版本中，去除了此輸出。

第6行顯示了Innodb進行了多少次buffer操做。經過比較 inserts和 merges，能夠看出insert buffer的效率

第7行顯示了hash table的一些信息

第8行顯示了每秒進行了多少次hash搜索，以及非hash搜索

LOG

這裏記錄了tansaction log子系統的信息（若是你不記得了，請看FILE I/O那一節所看到的I/O Helper Thread）

1 ---

2 LOG

3 ---

4 Logsequence number 84 3000620880

5 Logflushed up to 84 3000611265

6 Lastcheckpoint at 84 2939889199

7 0pending log writes, 0 pending chkp writes

8 14073669 log i/o's done, 10.90 log i/o's/second

第4行，顯示了當前的log sequencenumber。Log sequence number表示有多少字節寫入到了log文件內

第5行，顯示了已經被flushed(寫入磁盤)的logs

第6行，顯示了最後一個checkpoint的logs

第7，8行，顯示了pending log 的統計信息

BUFFER POOL AND MEMORY

1 ----------------------

2 BUFFERPOOL AND MEMORY

3 ----------------------

4 Totalmemory allocated 4648979546; in additional pool allocated 16773888

5 Bufferpool size 262144

6 Freebuffers 0

7 Databasepages 258053

8 Modifieddb pages 37491

9 Pendingreads 0

10 Pendingwrites: LRU 0, flush list 0, single page 0

11 Pagesread 57973114, created 251137, written 10761167

12 9.79reads/s, 0.31 creates/s, 6.00 writes/s

13 Buffer pool hit rate 999 / 1000

第4行顯示了分配給Innodb的內存大小，以及additional pool使用的大小（若是沒有使用，會顯示爲0）

第5-8行顯示了buffer pool的信息。分別顯示了Buffer pool大小，空閒的buffers, database pages, 髒頁(dirty pages)。你會看到buffer pool size比database pages要大，這是由於buffer pool還會存放lock index, hash index等一些其它的系統信息。