show engine innodb status 詳解

很多人讓我來闡述一下 SHOW INNODB STATUS 的輸出資訊, 瞭解 SHOW INNODB STATUS 都輸出了些什麼資訊，並且我們能從這些資訊中獲取什麼資訊，得以提高 MySQL 效能。

首先，讓我們來了解一下 SHOW INNODB STATUS 輸出的基礎，它列印了很多關於 InnoDB 內部效能相關的計數器、統計、事務處理資訊等。在 MySQL 5 中，InnoDB 的效能統計結果也在 SHOW STATUS 結果中顯示了。大部分和 SHOW INNODB STATUS 的其他資訊相同，在舊版本中還沒有這個功能。

SHOW INNODB STATUS 中的很多統計值都是每秒更新一次的，如果你打算利用這些統計值的話，那麼最好統計一段時間內的結果。InnoDB 首先輸出以下資訊：

1.=====================================

2.060717  3:07:56 INNODB MONITOR OUTPUT

3.=====================================

4.Per second averages calculated from the last 44 seconds

首先要確認這是至少統計了 20-30 秒的樣本資料。如果平均統計間隔是0或1秒，那麼結果就沒什麼意義了。
說實在的我不喜歡InnoDB提供的平均值，因為很難取得合理的平均間隔統計值，如果你是寫指令碼來取得 SHOW INNODB STATUS 結果的話，那麼最好取得全域性的統計結果，然後取得平均值。當然了，直接檢視輸出的結果資訊也是很有用的。

下一部分顯示了訊號(Semaphores)相關資訊：

1.----------

2.SEMAPHORES

3.----------

4.OS WAIT ARRAY INFO: reservation count 13569, signal count 11421

5.--Thread 1152170336 has waited at ./../include/buf0buf.ic line 630 for 0.00 seconds the semaphore:

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

7.waiters flag 0

8.wait is ending

9.--Thread 1147709792 has waited at ./../include/buf0buf.ic line 630 for 0.00 seconds the semaphore:

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

11.waiters flag 0

12.wait is ending

13.Mutex spin waits 5672442, rounds 3899888, OS waits 4719

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

這段可以分成2個部分。一部分是當前的等待，這部分只是包含了在高併發環境下的全部記錄，因此 InnoDB 會頻繁回退到系統等待。如果等待是透過自旋鎖來解決的話，那麼這些資訊就就不會顯示了。

透過這部分資訊，你就會知道系統負載的熱點在哪了。不過這需要了解一下原始碼相關的知識 - 從上面的資訊中就可以看出來是哪個原始碼檔案中的哪行(不同的版本結果可能不同)，只是從這裡卻看不出來任何資訊。儘管如此，還是可以從檔名中猜到一些東 西 - 比如本例中，檔名 "buf0buf.ic" 預示著和一些緩衝池爭奪有關係。如果想了解更多，就去看原始碼吧。

還有一些關於等待的更多細節。"lock var" 表示當前的 mutex 物件的值(被鎖住 = 1 / 釋放 = 0) 值，"waiters flag" 表示當前的等待個數。另外，本例中還可以看到等待狀態資訊 "wait is ending"，這表示 mutex 已經釋放，但是系統排程執行緒還正在處理。

第二塊是事件統計 - "reservation count" 和 "signal count" 顯示了 innodb 使用內部同步陣列的活躍程度 - 時間片(slot)分配以及執行緒訊號使用同步陣列的頻繁程度。這些統計資訊可以用於表示 innodb 回退到系統等待的頻率。還有關於系統等待的直接相關資訊，可以看到"OS Waits"的互斥訊號燈(mutexes)，以及讀寫鎖。這些資訊中顯示了互斥鎖和共享鎖。系統等待和 "保留(reservation)" 不完全一樣，在回退到用 sync_array 的複雜等待模式前，innodb 會嘗試 "輸出(yield)" 到系統，希望下一次排程時間物件裡命名執行緒已經釋放了。系統等待相對較慢，如果每秒發生了上萬次系統等待，則可能會有問題。另一個觀察方法是檢視系統狀態 中的上下文(context)交換頻率。

