您的位置:首页 > 其它

SHOW INNODB STATUS walk through

2017-09-18 22:25 471 查看

SHOW INNODB STATUS walk through

Peter Zaitsev  | July 17, 2006 |  Posted In:

Insight for DBAs
Many people asked me to publish a walk through SHOW INNODB STATUS
output, showing what you can learn from SHOW INNODB STATUS output and how to use this info to improve MySQL Performance.

To start with basics SHOW INNODB STATUS is command which prints out a lot of internal Innodb performance counters, statistics, information about transaction processing and all kinds of other things. In MySQL 5 number of Innodb performance counters were exported
and now available in SHOW STATUS output. Most of them are same as you previously could find in SHOW INNODB STATUS, there are however few which were not available before.

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:

Shell

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

1
2
3
4

=====================================

060717  3:07:56
INNODB MONITOR
OUTPUT
=====================================

Per second averages
calculated from
the last
44 seconds

Make sure data is sampled for at least 20-30 seconds. If averages are calculated for last 0 or 1 second they are pretty much unusable.

To be honest I do not really like averages Innodb provides as it is hard to get average for interval you want to have, if you’re writing scripts to look at SHOW INNODB STATUS it is much better to use global counters and get averages manually. They are still
however quite helpful if you’re just looking at output.

Next sections in Semaphores information:

Shell

----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 13569, signal count 11421
--Thread 1152170336 has waited at ./../include/buf0buf.ic line 630 for 0.00 seconds the semaphore:
Mutex at 0x2a957858b8 created file buf0buf.c line 517, lock var 0
waiters flag 0
wait is ending
--Thread 1147709792 has waited at ./../include/buf0buf.ic line 630 for 0.00 seconds the semaphore:
Mutex at 0x2a957858b8 created file buf0buf.c line 517, lock var 0
waiters flag 0
wait is ending
Mutex spin waits 5672442, rounds 3899888, OS waits 4719
RW-shared spins 5920, OS waits 2918; RW-excl spins 3463, OS waits 3163

1
2
3
4
5
6
7
8
9
10
11
12
13
14

----------

SEMAPHORES
----------

OS WAIT
ARRAY INFO:
reservation count
13569,
signal count
11421
--Thread
1152170336 has
waited at
./../include/buf0buf.ic
line 630
for 0.00
seconds the semaphore:

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

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

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

wait is
ending
Mutex
spin waits
5672442,
rounds 3899888,
OS waits
4719

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

There are two portions in this section. One is list of current waits. This section will only contain any entries if you’re running in high concurrency envinronment, so Innodb has to fall back to OS waits frequently. If wait was resolved via Spinlock it will
not be seen in this section.

Looking at this section you can get an idea what might be hot spot in your workload. It however requires some knowledge of source code – you only get file names and lines (which are different in different versions), you get no information what this object
is responsible for. You however can well guess from file names – in this case file is “buf0buf.ic” what means there is some buffer pool contention. However if you want to know more – you need to browse source.

You also see some details printed about wait. “lock var” is current value for the mutex object (locked=1/free=0) , “waiters flag” is current number of waiters, plus you can see wait status information “wait is ending” in this case which means mutex is already
free for grabs but os has not yet scheduled thread so it could proceed with execution.

The second piece of information is event counters – “reservation count” and “signal count” show how actively innodb uses internal sync array – how frequently slots are allocated in it and how frequently threads are signaled using sync array. These counters
can be used to represent frequency with which Innodb needs to fall back to OS Wait. There is direct information about OS waits as well – you can see “OS Waits” for

mutexes, as well as for read-write locks. For these information both for exclusive locks and for shared locks is displayed. 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 are relatively slow, and if you get tens of thousands of OS waits per second it may be the problem. The other way to look at it is context switch rate in your OS stats.

The other important peice of information is number of “spin waits” and “spin rounds”. Spin locks are low cost wait, compared to OS wait, it is however active wait which wastes your CPU cycles, so if you see very large amount of spin waits and spin rounds
significant CPU resources may be wasted. It should come to hundreds of thousands spin rounds per second to start really worry for most CPUs.
innodb_sync_spin_loops can be used to ballance between wasting CPU time running spin locks and doing unneeded context switches.

The next section is about deadlock errors:

Shell

------------------------
LATEST DETECTED DEADLOCK
------------------------
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)

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32

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

LATEST DETECTED DEADLOCK
------------------------

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)

For last deadlock Innodb shows transactions which caused deadlocks, their state during deadlock, what locks they were holding and what they were waiting for, which of transactions Innodb decided to roll back to resolve deadlock. Note – Innodb only prints
information about few of the locks which transaction is holding. Also only last statement from each transactions is displayed, while locks rows could be locked by one of previous statements. For complex deadlock investigations you might need to look at the
log files to find truly conflicting statements. For most simple cases information from SHOW INNODB STATUS is good enough.

