Monday, June 10, 2024

SHOW ENGINE INNODB STATUS

 

The SHOW ENGINE INNODB STATUS command in MySQL provides detailed information about the internal state of the InnoDB storage engine. This command is extremely useful for diagnosing performance issues, understanding locking, and troubleshooting various problems within the database.

The following sections are displayed

  • Status: Shows the timestamp, monitor name and the number of seconds, or the elapsed time between the current time and the time the InnoDB Monitor output was last displayed. The per-second averages are based upon this time.
  • BACKGROUND THREAD: srv_master_thread lines show work performed by the main background thread.
  • SEMAPHORES: Threads waiting for a semaphore and stats on how the number of times threads have needed a spin or a wait on a mutex or rw-lock semaphore. If this number of threads is large, there may be I/O or contention issues. Reducing the size of the innodb_thread_concurrency system variable may help if contention is related to thread scheduling. Spin rounds per wait shows the number of spinlock rounds per OS wait for a mutex.
  • LATEST FOREIGN KEY ERROR: Only shown if there has been a foreign key constraint error, it displays the failed statement and information about the constraint and the related tables.
  • LATEST DETECTED DEADLOCK: Only shown if there has been a deadlock, it displays the transactions involved in the deadlock and the statements being executed, held and required locked and the transaction rolled back to.
  • TRANSACTIONS: The output of this section can help identify lock contention, as well as reasons for the deadlocks.
  • FILE I/O: InnoDB thread information as well as pending I/O operations and I/O performance statistics.
  • INSERT BUFFER AND ADAPTIVE HASH INDEX: InnoDB insert buffer (old name for the change buffer) and adaptive hash index status information, including the number of each type of operation performed, and adaptive hash index performance.
  • LOG: InnoDB log information, including current log sequence number, how far the log has been flushed to disk, the position at which InnoDB last took a checkpoint, pending writes and write performance statistics.
  • BUFFER POOL AND MEMORY: Information on buffer pool pages read and written, which allows you to see the number of data file I/O operations performed by your queries. See InnoDB Buffer Pool for more. Similar information is also available from the INFORMATION_SCHEMA.INNODB_BUFFER_POOL_STATS table.
  • ROW OPERATIONS:Information about the main thread, including the number and performance rate for each type of row operation.

Here's an in-depth explanation of the output from SHOW ENGINE INNODB STATUS:

If there have been any deadlocks, this section will provide details about them.

Example Output Breakdown

mysql> SHOW ENGINE INNODB STATUS\G
*************************** 1. row ***************************
Type: InnoDB
Name:
Status:
=====================================
2024-01-01 00:00:00 0x7f4d84010700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 60 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 122 srv_active, 0 srv_shutdown, 101 srv_idle
srv_master_thread log flush and writes: 0
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 453715
OS WAIT ARRAY INFO: signal count 516588
Mutex spin waits 0, rounds 3198565, OS waits 132545
RW-shared spins 20039, rounds 192281, OS waits 16307
RW-excl spins 10134, rounds 138953, OS waits 4040
------------
TRANSACTIONS
------------
Trx id counter 3242342354
Purge done for trx's n:o < 3242342342 undo n:o < 0 state: running but idle
History list length 8
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 3242342353, ACTIVE 2 sec
2 lock struct(s), heap size 376, 1 row lock(s)
MySQL thread id 12, OS thread handle 140724674610944, query id 325 localhost root update
update t1 set a=10 where b=20
---TRANSACTION 3242342352, not started
0 lock struct(s), heap size 376, 0 row lock(s)
MySQL thread id 11, OS thread handle 140724674736128, query id 324 localhost root init
show engine innodb status
--------
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
79479 OS file reads, 1067 OS file writes, 867 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 0, seg size 2, 1 merges
merged operations:
insert 1, delete mark 0, delete 0
discarded operations:
insert 0, delete mark 0, delete 0
Hash table size 276707, node heap has 1 buffer(s)
0.00 hash searches/s, 0.00 non-hash searches/s
---
LOG
---
Log sequence number 39493902
Log flushed up to 39493902
Pages flushed up to 39493902
Last checkpoint at 39493902
0 pending log flushes, 0 pending chkp writes
268 log i/o's done, 0.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 137363456; in additional pool allocated 0
Total memory allocated by read views 264
Internal hash tables (constant factor + variable factor)
Adaptive hash index 10485864 (10485760 + 104)
Page hash 277432 (buffer pool 0 only)
Dictionary cache 2235313 (2219384 + 15929)
File system 1048560 (812272 + 235288)
Lock system 3333280 (3329360 + 3920)
Recovery system 0 (0 + 0)
Buffer pool size 8191
Free buffers 7999
Database pages 191
Old database pages 0
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 0, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 191, created 0, written 0
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
0 read views open inside InnoDB
Main thread process no. 275, id 140724674533056, state: sleeping
Number of rows inserted 0, updated 1, deleted 0, read 0
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

 