另一塊重要的資訊是 "spin waits" 和 "spin rounds" 的數量。相較於系統等待，自旋鎖是低成本的等待；不過它是一個活躍的等待，會浪費一些cpu資源。因此如果看到大量的自旋等待和自旋輪轉，則很顯然它浪費 了很多cpu資源。浪費cpu時間和無謂的上下文切換之間可以用 innodb_sync_spin_loops 來平衡。

接下來的這段顯示死鎖狀況:

1.------------------------

2.LATEST DETECTED DEADLOCK

3.------------------------

4.060717  4:16:48

5.*** (1) TRANSACTION:

6.TRANSACTION 0 42313619, ACTIVE 49 sec, process no 10099, OS thread id 3771312 starting index read

7.mysql tables in use 1, locked 1

8.LOCK WAIT 3 lock struct(s), heap size 320

9.MySQL thread id 30898, query id 100626 localhost root Updating

10.update iz set pad='a' where i=2

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

12.RECORD LOCKS space id 0 page no 16403 n bits 72 index `PRIMARY` of table `test/iz` trx id 0 42313619 lock_mode X locks rec but not gap waiting

13.Record lock, heap no 5 PHYSICAL RECORD: n_fields 4; compact format; info bits 0

14. 0: len 4; hex 80000002; asc     ;; 1: len 6; hex 00000285a78f; asc       ;; 2: len 7; hex 00000040150110; asc    @   ;; 3: len 10; hex 61202020202020202020; asc a         ;;

15. 

16.*** (2) TRANSACTION:

17.TRANSACTION 0 42313620, ACTIVE 24 sec, process no 10099, OS thread id 4078512 starting index read, thread declared inside InnoDB 500

18.mysql tables in use 1, locked 1

19.3 lock struct(s), heap size 320

20.MySQL thread id 30899, query id 100627 localhost root Updating

21.update iz set pad='a' where i=1

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

23.RECORD LOCKS space id 0 page no 16403 n bits 72 index `PRIMARY` of table `test/iz` trx id 0 42313620 lock_mode X locks rec but not gap

24.Record lock, heap no 5 PHYSICAL RECORD: n_fields 4; compact format; info bits 0

25. 0: len 4; hex 80000002; asc     ;; 1: len 6; hex 00000285a78f; asc       ;; 2: len 7; hex 00000040150110; asc    @   ;; 3: len 10; hex 61202020202020202020; asc a         ;;

26. 

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

28.RECORD LOCKS space id 0 page no 16403 n bits 72 index `PRIMARY` of table `test/iz` trx id 0 42313620 lock_mode X locks rec but not gap waiting

29.Record lock, heap no 4 PHYSICAL RECORD: n_fields 4; compact format; info bits 0

30. 0: len 4; hex 80000001; asc     ;; 1: len 6; hex 00000285a78e; asc       ;; 2: len 7; hex 000000003411d9; asc     4  ;; 3: len 10; hex 61202020202020202020; asc a         ;;

31. 

32.*** WE ROLL BACK TRANSACTION (2)

這裡顯示了 Innodb 最後檢測到事務引發的死鎖，包括髮生死鎖時的狀態，加了什麼鎖，在等待什麼鎖釋放，以及 Innodb 決定哪個事務會被回滾。注意，innodb只顯示了事務持有鎖的相關簡單資訊。並且只顯示了每個事務最後執行的語句，發生死鎖的記錄就是由於這些語句引起 的。檢視複雜的死鎖資訊還需要檢視日誌檔案，才能找到真正引發衝突的語句。大部分情況下，SHOW INNODB STATUS 顯示的資訊基本足夠了。

下面是關於外來鍵約束引發的死鎖資訊：

1.------------------------

2.LATEST FOREIGN KEY ERROR

3.------------------------

4.060717  4:29:00 Transaction:

5.TRANSACTION 0 336342767, ACTIVE 0 sec, process no 3946, OS thread id 1151088992 inserting, thread declared inside InnoDB 500

6.mysql tables in use 1, locked 1

7.3 lock struct(s), heap size 368, undo log entries 1

8.MySQL thread id 9697561, query id 188161264 localhost root update

9.insert into child values(2,2)

10.Foreign key constraint fails for table `test/child`:

11.,

12.  CONSTRAINT `child_ibfk_1` FOREIGN KEY (`parent_id`) REFERENCES `parent` (`id`) ON DELETE CASCADE

13.Trying to add in child table, in index `par_ind` tuple:

14.DATA TUPLE: 2 fields;

15. 0: len 4; hex 80000002; asc     ;; 1: len 6; hex 000000000401; asc       ;;

16. 

17.But in parent table `test/parent`, in index `PRIMARY`,

18.the closest match we can find is record:

19.PHYSICAL RECORD: n_fields 3; 1-byte offs TRUE; info bits 0

20. 0: len 4; hex 80000001; asc     ;; 1: len 6; hex 0000140c2d8f; asc     - ;; 2: len 7; hex 80009c40050084; asc    @   ;;

Innodb會顯示引發錯誤的語句。外來鍵約束定義失敗，以及定義關係最密切的父表。有很多嵌接資訊都是用16進製表示，不過對於問題診斷並不是太重 要，它們主要用於給 Innodb 的開發者來檢視或者用於除錯目的。

接下來是顯示 Innodb 當前活躍的事務：

1.------------

2.TRANSACTIONS

3.------------

4.Trx id counter 0 80157601

5.Purge done for trx's n:o <0 80154573 undo n:o <0 0

6.History list length 6

7.Total number of lock structs in row lock hash table 0

8.LIST OF TRANSACTIONS FOR EACH SESSION:

9.---TRANSACTION 0 0, not started, process no 3396, OS thread id 1152440672

10.MySQL thread id 8080, query id 728900 localhost root

11.show innodb status

12.---TRANSACTION 0 80157600, ACTIVE 4 sec, process no 3396, OS thread id 1148250464, thread declared inside InnoDB 442

13.mysql tables in use 1, locked 0

14.MySQL thread id 8079, query id 728899 localhost root Sending data

15.select sql_calc_found_rows  * from b limit 5

16.Trx read view will not see trx with id>= 0 80157601, sees <0 80157597

17.---TRANSACTION 0 80157599, ACTIVE 5 sec, process no 3396, OS thread id 1150142816 fetching rows, thread declared inside InnoDB 166

18.mysql tables in use 1, locked 0

19.MySQL thread id 8078, query id 728898 localhost root Sending data

20.select sql_calc_found_rows  * from b limit 5

21.Trx read view will not see trx with id>= 0 80157600, sees <0 80157596

22.---TRANSACTION 0 80157598, ACTIVE 7 sec, process no 3396, OS thread id 1147980128 fetching rows, thread declared inside InnoDB 114

23.mysql tables in use 1, locked 0

24.MySQL thread id 8077, query id 728897 localhost root Sending data

25.select sql_calc_found_rows  * from b limit 5

26.Trx read view will not see trx with id>= 0 80157599, sees <0 80157595

27.---TRANSACTION 0 80157597, ACTIVE 7 sec, process no 3396, OS thread id 1152305504 fetching rows, thread declared inside InnoDB 400

28.mysql tables in use 1, locked 0

29.MySQL thread id 8076, query id 728896 localhost root Sending data

30.select sql_calc_found_rows  * from b limit 5

31.Trx read view will not see trx with id>= 0 80157598, sees <0 80157594