As for deadlock information we have similar information about last failed foreign key constraint:

Shell

------------------------
LATEST FOREIGN KEY ERROR
------------------------
060717 4:29:00 Transaction:
TRANSACTION 0 336342767, ACTIVE 0 sec, process no 3946, OS thread id 1151088992 inserting, thread declared inside InnoDB 500
mysql tables in use 1, locked 1
3 lock struct(s), heap size 368, undo log entries 1
MySQL thread id 9697561, query id 188161264 localhost root update
insert into child values(2,2)
Foreign key constraint fails for table `test/child`:
,
CONSTRAINT `child_ibfk_1` FOREIGN KEY (`parent_id`) REFERENCES `parent` (`id`) ON DELETE CASCADE
Trying to add in child table, in index `par_ind` tuple:
DATA TUPLE: 2 fields;
0: len 4; hex 80000002; asc ;; 1: len 6; hex 000000000401; asc ;;
But in parent table `test/parent`, in index `PRIMARY`,
the closest match we can find is record:
PHYSICAL RECORD: n_fields 3; 1-byte offs TRUE; info bits 0
0: len 4; hex 80000001; asc ;; 1: len 6; hex 0000140c2d8f; asc - ;; 2: len 7; hex 80009c40050084; asc @ ;;

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20

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

LATEST FOREIGN KEY
ERROR
------------------------

060717  4:29:00
Transaction:
TRANSACTION
0 336342767,
ACTIVE 0
sec,
process no
3946,
OS thread id
1151088992 inserting,
thread declared
inside InnoDB
500

mysql tables in
use 1,
locked 1
3
lock struct(s),
heap size
368,
undo log entries
1

MySQL thread id
9697561,
query id
188161264 localhost
root update
insert
into child
values(2,2)

Foreign key constraint
fails for
table `test/child`:
,

  CONSTRAINT
`child_ibfk_1`
FOREIGN KEY
(`parent_id`)
REFERENCES `parent`
(`id`)
ON DELETE CASCADE
Trying
to add
in child
table,
in index
`par_ind`
tuple:

DATA TUPLE:
2 fields;
0:
len 4;
hex 80000002;
asc     ;;
1:
len 6;
hex 000000000401;
asc       ;;

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

the closest match
we can find
is record:
PHYSICAL
RECORD:
n_fields
3;
1-byte
offs TRUE;
info bits
0

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

Innodb will print statement which caused error. Definition of foreign key which failed as well as the closest match which was located in parent table. There is a lot of scary information in hex but it is not important for most diagnostic cases – It is left
by Innodb developers so SHOW INNODB STATUS can also be used as debugging tool.

Next section you will find in SHOW INNODB STATUS is information about currently active transactions:

Shell

------------
TRANSACTIONS
------------
Trx id counter 0 80157601
Purge done for trx's n:o < 0 80154573 undo n:o < 0 0
History list length 6
Total number of lock structs in row lock hash table 0
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0 0, not started, process no 3396, OS thread id 1152440672
MySQL thread id 8080, query id 728900 localhost root
show innodb status
---TRANSACTION 0 80157600, ACTIVE 4 sec, process no 3396, OS thread id 1148250464, thread declared inside InnoDB 442
mysql tables in use 1, locked 0
MySQL thread id 8079, query id 728899 localhost root Sending data
select sql_calc_found_rows * from b limit 5
Trx read view will not see trx with id >= 0 80157601, sees < 0 80157597
---TRANSACTION 0 80157599, ACTIVE 5 sec, process no 3396, OS thread id 1150142816 fetching rows, thread declared inside InnoDB 166
mysql tables in use 1, locked 0
MySQL thread id 8078, query id 728898 localhost root Sending data
select sql_calc_found_rows * from b limit 5
Trx read view will not see trx with id >= 0 80157600, sees < 0 80157596
---TRANSACTION 0 80157598, ACTIVE 7 sec, process no 3396, OS thread id 1147980128 fetching rows, thread declared inside InnoDB 114
mysql tables in use 1, locked 0
MySQL thread id 8077, query id 728897 localhost root Sending data
select sql_calc_found_rows * from b limit 5
Trx read view will not see trx with id >= 0 80157599, sees < 0 80157595
---TRANSACTION 0 80157597, ACTIVE 7 sec, process no 3396, OS thread id 1152305504 fetching rows, thread declared inside InnoDB 400
mysql tables in use 1, locked 0
MySQL thread id 8076, query id 728896 localhost root Sending data
select sql_calc_found_rows * from b limit 5
Trx read view will not see trx with id >= 0 80157598, sees < 0 80157594

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31

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

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

