解析innodb status各项参数

mysql> show innodb status\G;
*************************** 1. row ***************************
Type: InnoDB
Name:
Status:
=====================================
140423 4:15:38 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 14 seconds

参数值基本上按秒统计，需要选择适当的时间间隔取样。

======================================SEMAPHORES======================================

----------
SEMAPHORES

----------

大量线程等待semaphores 意味着disk I/O或者InnoDB的连接问题。可由heavy query parallelism或者OS thread scheduling发起Contention。大量连接会减少innodb_thread_concurrency(global, dynamic, 8 by default, 0-1,000)。0=unlimited(think of a buffet line, if everyone goes at once it willtake a long time)。
Innodb采取multiphase wait policy。首先，尝试spin wait，由CPU cycles 检查threads是否运行。而后升级为 OS wait, 可触发context switch让另一 thread运行。
spin waits = more cpu, no context switch vs. OS waits。

innodb_sync_spin_loops ：thread被挂起之前，等待空闲InnoDB mutex的次数，The default value 20（Global, dynamic, range is 0-4,294,967,295）。
OS WAITS ARRAY shows reservations for OS waits vs. how many signals were actually sent to threads.

基于locking在哪里，我们可以知道thread正在等待什么，buffer还是index write。比如：srv0srv.c 由长SELECT FOR UPDATE 查询引发的waits。

semaphore是一种保护便量或抽象数据类型用于构成限制共享资源（比如并行计算环境下的共享内存）访问的方法。基本上以锁的方式实现。

OS WAIT ARRAY INFO: reservation count 182944079, signal count 129485790

当前等待列表，如果并发数很大，Innodb就必须频繁等待 OS（该部分不包含由spinlock解决的等待）。reservation count和signal count表明InnoDB使用内部同步数组的频繁程度，这些数值表示InnoDB需要等待OS的频率。

--Thread 140383712171776 has waited at btr/btr0cur.c line 378 for 0.00 seconds the semaphore:

btr0pcur.c ：B-tree / persistent cursor ， index tree persistent cursor
X-lock on RW-latch at 0x7fad640306a0 created in file dict/dict0dict.c line 1353
a writer (thread id 140383712171776) has reserved it in mode wait exclusive
number of readers 1, waiters flag 1

waiters flag：当前等待线程数
Last time read locked in file btr/btr0cur.c line 385
Last time write locked in file btr/btr0cur.c line 378

--Thread 140383703385856 has waited at btr/btr0cur.c line 385 for 0.00 seconds the semaphore:
S-lock on RW-latch at 0x7fad640306a0 created in file dict/dict0dict.c line 1353
a writer (thread id 140383712171776) has reserved it in mode wait exclusive
number of readers 1, waiters flag 1
Last time read locked in file btr/btr0cur.c line 385
Last time write locked in file btr/btr0cur.c line 378

--Thread 140382476871424 has waited at ibuf/ibuf0ibuf.c line 738 for 0.00 seconds the semaphore:

ibuf0ibuf.c ： Insert Buffer /， Insert buffer
X-lock on RW-latch at 0x7fada8d03fb0 created in file buf/buf0buf.c line 550
a writer (thread id 140383711905536) has reserved it in mode wait exclusive
number of readers 1, waiters flag 1
Last time read locked in file buf/buf0flu.c line 660
Last time write locked in file ibuf/ibuf0ibuf.c line 738

补充：srv0srv.c ： Server / Server， Server main program
Mutex spin waits 0, rounds 41511596793, OS waits 84253954

RW-shared spins 92745676, OS waits 40399910; RW-excl spins 71767529, OS waits 49673121

spin waits和spin rounds：与OS wait相比，Spin locks 是低消耗的等待，但它是一种活跃的等待，会浪费CPU资源，因此spin waits和spin rounds 如果很大，CPU资源会被浪费。如果该值达到几十万，CPU危险了。

