网易 
新闻 LOFTER 邮箱 相册 阅读 图书 有道 摄影 企业邮箱 优惠券 云笔记 闪电邮 邮箱大师 印像派 考拉海购
 
更多
博客 
手机博客 博客搬家 博客VIP服务 发现 小组 风格
 
群博客 博客油菜地 博客话题 博客热点 博客圈子 找朋友
 
登录  
 加关注
查看详情
   显示下一条  |  关闭
温馨提示！由于新浪微博认证机制调整，您的新浪微博帐号绑定已过期，请重新绑定！立即重新绑定新浪微博》  |  关闭

SeaRiver Blog

实力才是你一生最好的依靠!

导航

 
 
 
 
 

日志

 
 
关于我
SeaRiver

强者恒强,弱者恒弱!

文章分类

SHOW INNODB STATUS 详解  

2007-10-13 03:19:29|  分类： MySQL |  标签： |举报 |字号大中小 订阅

  下载LOFTER 我的照片书  |

  原:http://blog.chinaunix.net/u/15394/showart.php?id=321424

SHOW INNODB STATUS walk through

In SHOW INNODB STATUS many values are per second. If you're planning to use these values make sure they are sampled over decent period of time. In the very start of printout Innodb will print:

在 SHOW INNODB STATUS 中许多值都是按秒统计的，如果要使用这些值，就得隔适当的时间取样。SHOW INNODB STATUS 的开头应该是：

  1. =====================================
  2. 060717  3:07:56 INNODB MONITOR OUTPUT
  3. =====================================
  4. Per second averages calculated from the last 44 seconds

数据的取样应该至少是20－30秒。最好是写一个脚本来统计 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就必须频繁等待 OS。那么该部分不包含由spinlock解决的等待。

该部分需要对源代码有一定了解，因为只能看到文件名和行数。但可以从文件名猜出其含义－buf0buf.ic是缓存池的内容。

“lock var”是当前互斥对象(locked=1/free=0)的值，"waiters flag"是当前等待线程数，还有一些状态信息："wait is ending"意思是互斥锁已经释放，但OS还没有分配，这时这个对象可以执行。

第二部分是事件信息。"reservation count" 和 "signal count" 表明InnoDB使用内部同步数组的频繁程度。这些数值表示InnoDB需要等待OS的频率。"OS Waits" 表明由于互斥的OS的等待。OS Wait is not exactly the same as "reservation" - before falling back to complex wait using sync_array Innodb tries to "yield" to OS hoping when name thread is scheduled next time object will be free already. OS Waits 相对较慢，如果每秒钟该值有几万，就有问题。另外一种方式来看该值是通过OS状态的 context switch.

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

死锁部分：

  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只打印锁的几个信息，且只显示事务的最后一条语句，有可能被锁的行由前面一条语句引起。对复杂死锁的研究得看日志文件。

外键信息与死锁信息相似:

  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    @   ;;

看不懂的16进制信息没关系－那是程序的调试信息。

当前活跃的事务:

  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只能打印出其中的一部分，以维持整个列表的长度。

Transaction id是当前事务的标识符。Purge done for trx's n:o 是回收程序启动事务的数量。如果回收程序没有运行事务，InnoDB只能回收旧版本。旧的未提交事务可能会阻塞回收进程而吃掉资源。通过查看当前事务数和最近一次回收事务数的差值就可以发现这个问题。在某些情况下，回收程序效率很低而要维持更新率，在这种情况下差值也会增加，这时innodb_max_purge_lag 会有所帮助。"undo n:o"显示回收程序正在处理的undo日志记录数，如果当前没有回收程序运行，则该值为0。

History list length 是在回滚段中为回收的事务数。当更新事务提交时该值增加，当回收线程运行时该值减少。

Total number of lock structs in row lock hash table是所有事务分配的行锁结构数。该值并不等于锁住的行数－因为一个锁结构中包含很多行。

MySQL的连接要么是not started 状态（该连接没有活动的事务），要么是ACTIVE状态（有活动事务）。注意，尽管连接是"SLEEP"状态，但事务也可以是活跃的－如果事务中有多个语句。事务状态就是事务正在做什么，如"fetching rows", "updating"。"Thread declared inside InnoDB 400"意思是线程正在InnoDB内核中运行，当前还可以有400个线程可以进来。InnoDB限制内核中的并发线程数使用变量innodb_thread_concurrency 。如果线程没在InnoDB内核中运行，状态应该是"waiting in InnoDB queue" 或"sleeping before joining InnoDB queue"。为避免太多线程竞争进入InnoDB队列，InnoDB有时会让线程先sleep，而不是wait。这样就会使InnoDB内核中的活跃线程少于innodb_thread_concurrency。这会减少线程等待进入队列的时间，可以调整innodb_thread_sleep_delay 的值，该值为微秒。

mysql tables in use 1, locked 0 是由线程正使用的表数，和线程锁住的表数。InnoDB一般不会锁表，因此该值一般为0，除非ALTER TABLE 或LOCK TABLES 相似的操作。

文件I/O:

  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的四个进程（括号中的名字）。插入缓存合并，异步日志刷新，read－ahead和脏缓存刷新。如果线程准备好了则为waiting for i/o request 状态，否则它就正在执行某种操作。