Trx id
counter 0
80157601
Purge
done for
trx's
n:o
< 0
80154573 undo
n:o
< 0
0

History list length
6
Total
number of lock
structs in
row lock hash
table 0

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

MySQL thread id
8080,
query id
728900 localhost
root
show
innodb status

---TRANSACTION
0 80157600,
ACTIVE 4
sec,
process no
3396,
OS thread id
1148250464,
thread declared
inside InnoDB
442
mysql
tables in
use 1,
locked 0

MySQL thread id
8079,
query id
728899 localhost
root Sending data
select
sql_calc_found_rows  *
from b
limit 5

Trx read
view will not
see trx with
id >=
0 80157601,
sees <
0 80157597
---TRANSACTION
0 80157599,
ACTIVE 5
sec,
process no
3396,
OS thread id
1150142816 fetching
rows,
thread declared
inside InnoDB
166

mysql tables in
use 1,
locked 0
MySQL
thread id
8078,
query id
728898 localhost
root Sending data

select sql_calc_found_rows  *
from b
limit 5
Trx
read view
will not
see trx with
id >=
0 80157600,
sees <
0 80157596

---TRANSACTION
0 80157598,
ACTIVE 7
sec,
process no
3396,
OS thread id
1147980128 fetching
rows,
thread declared
inside InnoDB
114
mysql
tables in
use 1,
locked 0

MySQL thread id
8077,
query id
728897 localhost
root Sending data
select
sql_calc_found_rows  *
from b
limit 5

Trx read
view will not
see trx with
id >=
0 80157599,
sees <
0 80157595
---TRANSACTION
0 80157597,
ACTIVE 7
sec,
process no
3396,
OS thread id
1152305504 fetching
rows,
thread declared
inside InnoDB
400

mysql tables in
use 1,
locked 0
MySQL
thread id
8076,
query id
728896 localhost
root Sending data

select sql_calc_found_rows  *
from b
limit 5
Trx
read view
will not
see trx with
id >=
0 80157598,
sees <
0 80157594

If you have small number of connections all connections will be printed in transaction list, if you have large number of connections Innodb will only print number of them, cutting the list so SHOW INNODB STATUS output will not grow too large.

Transaction id is current transaction identifier – it is incremented for each transaction.
Purge done for trx’s n:o is number of transaction to which purge is done. Innodb can only purge old versions if they there are no running transactions potentially needing them. Old stale uncommitted transactions may block purge process eating up resources.
By looking at transaction counter difference between current and last purged transaction you will be able to spot it. In some rare cases purge also could have hard time to keep up with update rate, in this case difference between these values will also grow
and innodb_max_purge_lag will become your friend. “undo n:o” will show the undo log record number which purge is currently processing, if it is active otherwise it will be zero.

History list length 6 is number of unpurged transactions in undo space. It is increased as transactions which have done updates are commited and decreased as purge runs.

Total number of lock structs in row lock hash table is number of row lock structures allocated by all transactions. Note not same as number of locked rows – there are normally many rows for each lock structure.

For each of connections for MySQL there will be ether not started state if there is no active Innodb transaction for this connection, or
ACTIVE if transaction is active. Note transaction can be active even if connection is in “Sleep” stage – if it is multiple statement transaction. Innodb also will print OS thread_id and process id which may be helpful if you would like to use gdb to
connect to running mysqld for troubleshooting purposes and similar things. Also transaction status is reported which is basically what transaction is doing it can be
“fetching rows”, “updating” and couple of other values. “Thread declared inside InnoDB 400” means thread is running inside Innodb kernel and still has 400 tickets to use. Innodb tries to limit thread concurrency allowing only
innodb_thread_concurrency threads to run inside Innodb kernel at the same time. If thread is not runniing inside innodb kernel status could be
“waiting in InnoDB queue” or “sleeping before joining InnoDB queue”. Latest one is quite interesting – to avoid too many threads competing to enter innodb queue at the same time Innodb makes thread to sleep for some time before trying to wait
(if no free slot was available). This may cause number of threads active inside kernel being less than number of threads allowed by
innodb_thread_concurrency. For certain workloads it may help to decrease the time thread waits before it enters the queue. This is done by adjusting
innodb_thread_sleep_delay variable. Value is specified in microseconds.

mysql tables in use 1, locked 0 is number of tables used by transaction in question (meaning it was accessed) and number of tables locked by transactions. Innodb does not lock tables for normal operation so number of tables locked normally stays
0, unless it is ALTER TABLE or similar statement, or if LOCK TABLES
was used.