OS Waits：表明由于互斥的OS的等待。OS Waits 相对较慢，如果每秒钟该值有几万，就有问题。另外一种方式来看该值是通过OS状态的 context switch.

此部分状态与如下参数相关：

●innodb_sync_spin_loops
● innodb_thread_concurrency

==========================LATEST DETECTED DEADLOCK===========================

------------------------

LATEST DETECTED DEADLOCK

------------------------

Heap size ：用于保存row locks的内存大小。

记录导致deadlock的事务。他们在死锁期间的状态，拥有的锁，等待获取的锁。Innodb决定roll back哪个事务来解决deadlock（选择发生最少更新操作的事务）。

注意：只打印少量已拥有的锁，以及每个事务最后一条lock rows的语句。Heap size ：用于保存row locks的内存大小。

060717 4:16:48
*** (1) TRANSACTION:
TRANSACTION 0 42313619, ACTIVE 49 sec, process no 10099, OS thread id 3771312 starting index read
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 320
MySQL thread id 30898, query id 100626 localhost root Updating
update iz set pad='a' where i=2
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
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
Record lock, heap no 5 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
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 ;;
*** (2) TRANSACTION:
TRANSACTION 0 42313620, ACTIVE 24 sec, process no 10099, OS thread id 4078512 starting index read, thread declared inside InnoDB 500
mysql tables in use 1, locked 1
3 lock struct(s), heap size 320
MySQL thread id 30899, query id 100627 localhost root Updating
update iz set pad='a' where i=1
*** (2) HOLDS THE LOCK(S):
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
Record lock, heap no 5 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
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 ;;
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
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
Record lock, heap no 4 PHYSICAL RECORD: n_fields 4; compact format; info bits 0
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 ;;

*** WE ROLL BACK TRANSACTION (2)

==========================TRANSACTIONS=======================================

------------
TRANSACTIONS
------------

MVCC ：当前无transaction使用此版本，则在undo区发生purging。一旦操作完成保证commit ，否则你无须保留数据而且purge也不会发生。current txn # and last purged txn # 是不同的。

如果连接比较少，则会全部列出；否则只会列出一部分而不致使得SHOW INNODB STATUS的输出变得很大。

此部分与下列参数有关：

●innodb_thread_concurrency
● innodb_thread_sleep_delay
● innodb_commit_concurrency
● innodb_concurrency_tickets

Trx id counter 0 149268577
Purge done for trx's n:o < 0 149201387 undo n:o < 0 0

Transaction id：当前Transaction标识，随Transaction增加而递增。

Purge done for trx’s n:o：已经完成purge的事务数，Innodb 仅能purge当前运行中的transactions 不需要的旧版本。旧的未commit的事务将被阻塞purge而不再消耗资源。通过比较当前transaction和最后purged事务的计数器，我们能够发现这一点，即149268577和149201387。有些时候，purge跟不上update的速度，此时，需要合理设置innodb_max_purge_lag的值。

undo n:o : 表示undo log中当前正在进行purge的记录数，如果没有激发则为0。
History list length 30800

在undo空间中尚未purge的事务数，它随完成updates并commited事务数的增加而增加，随purge运行而减少。

LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0 0, not started, process no 4797, OS thread id 140383716431616

not started：表明本连接没有Active的Innodb事务；否则，此处为ACTIVE。注意：multiple statement transaction，即使此连接为Sleep状态，它也是Active.

Innodb也输出OS thread_id and process id用于帮助我们通过gdb来连接正在运行的mysqld进行troubleshooting或相似的目的。
MySQL thread id 16797, query id 3017516449 localhost root
show innodb status
---TRANSACTION 0 0, not started, process no 4797, OS thread id 140383079786240
MySQL thread id 16698, query id 3017206263 10.66.137.122 hss_devel

---TRANSACTION 0 149268386, not started, process no 4797, OS thread id 140383731074816
MySQL thread id 16696, query id 3017206243 10.66.137.122 hss_devel