Number of pending operation is shown for each of helper threads - these are amount of operations queued for execution or being executed at the same time. Also number of pending fsync operations is displayed. For writes Innodb has to ensure data makes it to the disk - just passing it to OS cache is not enough. This is typically done by calling fsync() for modified files. Constant high values for any of these variables is indication of IO bound workload. Note however - IO requests submited by threads executing requests are not accounted here so you may have these at zeroes while workload being IO bound still.

Next, number of file IO operations is shown as well as computed averages. This is parameters which is great for graphing and monitoring.
"16384 avg bytes/read" shows average size of read requests. For random IO these should be 16K - page size, for full table scan or index scan read-ahead may be performed which can increase average read size significantly. So you can think about this value as read-ahead efficiency.

CODE:
  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

This section shows insert buffer and adaptive hash status. First line shows status of insert buffer - segment size and free list as well as if
there are any records is insert buffer. Next it shows how many inserts were done in insert buffer, how many recs were merged and how many merges did it took. Ratio of number of merges to number of inserts is pretty much insert buffer efficiency.

Adaptive hash index is hash index Innodb builds for some pages to speed up row lookup replacing btree search with hash search. This section shows hash table size, number of used cells and number of buffers used by adaptive hash index. You can also see number of hash index lookups and number of non-hash index lookups which is indication of hash index efficiency.

There is currently not much you can do to adjust adaptive hash index or insert buffer behavior so it is pretty much for informational purposes only.

CODE:
  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

Log section provides information about log subsystem of Innodb. You can see current log sequence number - which is amount of bytes Innodb has written in log files since system tablespace creation. You can also see up to which point logs have been flushed - so how much data is unflushed in log buffer as well as when last checkpoint was performed. Innodb uses fuzzy checkpointing so this line hold log sequence, all changes up to which has been flushed from buffer pool. Changes having higher log sequences may still only be recored in logs and not flushed from buffer pool so such log sequences can't be overwritten in log files. By monitoring log sequence number and value up to which logs have been flushed you can check if your innodb_log_buffer_size is optimal - if you see more than 30% of log buffer size being unflushed you may want to increase it.

You also can see number of pending normal log writes and number of checkpoint log writes. Number of log/io operations allows to separate tablespace related IO from log related IO so you can see how much IO your log file requires. Note depending on your innodb_flush_log_at_trx_commit value your log writes may be more or less expensive. If innodb_flush_logs_at_trx_commit=2 log writes are done to OS cache, and being sequential writes these logs writes are pretty fast.

CODE:
  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分配的总内存，额外分配的内存，缓存池中的页数，空闲页数，数据库页和脏页数。从这些值中可以看出是否InnoDB缓存分配得恰当－如果总有很多空闲页，表明数据库要比内存小，可以把innoDB缓存调小些。如果空闲页为0，那么数据库页不会和缓存容量相同，因为还要存锁、索引和其他得系统结构。

Pending reads and writes are pending requests on buffer pool level. Innodb may merge multiple requests to one on file level so these are different. We can also see different types of IO submited by Innodb - pages to be flushed via LRU pages - dirty pages which were not accessed long time, flush list - old pages which need to be flushed by checkpointing process and single page - independent page writes.

We can also see number of pages being read and written. Created pages is empty pages created in buffer pool for new data - when previous page content was not read to the buffer pool.

Finally you can see buffer pool hit ratio which measures buffer pool efficiency. 1000/1000 corresponds to 100% hit rate. It is hard to tell what buffer pool hit rate is good enough - it is very workload dependent. Sometimes 950/1000 will be enough, sometimes you can see IO bound workload with hit rate of 995/1000.

CODE:
  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

Finally last section - row operations which shows activity on the row basics and some system information.

It shows innodb thread queue status - how many threads are waiting and being active. How many read views are open inside Innodb - this is when transaction was started but no statement is currently active, state of Innodb main thread which controls scheduling of number of system operations - flushing dirty pages, checkpointing, purging, flusing logs, doing insert buffer merge. Values for "state" field are rather self explanatory.

You can also see number of rows operation since system startup as well as average values. This is also very good values to monitor and graph - row operations is very good measure of Innodb load. Not all row operations are created equal of course and accessing of 10 byte rows is much cheaper than accessing 10MB blog, but it is still much more helpful than number of queries, which is even more different.

One more thing to note - SHOW INNODB STATUS is not consistent - it does not correspond to some particular point in time. Different lines in SHOW INNODB STATUS populated in different point in times, so sometimes you may see a bit conflicting information. This is by design as requiring global lock to provide consitent information would cause significant overhead.

Posted by peter @ 12:18 am :: Innodb  
book mark SHOW INNODB STATUS walk through in del.icio.usdel.icio.us :: submit SHOW INNODB STATUS walk through to digg.comdigg  
Comment RSS :: Trackback URI  
  评论这张
 
阅读(1411)| 评论(0)

历史上的今天

评论

<#--最新日志，群博日志--> <#--推荐日志--> <#--引用记录--> <#--博主推荐--> <#--随机阅读--> <#--首页推荐--> <#--历史上的今天--> <#--被推荐日志--> <#--上一篇，下一篇--> <#-- 热度 --> <#-- 网易新闻广告 --> <#--右边模块结构--> <#--评论模块结构--> <#--引用模块结构--> <#--博主发起的投票-->
 
 
 
 
 
 
 
 
 
 
 
 
 
 

页脚

我的照片书 - 博客风格 - 手机博客 - 下载LOFTER APP - 订阅此博客

网易公司版权所有 ©1997-2018