In addition to Innodb specific information, there is generic statement information which is visible in SHOW PROCESSLIST showed in
SHOW INNODB STATUS, such as statement which is being executed, query id, query status etc.

Next section you will see is section showing details of file IO:

Shell

--------
FILE I/O
--------
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: 0; buffer pool: 0
17909940 OS file reads, 22088963 OS file writes, 1743764 OS fsyncs
0.20 reads/s, 16384 avg bytes/read, 5.00 writes/s, 0.80 fsyncs/s

1
2
3
4
5
6
7
8
9
10
11
12

--------

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

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:
0;
buffer pool:
0
17909940
OS file
reads,
22088963 OS
file writes,
1743764 OS
fsyncs

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

This section shows state of file IO helper threads – insert buffer thread, log thread, read thread and write thread. These are responsible appropriately for insert buffer merges, asynchronous log flushes, read-ahead and flushing of dirty buffers. Normal
reads originated from query executions are executed by threads running queries. On Unix/Linux you will always see 4 helper threads, on Windows it however can be adjusted by
innodb_file_io_threads variable. For each helper thread you can see thread state – if thread is ready –
waiting for i/o request or if it is executing certain operation.

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.

Shell

-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf for space 0: size 1, free list len 887, seg size 889, is not empty
Ibuf for space 0: size 1, free list len 887, seg size 889,
2431891 inserts, 2672643 merged recs, 1059730 merges
Hash table size 8850487, used cells 2381348, node heap has 4091 buffer(s)
2208.17 hash searches/s, 175.05 non-hash searches/s

1
2
3
4
5
6
7
8

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

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

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

2431891 inserts,
2672643 merged
recs,
1059730 merges
Hash
table size
8850487,
used cells
2381348,
node heap has
4091 buffer(s)

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.

Shell

---
LOG
---
Log sequence number 84 3000620880
Log flushed up to 84 3000611265
Last checkpoint at 84 2939889199
0 pending log writes, 0 pending chkp writes
14073669 log i/o's done, 10.90 log i/o's/second

1
2
3
4
5
6
7
8

---

LOG
---

Log sequence number
84 3000620880
Log
flushed up to  
84 3000611265

Last checkpoint at  84
2939889199
0
pending log writes,
0 pending
chkp writes

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.

Shell

----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 4648979546; in additional pool allocated 16773888
Buffer pool size 262144
Free buffers 0
Database pages 258053
Modified db pages 37491
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages read 57973114, created 251137, written 10761167
9.79 reads/s, 0.31 creates/s, 6.00 writes/s
Buffer pool hit rate 999 / 1000

1
2
3
4
5
6
7
8
9
10
11
12
13

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

BUFFER POOL AND
MEMORY
----------------------

Total memory allocated
4648979546;
in additional
pool allocated
16773888
Buffer
pool size  
262144

Free buffers      
0
Database
pages     258053

Modified db pages  37491
Pending
reads 0

Pending writes:
LRU 0,
flush list
0,
single page
0
Pages
read 57973114,
created 251137,
written 10761167

9.79 reads/s,
0.31 creates/s,
6.00 writes/s
Buffer
pool hit rate
999 /
1000

This section shows Buffer pool activity and memory usage. You can see total memory allocated by Innodb (sometimes it is higher than you anticipated), amount of memory allocated in additional memory pool (so you can check if it is sized right), total number
of pages in buffer pool, number of pages free, pages allocated by database pages and dirty pages. From these values you can learn if your buffer pool is sized well – if you have constantly a lot of pages free, it probably means your active database size is
smaller than allocated buffer pool size so you can tune it down. Even if free pages is zero as in this case database pages will not be equal to total size of buffer pool, because buffer pool also stores lock information, adaptive hash indexes and some other
system structures.

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.

Shell

--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
1 read views open inside InnoDB
Main thread process no. 10099, id 88021936, state: waiting for server activity
Number of rows inserted 143, updated 3000041, deleted 0, read 24865563
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s

1
2
3
4
5
6
7
8

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

ROW OPERATIONS
--------------

0 queries
inside InnoDB,
0 queries
in queue
1
read views
open inside InnoDB

Main thread process
no.
10099,
id 88021936,
state:
waiting for
server activity
Number
of rows inserted
143,
updated 3000041,
deleted 0,
read 24865563

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.

Note:
our book has an updated, more complete, more in-depth explanation of SHOW INNODB OUTPUT.
内容来自用户分享和网络整理,不保证内容的准确性,如有侵权内容,可联系管理员处理 点击这里给我发消息
标签: