show engine innodb status[解读]

12月 16, 2021 |

show engine innodb status 这个命令的输出挺复杂,将学到的内容整理如下

BACKGROUND THREAD
-----------------
#清理脏页,清理或者合并change buffer
srv_master_thread loops: 1397 srv_active, 0 srv_shutdown, 5574 srv_idle
#redo log刷入磁盘
srv_master_thread log flush and writes: 0

SEMAPHORES
----------
#mysql 的mutex是通过两段式实现,如果自旋(spin),也就是空转n次后能获取锁,那么就直接使用,否则进入操作系统的信号量等待队列线程挂起
#不太确定rounds的意思,感觉是spins时cpu的次数。这块很专业,需要源码支持
OS WAIT ARRAY INFO: reservation count 9105
OS WAIT ARRAY INFO: signal count 10334
RW-shared spins 0, rounds 0, OS waits 0
RW-excl spins 0, rounds 0, OS waits 0
RW-sx spins 0, rounds 0, OS waits 0
Spin rounds per wait: 0.00 RW-shared, 0.00 RW-excl, 0.00 RW-sx

#揭示事务锁定的页,行锁,修改记录数
Trx id counter 25867574
Purge done for trx's n:o < 25867574 undo n:o < 0 state: running but idle
History list length 0 #很有参考意义,太大会导致激烈地将数据写入磁盘
---TRANSACTION 25864972, ACTIVE 242 sec recovered trx
ROLLING BACK 2 lock struct(s), heap size 1128, 1 row lock(s), undo log entries 302786
---TRANSACTION 25865996, ACTIVE 35 sec updating or deleting
mysql tables in use 1, locked 1
21234 lock struct(s), heap size 2400376, 1528794 row lock(s), undo log entries 1507562
以下为锁等待示例,基于innodb_lock_waits 输出强烈建议比较学习
---TRANSACTION 25869588, ACTIVE 267 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 2 lock struct(s), heap size 1128, 1 row lock(s)
MySQL thread id 12, OS thread handle 140455116388096, query id 89 192.168.228.1 root updating
UPDATE child SET age=age+1, parent_id=2 WHERE id=2
------- TRX HAS BEEN WAITING 267 SEC FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 22 page no 4 n bits 72 index PRIMARY of table `employees`.`child` trx id 25869588 lock_mode X locks rec but not gap waiting
Record lock, heap no 3 PHYSICAL RECORD: n_fields 5; compact format; info bits 0
0: len 4; hex 80000002; asc ;;
1: len 6; hex 0000018ab756; asc V;;
2: len 7; hex 020000011c0f15; asc ;;
3: len 4; hex 80000015; asc ;;
4: len 4; hex 80000002; asc ;;
---TRANSACTION 25869587, ACTIVE 492 sec
2 lock struct(s), heap size 1128, 2 row lock(s)
MySQL thread id 10, OS thread handle 140455140357888, query id 80 192.168.228.1 root

FILE I/O
--------
#从vmstat输出也能反应io情况
Pending normal aio reads: [0, 0, 0, 0] , aio writes: [0, 0, 0, 0] ,
ibuf aio reads:, log i/o's:, sync i/o's:
Pending flushes (fsync) log: 0; buffer pool: 0
312199 OS file reads, 1093611 OS file writes, 204395 OS fsyncs
16.43 reads/s, 16384 avg bytes/read, 0.48 writes/s, 0.26 fsyncs/s

-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
# 反应change buffer(记录对二次索引改动)情况, 和自适应索引命中情况
Ibuf: size 1, free list len 1704, seg size 1706, 0 merges
merged operations:
insert 0, delete mark 0, delete 0
discarded operations:
insert 0, delete mark 0, delete 0
Hash table size 622663, node heap has 668 buffer(s)
0.00 hash searches/s, 0.00 non-hash searches/s
---
LOG # redo log的刷盘情况
---
Log sequence number 34064785034
Log buffer assigned up to 34064785034
Log buffer completed up to 34064785034
Log written up to 34064785034
Log flushed up to 34064785034
Added dirty pages up to 34064785034
Pages flushed up to 34064785034
Last checkpoint at 34064785034
772735 log i/o's done, 0.13 log i/o's/second

BUFFER POOL AND MEMORY
----------------------
Total large memory allocated 0
Dictionary memory allocated 383826
Buffer pool size 19189
Free buffers 0
Database pages 18521
Old database pages 6847 #old sublist的页数
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
# young sublist为热区,不易被驱逐
Pages made young 630, not young 62013704
0.00 youngs/s, 0.00 non-youngs/s
Pages read 312174, created 63190, written 236725
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 611 / 1000, young-making rate 0 / 1000 not 389 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 18521, unzip_LRU len: 0
I/O sum[383]:cur[0], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
# 参考说进入innodb的查询数, 一直没观察到这个值
0 queries inside InnoDB, 0 queries in queue
0 read views open inside InnoDB
Number of rows inserted 0, updated 7500538, deleted 0, read 7500538
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
Number of system rows inserted 0, updated 317, deleted 0, read 4700
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s

innodb_lock_waits 示例输出

mysql> select * from sys.innodb_lock_waits\G
*************************** 1. row ***************************
                wait_started: 2021-12-16 23:44:22
                    wait_age: 00:05:18
               wait_age_secs: 318
                locked_table: `employees`.`child`
         locked_table_schema: employees
           locked_table_name: child
      locked_table_partition: NULL
   locked_table_subpartition: NULL
                locked_index: PRIMARY
                 locked_type: RECORD
              waiting_trx_id: 25869588
         waiting_trx_started: 2021-12-16 23:44:22
             waiting_trx_age: 00:05:18
     waiting_trx_rows_locked: 1
   waiting_trx_rows_modified: 0
                 waiting_pid: 12
               waiting_query: UPDATE child SET age=age+1, parent_id=2 WHERE id=2
             waiting_lock_id: 140456342345296:22:4:3:140456235196208
           waiting_lock_mode: X,REC_NOT_GAP
             blocking_trx_id: 25869587
                blocking_pid: 10
              blocking_query: NULL
            blocking_lock_id: 140456342342872:22:4:3:140456235178144
          blocking_lock_mode: X,REC_NOT_GAP
        blocking_trx_started: 2021-12-16 23:40:37
            blocking_trx_age: 00:09:03
    blocking_trx_rows_locked: 2
  blocking_trx_rows_modified: 0
     sql_kill_blocking_query: KILL QUERY 10 #解决方案
sql_kill_blocking_connection: KILL 10   #解决方案
1 row in set (0.01 sec)

# 对于locked_type: RECORD,默认是gap locks, 除非lock_mode有REC_NOT_GAP标识
# lock_id"22:4:3"与show engine innodb status输出中的space id 22 page no 4 ,heap no 3对应

参考文档

https://dev.mysql.com/doc/mysql-em-plugin/en/myoem-metrics.html https://www.percona.com/blog/2006/07/17/show-innodb-status-walk-through/

Posted in: database | Tags:

Comments are closed.