如果當前連線不是很多，則會顯示全部事務列表；如果有大量連線，則 Innodb 只會顯示他們的數量，減少輸出的列表資訊，使得輸出結果不會太多。

事務ID是當前事務的標識，事務的id每次都會增加。Purge done for trx's n:o 是指淨化(purge)執行緒已經完成的事務數。Innodb僅清除那些被當前事務認為不再需要的舊版本資料。那些未提交的舊事務可能會阻塞淨化執行緒並且消 耗資源。透過檢視2次清除事務數之差，就可以知道是否發生了這種情況。少數情況下，淨化執行緒可能難以跟上更新的速度，2次檢視值之差可能會越來越大；那 麼，innodb_max_purge_lag 就派得上用場了。 "undo n:o" 顯示了淨化執行緒當前正在處理的回滾日誌號，如果當前不處於活躍狀態，則它的值是 0。

History list length 6 是指在回滾空間中的未清除事務數。隨著事務的提交，它的值會增加；隨著清除執行緒的執行，它的值會減小。

Total number of lock structs in row lock hash table 是指事務分配過的行鎖結構總數。它和曾經被鎖住過的行總數不一定相等，通常是一個鎖結構對應多行記錄。

MySQL中，每個連線如果沒有活動的事務，則它的狀態是 not started ，如果有活動的事務，則是 ACTIVE 。 注意，儘管事務是活動的，但是其連線的狀態卻可能是 "睡眠(sleep)" - 如果是在一個有多條語句的事務裡的話。Innodb 會同時顯示系統的執行緒號以及程式號，這有助於利用gdb來除錯或者其他類似用途。另外，事務的狀態也會根據當前實際狀態來顯示，例如 "讀取記錄 (fetching rows)" ，em>"更新(updating)"等等。"Thread declared inside InnoDB 400" 的意思是 Innodb 核心正在執行該執行緒，並且還需要400個票。Innodb 會根據 innodb_thread_concurrency 的值來限制同時併發的執行緒數不超過它。如果執行緒當前不在 Innodb 的核心中執行，則它的狀態可能是 "waiting in InnoDB queue" 或 "sleeping before joining InnoDB queue" 。後面這 個狀態有點意思 - Innodb 為了避免有太多的執行緒同時搶著要進入執行佇列，那麼就會嘗試讓這些執行緒進入等待狀態(如果沒有足夠的空閒插槽(slot)的話)。這就可能會導致 Innodb 核心中當前活躍的執行緒數可能比 innodb_thread_concurrency 的值還小。某種負載環境下，這可能有助於減小執行緒進入佇列的時間。可以透過調整 innodb_thread_sleep_delay 來實現，它的單位是微妙。

mysql tables in use 1, locked 0 是指事務中已經用過的資料表個數(已經訪問過了的)，以及被鎖的個數。Innodb 一般情況不會鎖表，因此鎖表數一般是0，除非是 ALTER TABLE 或者其他類似 LOCK TABLES 的語句。

除了Innodb相關的特定資訊外，一些基本資訊可以透過 來檢視，例如正在執行什麼語句，查詢ID號，查詢狀態等。

下面這部分顯示的是跟IO相關的具體資訊：

1.--------

2.FILE I/O

3.--------

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

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

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

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

8.Pending normal aio reads: 0, aio writes: 0,

9. ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0

10.Pending flushes (fsync) log: 0; buffer pool: 0

11.17909940 OS file reads, 22088963 OS file writes, 1743764 OS fsyncs

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

本部分顯示了IO助手執行緒狀態 - 插入緩衝執行緒，日誌執行緒，讀、寫執行緒。它們分別對應插入緩衝合併，非同步日誌重新整理，預讀以及重新整理髒資料。源自查詢的正常讀取是由正在執行的查詢執行的。在 Unix/Linux平臺下，總能看見4個執行緒，在Windows上可以透過 innodb_file_io_threads 來調整。每個執行緒準備好之後都能看到其狀態：waiting for i/o request 或者正在執行特定的操作。

每個執行緒都會顯示正在進行的運算元量 - 同時正要執行或者正在執行的運算元量。另外，正在執行的 fsync 運算元量也會顯示出來。有寫資料時，Innodb需要確保資料最終被寫到磁碟上，只是把它們放在系統快取裡是不夠的。通常是呼叫 fsync() 來完成的。如果它的值一直很高，那意味這Innodb可能是處於IO負載較高狀態。注意，由執行緒執行請求引發的IO請求是不計算在內的，因此儘管系統的 IO負載較高，但是它們的值卻可能為 0。

接下來顯示的是IO操作的平均統計值，它們對於圖形顯示或者監控很有用。
"16384 avg bytes/read" 是讀請求的平均值。隨機IO的話，每個頁的大小是16K，全表掃描或索引掃描時的預讀會導致這個值明顯的增加。因此，它體現了預讀的效率。

1.-------------------------------------

2.INSERT BUFFER AND ADAPTIVE HASH INDEX

3.-------------------------------------

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

5.Ibuf for space 0: size 1, free list len 887, seg size 889,

6.2431891 inserts, 2672643 merged recs, 1059730 merges

7.Hash table size 8850487, used cells 2381348, node heap has 4091 buffer(s)

8.2208.17 hash searches/s, 175.05 non-hash searches/s

本部分顯示了插入緩衝以及自適應雜湊索引的狀態。第一行顯示了插入緩衝的狀態 - 段的大小以及空閒列表，以及緩衝中有多少記錄。接下來顯示了緩衝中已經完成了多少次插入，有多少記錄已經合併，有多少次合併已經完成。合併次數除以插入次 數得到的比率可以反映出插入緩衝的效率如何。

Innodb採用雜湊索引建立記憶體頁索引形成自適應雜湊索引而不是採 B-tree 索引，得以加速行記錄到記憶體頁的檢索。這裡顯示了雜湊表的大小，以及自適應雜湊索引使用了多少單元和緩衝。可以透過計算利用雜湊索引檢索的次數以及沒利用 它檢索的次數來了解雜湊索引的效率。

當前對自適應雜湊索引基本沒有什麼辦法可以調整它，主要還是用於檢視。

1.---

2.LOG

3.---

4.Log sequence number 84 3000620880

5.Log flushed up to   84 3000611265

6.Last checkpoint at  84 2939889199

7.0 pending log writes, 0 pending chkp writes

8.14073669 log i/o's done, 10.90 log i/o's/second

接下來顯示的是Innodb的日誌子系統相關資訊。可以看到當前的日誌序列號 - 相當於Innodb自從表空間開始建立直到現在已經寫入日誌檔案的總位元組數。還可以看到日誌已經重新整理到哪個點，同樣也可以根據最後檢查點計算出還有多少日 志沒有重新整理到檔案中去。Innodb採用模糊檢查點，因此這行顯示的是已經從緩衝池中重新整理到檔案的日誌序列號。由於更高的日誌序列號可能不會被立刻重新整理到 日誌檔案中去，因此日誌序列號不能被覆蓋掉。透過監控重新整理到哪個日誌的日誌序列，可以判定 innodb_log_buffer_size 的設定是否合理，如果看到超過 30% 的日誌還沒有重新整理到日誌檔案中，則需要考慮增加它的值了。

另外，還能看到日誌寫入以及檢查點的數目。根據日誌 I/O 操作的數目可以區分開表空間相關的IO請求和日誌IO請求數量，進而可以確定到底需要幾個日誌檔案。注意，innodb_flush_log_at_trx_commit 的值可以影響到日誌寫操作的代價高或低。如果 innodb_flush_logs_at_trx_commit=2，則日誌是寫到系統快取，然後再順序寫到日誌檔案中，因此相對會快很多。

1.----------------------

2.BUFFER POOL AND MEMORY

3.----------------------