Breakdown of Output:

 Initial Information 

===================================== 2024-01-01 00:00:00 0x7f4d84010700 INNODB MONITOR OUTPUT =====================================
  • Timestamp: The time at which the SHOW ENGINE INNODB STATUS command was executed.
  • Thread ID: The identifier of the thread producing the output. 
  • Per second average
Per second averages calculated from the last 60 seconds
  • Averages: Performance metrics averaged over the last 60 seconds.  
  • Background Thread
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 122 srv_active, 0 srv_shutdown, 101 srv_idle
srv_master_thread log flush and writes: 0

  • Background Thread Loops: Counts of the different states of the master thread (active, shutdown, idle).
  • Log flushes and writes: How many times the logs were flushed and written.
    •  Semaphores

    ----------
    SEMAPHORES
    ----------
    OS WAIT ARRAY INFO: reservation count 453715
    OS WAIT ARRAY INFO: signal count 516588
    Mutex spin waits 0, rounds 3198565, OS waits 132545
    RW-shared spins 20039, rounds 192281, OS waits 16307
    RW-excl spins 10134, rounds 138953, OS waits 4040
    The SEMAPHORES section of the SHOW ENGINE INNODB STATUS output provides detailed information about the internal locking mechanisms (semaphores) used by InnoDB to ensure data consistency and manage concurrent access to the database. Here's an explanation of each line:

    1. OS WAIT ARRAY INFO: reservation count 453715

    • reservation count: This indicates the total number of times threads have had to wait for a resource. A higher count may indicate contention for resources, suggesting potential performance bottlenecks.

    2. OS WAIT ARRAY INFO: signal count 516588

    • signal count: This represents the total number of times threads were woken up after waiting for a resource. This value being higher than the reservation count suggests that threads are being efficiently woken up once resources become available.

    3. Mutex spin waits 0, rounds 3198565, OS waits 132545

    • Mutex spin waits: Number of times threads have attempted to acquire a mutex but found it already locked and had to "spin" (i.e., repeatedly check) until it became available. Here, the count is 0, indicating no spins.
    • rounds: Number of spin rounds. A higher number indicates more time spent in spin-wait loops, potentially leading to higher CPU usage.
    • OS waits: Number of times threads had to sleep and wait for a mutex to become available. This usually happens when spinning is not enough to acquire the mutex. High OS wait counts can indicate contention issues.

    4. RW-shared spins 20039, rounds 192281, OS waits 16307

    • RW-shared spins: Number of times threads attempted to acquire a read-write lock in shared (read) mode but had to spin.
    • rounds: Number of spin rounds for shared locks.
    • OS waits: Number of times threads had to sleep and wait for a read-write lock in shared mode to become available.

    5. RW-excl spins 10134, rounds 138953, OS waits 4040

    • RW-excl spins: Number of times threads attempted to acquire a read-write lock in exclusive (write) mode but had to spin.
    • rounds: Number of spin rounds for exclusive locks.
    • OS waits: Number of times threads had to sleep and wait for a read-write lock in exclusive mode to become available.

    Interpretation

    • High reservation and signal counts: Indicate frequent contention and resource signaling. Frequent waits can affect performance.
    • High OS waits: Indicate that threads are often put to sleep, which can reduce throughput and increase response time.
    • Spin waits and rounds: High numbers can indicate CPU overhead due to threads busy-waiting for locks.

    ----------
    SEMAPHORES
    ----------
    OS WAIT ARRAY INFO: reservation count 1000000
    OS WAIT ARRAY INFO: signal count 1200000
    Mutex spin waits 0, rounds 5000000, OS waits 250000
    RW-shared spins 50000, rounds 450000, OS waits 30000
    RW-excl spins 20000, rounds 250000, OS waits 10000

    This would suggest:

    • High contention for resources.
    • Significant CPU usage due to spinning.
    • Threads frequently put to sleep and later woken up, indicating potential bottlenecks.

    Actionable Insights

    • Performance tuning: Optimize queries, indexes, and schema design to reduce contention.
    • Hardware upgrades: Consider adding more CPU cores or faster processors to handle spin-wait overhead.
    • Concurrency management: Use connection pooling and adjust InnoDB configuration parameters to better handle concurrent access.
     
    • Transactions
     ------------
    TRANSACTIONS
    ------------
    Trx id counter 3242342354
    Purge done for trx's n:o < 3242342342 undo n:o < 0 state: running but idle
    History list length 8
    LIST OF TRANSACTIONS FOR EACH SESSION:
    ---TRANSACTION 3242342353, ACTIVE 2 sec
    2 lock struct(s), heap size 376, 1 row lock(s)
    MySQL thread id 12, OS thread handle 140724674610944, query id 325 localhost root update
    update t1 set a=10 where b=20
    ---TRANSACTION 3242342352, not started
    0 lock struct(s), heap size 376, 0 row lock(s)
    MySQL thread id 11, OS thread handle 140724674736128, query id 324 localhost root init
    show engine innodb status

     

    The TRANSACTIONS section of the SHOW ENGINE INNODB STATUS output provides detailed information about the currently active transactions within the InnoDB storage engine. Here's a detailed explanation of each part:

    1. Trx id counter 3242342354

    • Trx id counter: This is the current transaction ID counter. Every transaction in InnoDB is assigned a unique transaction ID when it starts. This counter increments with each new transaction.

    2. Purge done for trx's n
    < 3242342342 undo n
    < 0 state: running but idle

    • Purge done for trx's n
      < 3242342342
      : Indicates that the purge process (which cleans up old, uncommitted transactions) has completed for transactions with IDs less than 3242342342.
    • undo n
      < 0
      : Indicates that there are no pending undo log records to be purged.
    • state: running but idle: The purge process is currently running but not actively purging any records at the moment.

    3. History list length 8

    • History list length: This represents the number of unpurged transactions in the history list. A longer history list can indicate that the purge process is falling behind, which might affect performance.

    4. LIST OF TRANSACTIONS FOR EACH SESSION:

    This section lists detailed information about each active transaction. Each transaction block contains:

    Transaction 1:

    • ---TRANSACTION 3242342353, ACTIVE 2 sec:
      • 3242342353: Transaction ID.
      • ACTIVE 2 sec: The transaction has been active for 2 seconds.
    • 2 lock struct(s), heap size 376, 1 row lock(s):
      • 2 lock struct(s): The number of lock structures held by the transaction.
      • heap size 376: The amount of memory allocated for these lock structures.
      • 1 row lock(s): The number of rows locked by this transaction.
    • MySQL thread id 12, OS thread handle 140724674610944, query id 325 localhost root update:
      • MySQL thread id 12: The ID of the MySQL thread handling this transaction.
      • OS thread handle 140724674610944: The handle of the operating system thread.
      • query id 325: The ID of the current query being executed.
      • localhost root update: The user (root) and host (localhost) executing the query, along with the query type (update).
    • update t1 set a=10 where b=20: The current query being executed by the transaction.

    Transaction 2:

    • ---TRANSACTION 3242342352, not started:
      • 3242342352: Transaction ID.
      • not started: The transaction has been created but not started yet.
    • 0 lock struct(s), heap size 376, 0 row lock(s):
      • 0 lock struct(s): No lock structures are held by the transaction.
      • heap size 376: Memory allocated for lock structures (though none are currently held).
      • 0 row lock(s): No rows are locked by this transaction.
    • MySQL thread id 11, OS thread handle 140724674736128, query id 324 localhost root init:
      • MySQL thread id 11: The ID of the MySQL thread handling this transaction.
      • OS thread handle 140724674736128: The handle of the operating system thread.
      • query id 324: The ID of the current query being executed.
      • localhost root init: The user (root) and host (localhost) executing the query, along with the query type (init, indicating initialization).
    • show engine innodb status: The current query being executed by the transaction.

     Eg.

    ----------
    TRANSACTIONS
    ------------
    Trx id counter 3242342354
    Purge done for trx's n:o < 3242342342 undo n:o < 0 state: running but idle
    History list length 8
    LIST OF TRANSACTIONS FOR EACH SESSION:
    ---TRANSACTION 3242342353, ACTIVE 2 sec
    2 lock struct(s), heap size 376, 1 row lock(s)
    MySQL thread id 12, OS thread handle 140724674610944, query id 325 localhost root update
    update t1 set a=10 where b=20
    ---TRANSACTION 3242342352, not started
    0 lock struct(s), heap size 376, 0 row lock(s)
    MySQL thread id 11, OS thread handle 140724674736128, query id 324 localhost root init
    show engine innodb status
     

    Analysis

    1. Trx id counter: The next transaction ID to be assigned is 3242342354.
    2. Purge status: The purge process has cleaned up transactions up to ID 3242342342.
    3. History list length: There are 8 transactions in the history list that have not yet been purged.
    4. Active transactions:
      • Transaction 3242342353:
        • Has been active for 2 seconds.
        • Holds 2 lock structures, has allocated 376 bytes of memory for locks, and has locked 1 row.
        • Being executed by MySQL thread ID 12, with OS thread handle 140724674610944.
        • Currently executing an update query: update t1 set a=10 where b=20.
      • Transaction 3242342352:
        • Not started.
        • Holds no lock structures.
        • Being executed by MySQL thread ID 11, with OS thread handle 140724674736128.
        • Currently executing: show engine innodb status.

    Conclusion

    Understanding the TRANSACTIONS section helps in diagnosing issues related to transaction handling, locking, and 
    resource contention in MySQL. By analyzing this information, you can identify potential performance bottlenecks 
    and take appropriate actions to optimize transaction management in your database.
    • File I/O
    --------
    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
    79479 OS file reads, 1067 OS file writes, 867 OS fsyncs
    0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s

  • I/O Threads: State of I/O threads handling reads, writes, and log requests.
  • Pending I/O Operations: Number of pending asynchronous I/O operations.
  • File I/O Statistics: Counts of file reads, writes, and fsyncs, and their rates per second.


    • Insert Buffer and Adaptive Hash Index
     -------------------------------------
    INSERT BUFFER AND ADAPTIVE HASH INDEX
    -------------------------------------
    Ibuf: size 1, free list len 0, seg size 2, 1 merges
    merged operations:
    insert 1, delete mark 0, delete 0
    discarded operations:
    insert 0, delete mark 0, delete 0
    Hash table size 276707, node heap has 1 buffer(s)
    0.00 hash searches/s, 0.00 non-hash searches/s


  • Insert Buffer (Ibuf): Details about the size and operations of the insert buffer.
  • Adaptive Hash Index: Size and searches per second.
  •  
    • Log
     ---
    LOG
    ---
    Log sequence number 39493902
    Log flushed up to 39493902
    Pages flushed up to 39493902
    Last checkpoint at 39493902
    0 pending log flushes, 0 pending chkp writes
    268 log i/o's done, 0.00 log i/o's/second


  • Log Sequence Number (LSN): Various LSNs indicating the progress of log writes and flushes.
  • Log I/O Operations: Number of log I/O operations done.
  •  
    • Buffer Pool and Memory
     ----------------------
    BUFFER POOL AND MEMORY
    ----------------------
    Total memory allocated 137363456; in additional pool allocated 0
    Total memory allocated by read views 264
    Internal hash tables (constant factor + variable factor)
    Adaptive hash index 10485864 (10485760 + 104)
    Page hash 277432 (buffer pool 0 only)
    Dictionary cache 2235313 (2219384 + 15929)
    File system 1048560 (812272 + 235288)
    Lock system 3333280 (3329360 + 3920)
    Recovery system 0 (0 + 0)
    Buffer pool size 8191
    Free buffers 7999
    Database pages 191
    Old database pages 0
    Modified db pages 0
    Pending reads 0
    Pending writes: LRU 0, flush list 0, single page 0
    Pages made young 0, not young 0
    0.00 youngs/s, 0.00 non-youngs/s
    Pages read 191, created 0, written 0
    0.00 reads/s, 0.00 creates/s, 0.00 writes/s
    Buffer pool hit rate 1000 / 1000


  • Total Memory: Allocated memory for various components of InnoDB.
  • Buffer Pool Size and Usage: Number of pages in the buffer pool, free buffers, database pages, and their read/write statistics.
  • Hit Rate: Indicates how often InnoDB is able to find a page in the buffer pool rather than reading it from disk
    • Row Operations 
    --------------
    ROW OPERATIONS
    --------------
    0 queries inside InnoDB, 0 queries in queue
    0 read views open inside InnoDB
    Main thread process no. 275, id 140724674533056, state: sleeping
    Number of rows inserted 0, updated 1, deleted 0, read 0
    0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s


  • Current Query and Read Views: Number of active queries and read views.
  • Row Operation Statistics: Counts of row operations (insert, update, delete, read) and their rates per second.
  •  

    Key Points to Focus On

    • Transactions: Identify long-running transactions and their impact.
    • Semaphores: High semaphore waits can indicate contention.
    • Buffer Pool: Check the buffer pool hit rate and memory allocation to ensure efficient caching.
    • File I/O: Monitor pending I/O operations to detect bottlenecks.
    • Log: Ensure logs are being flushed properly to avoid data loss.
    This output provides a comprehensive view of InnoDB's internal workings, allowing you to identify 
    performance bottlenecks, contention, and potential issues affecting the database's stability.

     


     

     

    No comments:

    Basics of Kubernetes

     Kubernetes, often abbreviated as K8s , is an open-source platform designed to automate the deployment, scaling, and management of container...