show engine innodb status 详细介绍

Contents

SHOWENGINE INNODB STATUS详细介绍。

很多人用过SHOW ENGINE INNODB STATUS来查看服务器信息以及定位问题，但它的输出内容比较复杂难懂。而网上也基本没有这方面的介绍材料– 特别是中文资料。

本文接下来详细介绍这些信息的含义，也包含一些信息产生的前因后果。希望能对你有所帮助，也希望各位看客对于文中的错误加以指正。

Header

这部分简单的打印，输出的时间，以及自从上次输出的间隔时间。

1 =====================================

2 07091310:31:48 INNODB MONITOR OUTPUT

3 =====================================

4 Persecond averages calculated from the last 49 seconds

SEMAPHORES

如果你有一个高并发的系统，你需要关注这一部分的输出。

它由两部分组成，event counters, 和可选项输出,即当前等待的事件(current waits)。

下面给出了一个示例输出。

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等一些其它的系统信息。

9-10行显示了pending的reads 和writes

11行显示了Innodb读写和创建的页面（pages）

13行显示了Innodb的buffer pool命中率，通常要保证在998/1000以上。如果没有，可考虑增大buffer pool size，以及优化你的查询

ROW OPERATIONS

这一部分显示了rowoperation及其它的一些统计信息

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

2 ROWOPERATIONS

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

4 0queries inside InnoDB, 0 queries in queue

5 1read views open inside InnoDB

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

7 Numberof rows inserted 143, updated 3000041, deleted 0, read 24865563

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

9 ----------------------------

10 ENDOF INNODB MONITOR OUTPUT

11 ============================

第4行显示了有多少线程在Innodb内核（你可回顾transaction一章）

第5行显示了有多少read view被打开了，一个read view是一致性保证的MVCC “snapshot”

第6行显示了内核的main thread的状态信息，其余可能的状态还会有：

archiving log (if log archive is on)

doing background droptables

doing insert buffer merge

flushing buffer pool pages

flushing log

making checkpoint

purging

reserving kernel mutex

sleeping

suspending

waiting for buffer poolflush to end

waiting forser veractivity

7-8行显示了行操作(rowoperation)的一些统计信息。

refer：http://blog.51cto.com/louisyang/1379813

posted @ 2018-04-18 17:26 笔案阅读(401) 评论(0) 编辑收藏举报

刷新页面返回顶部

什么是purge操作

公告