---TRANSACTION 0 0, not started, process no 4797, OS thread id 140383691671296
MySQL thread id 16689, query id 3017206165 10.66.136.110 hss_devel
---TRANSACTION 0 149268377, not started, process no 4797, OS thread id 140383082182400
MySQL thread id 16688, query id 3017206161 10.66.136.110 hss_devel
---TRANSACTION 0 149268381, not started, process no 4797, OS thread id 140383702853376
MySQL thread id 16671, query id 3017206189 ds.app.test.eng.nay.redhat.com 10.66.80.134 hss_devel
---TRANSACTION 0 0, not started, process no 4797, OS thread id 140383692470016
MySQL thread id 14828, query id 3017206264 10.66.136.184 hss_devel
---TRANSACTION 0 144974395, not started, process no 4797, OS thread id 140383072331520
MySQL thread id 10821, query id 3017206264 10.66.136.251 hss_devel
---TRANSACTION 0 0, not started, process no 4797, OS thread id 140383082448640
MySQL thread id 10820, query id 3017206264 10.66.136.251 hss_devel
---TRANSACTION 0 149268576, ACTIVE 2 sec, process no 4797, OS thread id 140383084046080 waiting in InnoDB queue
mysql tables in use 1, locked 1
1 lock struct(s), heap size 368, 0 row lock(s), undo log entries 129
MySQL thread id 16799, query id 3017516448 etl-hss-devel.app.eng.bos.redhat.com 10.16.101.22 hss_devel update
insert into staging.BugzillaS_flags values (360280,437640,10,'?',84099,NULL,'2008-03-15 12:55:16','2008-03-15 12:55:16')
---TRANSACTION 0 149268575, ACTIVE 3 sec, process no 4797, OS thread id 140383736665856 waiting in InnoDB queue
mysql tables in use 1, locked 1
1 lock struct(s), heap size 368, 0 row lock(s), undo log entries 146
MySQL thread id 16798, query id 3017516447 etl-hss-devel.app.eng.bos.redhat.com 10.16.101.22 hss_devel update
insert into staging.BugzillaS_flags values (350234,430145,152,'+',193983,NULL,'2008-01-24 14:57:06','2008-01-24 14:57:06')
---TRANSACTION 0 149268496, ACTIVE 143 sec, process no 4797, OS thread id 140383711905536 inserting, thread declared inside InnoDB 500

1. 事务状态由事务正在执行的操作显示为：fetching rows，updating或一对其他的值。thread declared inside InnoDB 500：表明此thread运行于Innodb kernel内并还有500tickets可用。Innodb试图限制thread并发而仅仅允许innodb_thread_concurrency个thread同行运行与Innodb kernel内。

mysql tables in use 1, locked 1
1 lock struct(s), heap size 368, 0 row lock(s), undo log entries 7777
MySQL thread id 16723, query id 3017516369 etl-hss-devel.app.eng.bos.redhat.com 10.16.101.22 hss_devel update
insert into staging.BugzillaS_bugs_tmp values (67776,111,'2.1',35221,'ERRATA','---','CLOSED','medium','medium',84977,84973,NULL,'','','With cluster turned off, cluadmin \'cluster status\' gets error \"cluGetDiskNodesStates failed\"','2002-07-01 17:50:18','2008-05-01 11:38:02')

---TRANSACTION 0 149268576, ACTIVE 2 sec, process no 4797, OS thread id 140383084046080 waiting in InnoDB queue

2. 如果thread没有在innodb kernel运行，则状态为：“waiting in InnoDB queue” 或“sleeping before joining InnoDB queue”。

为了避免太多thread同时试图进入innodb queue，在试图wait之前（没有空闲slot可用）先sleep一些时间，这将使得在kernel内active的线程数小于innodb_thread_concurrency指定的数值，而这将减少thread等待进入queue的时间。通过调整参数innodb_thread_sleep_delay来实现。
mysql tables in use 1, locked 1