4.Total memory allocated 4648979546; in additional pool allocated 16773888

5.Buffer pool size   262144

6.Free buffers       0

7.Database pages     258053

8.Modified db pages  37491

9.Pending reads 0

10.Pending writes: LRU 0, flush list 0, single page 0

11.Pages read 57973114, created 251137, written 10761167

12.9.79 reads/s, 0.31 creates/s, 6.00 writes/s

13.Buffer pool hit rate 999 / 1000

這部分顯示了緩衝池和記憶體的利用率相關資訊。可以看到Innodb分配的所有記憶體(有些時候可能比你設定的還要多點)，以及額外的記憶體池分配情況 (可以檢查它的大小是否正好)，緩衝池總共有多少個記憶體頁，有多少空閒記憶體頁，資料庫分配了多少個記憶體頁以及有多少個髒記憶體頁。從這些資訊中，就可以判斷 記憶體緩衝池是否設定合理，如果總是有大量空閒記憶體頁，則不需要設定那麼多記憶體，可以適當減小一點。如果空閒記憶體頁為 0，這種情況下資料庫記憶體頁就不一定會和緩衝池的總數一致，因為緩衝池還需要儲存鎖資訊，自適應雜湊索引以及其他系統結構等資訊。

等待中的讀寫是指記憶體緩衝池級別的請求。Innodb可能會把多個檔案級別的請求合併到一個上，因此各不相同。我們還可以看到Innodb提交的各 種不同型別的IO，LRU記憶體頁中需要重新整理的頁 - 髒記憶體頁，它們不會被長時間存取；重新整理列表 -
檢查點程式處理完之後需要重新整理的舊記憶體頁；獨立記憶體頁 - 獨立的寫記憶體頁。

我們還可以看到記憶體頁總共讀寫了多少次。已經建立的記憶體頁是當前一個記憶體頁中的內容沒有讀取到記憶體緩衝池中時，專門為新資料建立的空記憶體頁。

最後我們可以看到緩衝池的命中率，它預示著緩衝池的效率。1000/1000 相當於 100% 的命中率。不過這樣也很難說明緩衝池的命中率就足夠高了，這要需要根據不同的負載環境而定。通常情況下，950/1000 就夠了，有些時候在IO負載較高的環境下，命中率可能為 995/1000。

1.--------------

2.ROW OPERATIONS

3.--------------

4.0 queries inside InnoDB, 0 queries in queue

5.1 read views open inside InnoDB

6.Main thread process no. 10099, id 88021936, state: waiting for server activity

7.Number of rows inserted 143, updated 3000041, deleted 0, read 24865563

8.0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s

最後一部分，顯示了資料行操作以及一些系統資訊相關情況。

一開始顯示了Innodb執行緒佇列狀態 - 有多少執行緒處於等待或活躍的。Innodb內部開啟了多少讀檢視 -
這是在事務開始後，但是當前還沒有活躍語句的情況，Innodb主執行緒的狀態控制了系統操作排程的數量 - 重新整理髒記憶體頁、檢查點、淨化執行緒、重新整理日誌、合併插入緩衝等。 "state" 的值則表示了主執行緒當前的狀態。

接下來可以看到自從系統啟動以來，所有的資料行運算元量及其平均值。它們可以很方便地用於監控以及畫出系統狀態圖，資料行操作次數可以很好的衡量 Innodb的負載。不是所有的資料行操作帶來的負載都是一樣的，存取10位元組的行比10Mb的行相比會小了很多，不過相對於查詢的總次數來說這個資訊可 是有用的多了，差別也很大。

還有一點需要注意的是，SHOW INNODB STATUS 不是一成不變的，有些時間點上可能會不相符。SHOW INNODB STATUS結果中，不同時間可能會顯示不同結果，因此有些時候可能會看到衝突的資訊。這是由於設計時需要由全域性鎖提供一致性資訊，導致了大量的開銷。