1 lock struct(s), heap size 368, 0 row lock(s), undo log entries 129
MySQL thread id 16799, query id 3017516448 etl-hss-devel.app.eng.bos.redhat.com 10.16.101.22 hss_devel update
insert into staging.BugzillaS_flags values (360280,437640,10,'?',84099,NULL,'2008-03-15 12:55:16','2008-03-15 12:55:16')
---TRANSACTION 0 149268491, ACTIVE 145 sec, process no 4797, OS thread id 140383734535936 waiting in InnoDB queue
mysql tables in use 1, locked 0

3.mysql tables in use 1, locked 1：被此事务使用的数据表和被此事务Lock的数据表的数量。Innodb对一般操作并不锁表，因此locked值一般为0；但对于ALTER TABLE或相似的语句，LOCK TABLES将被使用。
MySQL thread id 16733, query id 3017220245 10.66.137.122 hss_devel Copying to tmp table
SELECT M.bug_product product FROM(SELECT distinct bug_product FROM fact.v_open_bug_trend_detail_dt order by bug_product) M
Trx read view will not see trx with id >= 0 149268492, sees < 0 149201352
---TRANSACTION 0 149201352, ACTIVE 17960 sec, process no 4797, OS thread id 140383736399616
MySQL thread id 14829, query id 3017206264 10.66.136.184 hss_devel
Trx read view will not see trx with id >= 0 149201353, sees < 0 149201351

===================================FILE I/O=========================================

--------
FILE I/O
--------

file IO helper threads – insert buffer thread, log thread, read thread and write thread 的状态。对应于如下操作：insert buffer merges, asynchronous log flushes, read-ahead and flushing of dirty buffers.Unix/Linux一般有4个helper threads，你能看到每个helper threads的线程状态，如果线程是ready的，其状态为：waiting for i/o request.
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 (write thread)
Pending normal aio reads: 0, aio writes: 0,
ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
Pending flushes (fsync) log: 1; buffer pool: 0
182899700 OS file reads, 111596903 OS file writes, 5072400 OS fsyncs
174.20 reads/s, 22611 avg bytes/read, 130.28 writes/s, 16.71 fsyncs/s

Pending normal aio：每个helper线程pending操作的数量，排队中的和正在执行的execution。Pending flushes (fsync) log：pending的fsync操作数。

writes：在OS cache不足时确保数据刷新至磁盘，一般由fsync() 完成文件修改。

这些变量值代表 IO负载，线程执行请求commit的IO并不计算在内，因此在IO有负载的时候也会看到这些值为0.

IO操作的平均值，如22611 avg bytes/read： read请求的平均大小；随机IO一般为16K(page size)，full table scan / index scan将明显增加IO大小，你可以由此值查看read-ahead效率。

===================== INSERT BUFFER AND ADAPTIVE HASH INDEX===================

-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------

Innodb_buffer_pool_pages_misc ： 11% InnoDB buffer pool
innodb_adaptive_hash_index 状态变量可以关闭 adaptive hash index 。

当插入使用 non-unique 二级索引，InnoDB 将records 放入insert buffer，而后在transaction提交后 flush至disk。

如果一张表几乎在内存中完全fits，则使用hash indexes是最快的查询方式。InnoDB监控表的索引搜索，如果InnoDB注意到构建hash index将使查询获益则自动创建。InnoDB在那些经常被访问的索引页面构建hash indexes。

innodb_adaptive_hash_index ： global, static (notdynamic).
Ibuf: size 83, free list len 1849, seg size 1933,

insert buffer的状态：segment size和free list的大小(如果insert buffer存在一些记录)
296920721 inserts, 296902154 merged recs, 6883558 merges

inserts操作数，被merged的记录数，执行了的merges操作数。比率merges/inserts表示insert buffer的效率。

Hash table size 17393, node heap has 1 buffer(s)

Adaptive hash index，是建立在一些pages上的hash index,用hash代替btree检索提高查询速度。hash table size，被使用的cells数；被adaptive hash index所使用的buffers数。
1334.98 hash searches/s, 9359.05 non-hash searches/s

hash index/non-hash index表示hash index 的效率。

当前我们不能调整INSERT BUFFER 和ADAPTIVE HASH INDEX的行为，这些只是出于提供信息的目的。

=============================LOG==================================

---

LOG
---

Log子系统信息。
Log sequence number 408 205655208

表示自system表空间创建以来，写入log文件的字节数。Innodb使用fuzzy checkpointing，此行追踪log sequence，buffer pool中此number之前的sequence均已flushed；比此number高的sequence仅仅记录到logs中而未flushed。观察此值，判断innodb_log_buffer_size是否进行了优化；如果发现30%尚未flushed，你需要增加这个参数的值。
Log flushed up to 408 205652469

日志文件已经被flush到哪个point
Last checkpoint at 408 201430671

最后checkpoint时，尚未flush到日志buffer的数据量
1 pending log writes, 0 pending chkp writes

38582740 log i/o's done, 5.07 log i/o's/second

log/io操作允许将表空间相关的IO与log相关的IO分离开，你可以看到log file需要多少IO。这与参数innodb_flush_log_at_trx_commit有关，如果innodb_flush_logs_at_trx_commit=2，log file写入OS cache，顺序写入logs将非常快。

==================BUFFER POOL AND MEMORY==========================

----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 123094498; in additional pool allocated 2097152

为innodb分配内存大小（有时高于你的期望），为additional pool 分配内存大小(可以查看size是否正确）

Dictionary memory allocated 1949344
Buffer pool size 512

buffer pool中的page数
Free buffers 0

buffer pool中free状态的page数

Database pages 511

为database分配的page数
Modified db pages 379

dirty状态的page数

以上数据可以判断buffer pool大小是否合适，如果持续存在大量free pages，可能意味着active数据库小于已分配的buffer pool ，你可以将buffer pool 的大小调低。即使free pages为0，database pages也不会等于buffer pool的总大小，因为buffer pool还存储lock、adaptive hash indexes和其他一些system structures。

Pending reads 0
Pending writes: LRU 19, flush list 0, single page 0

Pending reads，Pending writes：在buffer pool级别处于pending状态的请求数。在file级别，Innodb会merge多个请求为一个请求，因此这些值是不同的。

Innodb提交的各种IO：

LRU，被flushed的LRU pages, dirty pages长时间不被访问。flush list，需要被checkpointing进程flushed的old pages。single page，独立的页面写操作数（不为其他writes所batch的writes）。
Pages read 569544035, created 5975412, written 83454064

读写页面数；created：buffer pool 为新数据创建空页面。
240.41 reads/s, 15.57 creates/s, 147.70 writes/s
Buffer pool hit rate 995 / 1000

Buffer pool hit rate表示buffer pool 的效率。995 / 1000表示命中率为99.5%，但这不能说命中率很高，这与负载相关。

======================ROW OPERATIONS=======================

--------------
ROW OPERATIONS
--------------
8 queries inside InnoDB, 37 queries in queue

显示Innodb线程队列状态，多少线程waiting（37）, 多少线程active（8）。
3 read views open inside InnoDB

在InnoDB内打开多少read view，transaction已被start但当前无active语句。
Main thread process no. 4797, id 140383751898880, state: sleeping

Main thread控制系统操作 Number的调度：flushing dirty pages, checkpointing, purging, flusing logs, doing insert buffer merge。
Number of rows inserted 554607196, updated 5022624, deleted 286552576, read 355723412743

自system启动以来，row操作的平均数，用以度量Innodb负载。并非所有row大小均相等，10byte row~10MB blog，但相较于query更能帮助我们观察负载。
1887.37 inserts/s, 0.00 updates/s, 0.00 deletes/s, 9661.45 reads/s

参考：http://www.mysqlperformanceblog.com/2006/07/17/show-innodb-status-walk-through/

更多相关文章

随机推荐