Shulou(Shulou.com)06/01 Report--

Show engine innodb status interpretation

Note: the following is based on the personal understanding of the innodb status part of "High performance mysql third Edition" and "mysql Technology Insider innodb Storage engine". If there are any mistakes, please correct them!

Innodb storage engine in show engine innodb status (the old version corresponds to show innodb status) output, in addition to a lot of internal information, its output is a separate string, no rows and columns, the content is divided into many small segments, each piece of information corresponding to different parts of the innodb storage engine, some of which is very useful for innodb developers, but a lot of information, if you try to understand And when applied to high-performance innodb tuning, you will find them very interesting and even necessary.

The output contains statistics on averages that are statistics since the last time the output was generated, so if you are checking these values, make sure that you have waited for at least 30 seconds. Make the accumulation between the two samples long enough and sample multiple times to check the counter changes to figure out its behavior. Not all outputs will be generated at one point in time. So not all displayed averages are recalculated at the same time interval. Moreover, innodb has an internal reset interval, which is unpredictable and varies from version to version.

This output is enough to manually calculate most of the statistics you want, and there is a monitoring tool innotop that can help you calculate incremental differences and averages. Next, click show engine innodb status; on your mysql command line to look at the output and follow the steps below to understand what the output means step by step:

Note: the following uses the mysql5.5.24 version to interpret, mysql5.6.x and 5.7.x output has been adjusted in some places.

1. The first paragraph is the header information, which simply declares the beginning of the output, including the current date and time, and the amount of time that has elapsed since the last output.

= =

160129 12:07:26 INNODB MONITOR OUTPUT # the second line is the current date and time

= =

The fourth line of Per second averages calculated from the last 24 seconds # shows the time interval between calculating this average, that is, the time since the last output, or the time since the last internal reset.

two。 Starting with innodb1.0.x, you can use the command show engine innodb status; to view the status information of master thread:

-

BACKGROUND THREAD

-

Srv_master_thread loops: 30977173 1_second, 30975685 sleeps, 3090359 10_second, 166112 background, 165988 flush # this line shows that the main loop performed 30977,173 1_second times, the suspended operations performed 30975685 sleeps times per second (indicating that the load was not very heavy), the 10-second activity carried out 3090359 10_second times, the 1-second cycle and 10-second cycle ratio conformed to the 1-second cycle and 10-second cycle ratio 166112 background times, flush loop performed 165,988 flush times, if on a very stressful mysql You may see that the proportion of runs per second and hangs is less than 1, this is because innodb has made some internal optimizations, when the pressure is high, the interval time does not always wait for 1 second, therefore, it cannot be considered that the values of cycles and hangs per second are always the same, in some cases, the difference between the two can be used to compare and reflect the load pressure of the current database.

Srv_master_thread log flush and writes: 31160103

3. If you have a highly concurrent workload, you should pay attention to the next section (SEMAPHORES semaphore), which contains two kinds of data: an event counter and an optional list of current waiting threads. If there is a performance bottleneck, you can use this information to identify the bottleneck. Unfortunately, it is a bit complicated to know how to use this information. Here are some explanations:

-

SEMAPHORES

-

OS WAIT ARRAY INFO: reservation count 68581015, signal count 218437328

-- Thread 140653057947392 has waited at btr0pcur.c line 437 for 0.00 seconds the semaphore:

S-lock on RW-latch at 0x7ff536c7d3c0 created in file buf0buf.c line 916

A writer (thread id 140653057947392) has reserved it in mode exclusive

Number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0sel.c line 3097

Last time write locked in file / usr/local/src/soft/mysql-5.5.24/storage/innobase/buf/buf0buf.c line 3151

-- Thread 140653677291264 has waited at btr0pcur.c line 437 for 0.00 seconds the semaphore:

S-lock on RW-latch at 0x7ff53945b240 created in file buf0buf.c line 916

A writer (thread id 140653677291264) has reserved it in mode exclusive

Number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0sel.c line 3097

Last time write locked in file / usr/local/src/soft/mysql-5.5.24/storage/innobase/buf/buf0buf.c line 3151

Mutex spin waits 1157217380, rounds 1783981614, OS waits 10610359

RW-shared spins 103830012, rounds 1982690277, OS waits 52051891

RW-excl spins 43730722, rounds 602114981, OS waits 3495769

Spin rounds per wait: 1.54 mutex, 19.10 RW-shared, 13.77 RW-excl

There are a lot of contents, which are explained in turn in the following paragraphs:

3.1.

OS WAIT ARRAY INFO: reservation count 68581015, signal count 218437328 # this line gives information about the operating system wait array, which is an array of slots in which innodb reserves slots for semaphores that the operating system uses to signal threads so that threads can continue to run to do what they are waiting to do. This line also shows how many operating system waits innodb uses: retention statistics (reservation count) show the frequency of innodb allocation slots, while signal counting (signal count) measures how often threads get signals through an array, and operating system waits are more expensive than idle waits (spin wait).

3.2.

-- Thread 140653057947392 has waited at btr0pcur.c line 437 for 0.00 seconds the semaphore:

S-lock on RW-latch at 0x7ff536c7d3c0 created in file buf0buf.c line 916

A writer (thread id 140653057947392) has reserved it in mode exclusive

Number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0sel.c line 3097

Last time write locked in file / usr/local/src/soft/mysql-5.5.24/storage/innobase/buf/buf0buf.c line 3151

-- Thread 140653677291264 has waited at btr0pcur.c line 437 for 0.00 seconds the semaphore:

S-lock on RW-latch at 0x7ff53945b240 created in file buf0buf.c line 916

A writer (thread id 140653677291264) has reserved it in mode exclusive

Number of readers 0, waiters flag 1, lock_word: 0

Last time read locked in file row0sel.c line 3097

Last time write locked in file / usr/local/src/soft/mysql-5.5.24/storage/innobase/buf/buf0buf.c line 3151

This section shows the innoDB threads currently waiting for mutexes. Here you can see that there are two threads waiting, each with-- Thread has waited.... At first, this paragraph should normally be empty (that is, it is not available when viewing), unless the server is running a highly concurrent workload, prompting innodb to take steps to keep the operating system waiting, unless you are familiar with innodb source code. Otherwise, the most useful information you can see here is the name of the code file / usr/local/src/soft/mysql-5.5.24/storage/innobase/buf/buf0buf.c line 3151 where the thread wait occurs.

What is the hot spot inside the innodb? For example, if you see many threads waiting on a file called buf0buf.c, it means that there are

The buffer pool competes, and this output also shows how long these threads have been waiting, where waiters flag shows how many are waiting for the same mutex. If waiters flag is 0, no thread is waiting for the same mutex (wait is ending may be seen after waiters flag 0, indicating that the mutex has been released, but the operating system has not scheduled the thread to run).

You may wonder what innodb is really waiting for. Innodb uses mutexes and semaphores to protect critical areas of code, such as limiting only one thread to enter the critical section at a time, or restricting writes when there is an active read. There are many critical sections in innodb code that can all be there under the right conditions, and it is common to see when you gain access to buffer pool paging.

3.3.

Some of the information after the wait thread is as follows, which shows more event counters, and in each case, you can see how often innodb relies on the operating system to wait:

Mutex spin waits 1157217380, rounds 1783981614, OS waits 10610359 # this line shows several counters related to mutexes

RW-shared spins 103830012, rounds 1982690277, OS waits 52051891 # this line shows the counters of shared locks for read and write

RW-excl spins 43730722, rounds 602114981, OS waits 3495769 # this line shows read-write exclusive lock counters

Spin rounds per wait: 1.54 mutex, 19.10 RW-shared, 13.77 RW-excl

Innodb has a multi-stage wait strategy. First, it tries to idle the lock, and if it does not succeed after a preset idle wait cycle (setting the innodb_sync_spin_loops configuration variable command), it will fall back into a more expensive and complex wait array.

Idle waits are relatively cheap, but they constantly check to see if a resource is locked, which consumes CPU cycles, but this is not as bad as it sounds, because when processors are waiting for IO, there are generally some idle CPU cycles available, and idle waits are cheaper than other ways, even if there are no idle CPU cycles. However, idle waiting also monopolizes CPU when another thread can do something.

The alternative to idling waiting is to let the operating system do context switching, so that while one thread is waiting, another thread can be run, and then wake up the sleeping thread by waiting for the semaphore in the array to signal. It is more effective to send signals through semaphores, but context switching is expensive, which will soon add up. Thousands of switches per second can cause a lot of system overhead.

You can try to strike a balance between idling and operating system waits by changing the value of innodb_sync_spin_loops. Don't worry about idling waits unless you see hundreds of thousands of idling waits in a second. At this point, you can consider the performance_ schema library or show engine innodb mutex; to view the relevant information.

4. The following foreign key error message generally does not appear, unless there is a foreign key error on your server, sometimes the problem is that the transaction looks for a parent or child table when inserting, updating or deleting a record, and sometimes when innodb tries to add or delete a foreign key or modify an existing foreign key, it is found that the types of tables do not match This part of the output is very helpful for debugging the exact cause of foreign key errors that are ambiguous with innodb. Let's take a look at an example:

4.1 create a parent table:

Mysql > create table parent (parent_id int not null,primary key (parent_id)) engine=innodb

4.2 create a child table:

Mysql > create table child (child_id int not null,key child_id (child_id), constraint i_child foreign key (child_id) references parent (parent_id)) engine=innodb

4.3 insert data:

Mysql > insert into parent (parent_id) values (1)

Mysql > insert into child (child_id) values (1)

4.5 there are two basic foreign key errors:

The first: adding, updating, and deleting data in a way that may violate foreign key constraints will result in the first type of error, such as the following error when deleting a row in the parent table:

Mysql > delete from parent

ERROR 1451 (23000): Cannot delete or update a parent row: a foreign key constraint fails (`xiaoboluo`.`child`, CONSTRAINT `i_ child` FOREIGN KEY (`child_ id`) REFERENCES `parent` (`parent_ id`))

The error message is quite clear, and you will see a similar message for all errors caused by adding, deleting, and updating mismatched rows. Here is the output of show engine innodb status:

-

LATEST FOREIGN KEY ERROR

-

160128 1:17:06 Transaction: # this line shows the date and time of the last foreign key error

TRANSACTION D203D6, ACTIVE 0 sec updating or deleting

Mysql tables in use 1, locked 1

4 lock struct (s), heap size 1248, 2 row lock (s), undo log entries 1

MySQL thread id 20027, OS thread handle 0x7f0a4c0f8700, query id 1813996 localhost root updating

Delete from parent

Foreign key constraint fails for table `xiaoboluo`.`child`:

, # the above section shows the details of transactions that break foreign key constraints. The latter section shows the exact data that innodb was trying to modify when the error was found, and much of the output is row data converted to printable format.

CONSTRAINT `i_ child`FOREIGN KEY (`child_ id`) REFERENCES `parent` (`parent`)

Trying to delete or update in parent table, in index `PRIMARY` tuple:

DATA TUPLE: 3 fields

0: len 4; hex 80000001; asc

1: len 6; hex 000000d203d6; asc

2: len 7; hex 1e000001ca0110; asc

But in child table `xiaoboluo`.`child`, in index `child_ id`, there is a record:

PHYSICAL RECORD: n_fields 2; compact format; info bits 0

0: len 4; hex 80000001; asc

1: len 6; hex 000013a99b3e; asc >

4.6 second: errors that occur when trying to modify the table structure of the parent table are less clear, which may make debugging more difficult:

Mysql > alter table parent modify parent_id int unsigned not null

ERROR 1025 (HY000): Error on rename of'. / xiaoboluo/#sql-b695_4e3b' to'. / xiaoboluo/parent' (errno: 150)

View the show engine innodb status output information:

-

LATEST FOREIGN KEY ERROR

-

160128 1:32:33 Error in foreign key constraint of table xiaoboluo/child:

There is no index in referenced table which would contain

The columns as the first columns, or the data types in the

Referenced table do not match the ones in table. Constraint:

CONSTRAINT "i_child" FOREIGN KEY ("child_id") REFERENCES "parent" ("parent_id")

The index in the foreign key in table is "child_id"

See http://dev.mysql.com/doc/refman/5.5/en/innodb-foreign-key-constraints.html

For correct foreign key definition.

InnoDB: Renaming table `xiaoboluo`. To `xiaoboluo`.`parent` failed!

The above error is that the data type does not match, and the foreign key column must have exactly the same data type, including any modifiers (for example, here the parent table adds an extra unsigned, which is also the problem). When you see the 1025 error and do not understand why, it is best to check innodb status. Each time you see a new error, the foreign key error message is rewritten, and the pt-fk-error-logger tool in percona toolkit can save this information in a table for later analysis.

5. Like foreign key errors, this section occurs only when the server produces a deadlock, and the deadlock information is also rewritten every time there is a new deadlock error. The pt-deadlock-logger tool in percona toolkit can use a table to save this information for later analysis.

Deadlock is a loop in the waiting diagram, that is, a data structure that locks a row is waiting for another lock. The loop can be arbitrarily large. Innodb will immediately detect the deadlock, because whenever there is a transaction waiting for a row lock, it will check whether there is a loop in the waiting diagram. The situation of deadlock may be more complicated, but this section only shows the last two deadlocks. The last statement they execute in their respective transactions and the information that they form a ring lock in the waiting diagram. You don't see any other transactions in this loop, or you may not see the statements that actually acquired the lock earlier in the transaction, but you can usually determine what caused the deadlock by looking at the output.

There are actually two kinds of deadlocks in innodb, the first one that is often encountered, which is a real loop in the waiting diagram, and the other is that in a waiting diagram, it is too expensive to detect whether it contains a loop. If innodb checks more than 100W locks in the diagram, or if innodb redoes more than 200 transactions during the check, it will give up. It is also announced that there is a deadlock, and these values are constants hard-coded in the innodb code that cannot be configured (if you can modify the code and recompile it if you NB). The second deadlock error you can see a message in the output: TOO DEEP OR LONG SEARCH IN THE LOCK TABLE WAITS-FOR GRAPH

Innodb prints not only the locks held and waited by the transaction, but also the record itself. Unfortunately, it may exceed the length reserved for the output (only 1m can be printed and only the last deadlock information can be retained). If you can't see the complete output, you can create an innodb_monitor or innodb_lock_ monitor table under any library. In this way, the innodb status information is complete and recorded in the error log every 15s. For example, create table innodb_monitor (an int) engine=innodb;, can delete this table when it does not need to be recorded in the error log.

5.1 take a look at the following example:

5.1.1 create tables:

Mysql > create table test_deadlock (id int unsigned not null primary key auto_increment,test int unsigned not null)

Query OK, 0 rows affected (0.02 sec)

5.1.2 insert test data:

Mysql > insert into test_deadlock (test) values (1), (2), (3), (4), (5)

Query OK, 5 rows affected (0.00 sec)

Records: 5 Duplicates: 0 Warnings: 0

Open two session terminals:

5.1.3 session 1 executes the following SQL:

Mysql > set autocommit=0

Query OK, 0 rows affected (0.00 sec)

Mysql > select * from test_deadlock where id=1 for update

+-+ +

| | id | test |

+-+ +

| | 1 | 1 |

+-+ +

1 row in set (0.00 sec)

5.1.4 then session 2 executes the following SQL:

Mysql > set autocommit=0

Query OK, 0 rows affected (0.00 sec)

Mysql > select * from test_deadlock where id=2 for update

+-+ +

| | id | test |

+-+ +

| | 2 | 2 |

+-+ +

1 row in set (0.00 sec)

5.1.5 when you go back to session 1 and execute the following SQL, a wait occurs:

Mysql > select * from test_deadlock where id=2 for update

5.1.6 go back to session 2 and execute the following SQL, resulting in a deadlock, and session 2 is rolled back:

Mysql > select * from test_deadlock where id=1 for update

ERROR 1213 (40001): Deadlock found when trying to get lock; try restarting transaction

5.2 View innodb status information:

-

LATEST DETECTED DEADLOCK

-

160128 1:51:53 # this shows the date and time of the last deadlock

* * (1) TRANSACTION:

TRANSACTION D20847, ACTIVE 141 sec starting index read

Mysql tables in use 1, locked 1

LOCK WAIT 3 lock struct (s), heap size 376,2 row lock (s)

MySQL thread id 20027, OS thread handle 0x7f0a4c0f8700, query id 1818124 localhost root statistics

Select * from test_deadlock where id=2 for update

* * (1) WAITING FOR THIS LOCK TO BE GRANTED:

RECORD LOCKS space id 441 page no 3 n bits 72 index `PRIMARY` of table `xiaoboluo`.`test _ lock`trx id D20847 lock_mode X locks rec but not gap waiting

Record lock, heap no 3 PHYSICAL RECORD: n_fields 4; compact format; info bits 0

0: len 4; hex 00000002; asc

1: len 6; hex 000000d20808; asc

2: len 7; hex ad000001ab011d; asc

3: len 4; hex 00000002; asc

* * (2) TRANSACTION:

TRANSACTION D20853, ACTIVE 119 sec starting index read

Mysql tables in use 1, locked 1

3 lock struct (s), heap size 1248, 2 row lock (s)

MySQL thread id 20081, OS thread handle 0x7f0a0f020700, query id 1818204 localhost root statistics

Select * from test_deadlock where id=1 for update

(2) HOLDS THE LOCK (S):

RECORD LOCKS space id 441 page no 3 n bits 72 index `PRIMARY` of table `xiaoboluo`.`test _ lock`trx id D20853 lock_mode X locks rec but not gap

Record lock, heap no 3 PHYSICAL RECORD: n_fields 4; compact format; info bits 0

0: len 4; hex 00000002; asc

1: len 6; hex 000000d20808; asc

2: len 7; hex ad000001ab011d; asc

3: len 4; hex 00000002; asc

* * (2) WAITING FOR THIS LOCK TO BE GRANTED:

RECORD LOCKS space id 441 page no 3 n bits 72 index `PRIMARY` of table `xiaoboluo`.`test _ lock`trx id D20853 lock_mode X locks rec but not gap waiting

Record lock, heap no 2 PHYSICAL RECORD: n_fields 4; compact format; info bits 0

0: len 4; hex 00000001; asc

1: len 6; hex 000000d20808; asc

2: len 7; hex ad000001ab0110; asc

3: len 4; hex 00000001; asc

* WE ROLL BACK TRANSACTION (2)

There is a lot of content in this part, which is explained one by one in the following paragraphs:

5.2.1 the following section shows information about the first transaction of the deadlock:

* * (1) TRANSACTION:

TRANSACTION D20847, ACTIVE 141 sec starting index read

Mysql tables in use 1, locked 1

LOCK WAIT 3 lock struct (s), heap size 376,2 row lock (s)

MySQL thread id 20027, OS thread handle 0x7f0a4c0f8700, query id 1818124 localhost root statistics

Select * from test_deadlock where id=2 for update

TRANSACTION D20847 sec sec: this line indicates that the transaction D20847 is active and 141s active index read indicates that the data rows are being read using the index

The line mysql tables in use 1, locked transactions indicates that transaction D20847 is using 1 table, and there are 1 tables involving locks

LOCK WAIT 3 lock struct (s), heap size 376,2 row lock (s) # this line indicates that you are waiting for 3 locks, occupying 376bytes of memory, involving two rows of records. If the transaction has locked several rows of data, there will be a row of information showing the number of locking structures (note that this is different from row locks) and heap size, which refers to the amount of memory used to hold these row locks. Innodb uses a special bit chart to implement row locks. Theoretically, it can represent each locked row as a bit. Tests show that each lock is usually no more than 4 bits.

MySQL thread id 20027, OS thread handle 0x7f0a4c0f8700, query id 1818124 localhost root statistics # this line represents the thread ID information, operating system handle information, connection source, user of the transaction

Select * from test_deadlock where id=2 for update # this line indicates the SQL involved in the transaction

5.2.2 the following section shows information such as the lock that the first transaction is waiting for when the deadlock occurs:

* * (1) WAITING FOR THIS LOCK TO BE GRANTED: # this line indicates that the first transaction is waiting for the lock to be granted

RECORD LOCKS space id 441 page no 3 n bits 72 index `PRIMARY` of table `xiaoboluo`.`test _ lock`trx id D20847 lock_mode X locks rec but not gap waiting

Record lock, heap no 3 PHYSICAL RECORD: n_fields 4; compact format; info bits 0

0: len 4; hex 00000002; asc

1: len 6; hex 000000d20808; asc

2: len 7; hex ad000001ab011d; asc

3: len 4; hex 00000002; asc

RECORD LOCKS space id 441 page no 3 n bits 72 index `PRIMARY` of table `xiaoboluo`.`test _ lock`lock`lock D20847 lock_mode X locks rec but not gap waiting# this line of information indicates that the waiting lock is a record lock, the space id is 441and the page number is 3, probably located at 72 bits of the page, and the lock occurs on the primary key of the table xiaoboluo.test_deadlock, which is an X lock, but not gap lock. Waiting says he is waiting for a lock.

Record lock, heap no 3 PHYSICAL RECORD: n_fields 4; compact format; info bits 0 # this line indicates the heap no location of the record lock

The rest of this section is useful only for debugging.

0: len 4; hex 00000002; asc

1: len 6; hex 000000d20808; asc

2: len 7; hex ad000001ab011d; asc

3: len 4; hex 00000002; asc

5.2.3 the following section is the status of transaction 2:

* * (2) TRANSACTION:

TRANSACTION D20853, ACTIVE 119 sec starting index read # transaction 2 is active 119s

Mysql tables in use 1, locked 1 # is using 1 table and 1 table involving locks

3 lock struct (s), heap size 1248, 2 row lock (s) # involves 3 locks, 2 lines of records

MySQL thread id 20081, OS thread handle 0x7f0a0f020700, query id 1818204 localhost root statistics

Select * from test_deadlock where id=1 for update # SQL of the second transaction

5.2.4 the following section is the holding lock information for transaction 2:

(2) HOLDS THE LOCK (S):

RECORD LOCKS space id 441 page no 3 n bits 72 index `PRIMARY` of table `xiaoboluo`.`test _ lock`trx id D20853 lock_mode X locks rec but not gap

Record lock, heap no 3 PHYSICAL RECORD: n_fields 4; compact format; info bits 0

0: len 4; hex 00000002; asc

1: len 6; hex 000000d20808; asc

2: len 7; hex ad000001ab011d; asc

3: len 4; hex 00000002; asc

RECORD LOCKS space id 441 page no 3 n bits 72 index `PRIMARY` of table `xiaoboluo`.`test _ lock`trx id D20853 lock_mode X locks rec but not gap

Record lock, heap no 3 PHYSICAL RECORD: n_fields 4; compact format; info bits 0 # is the lock that transaction 1 is waiting for, judging from the debugging information behind these two lines of holding lock information.

5.2.5 the following part is the lock that transaction 2 is waiting for. From the following information, you are waiting for the same table, the same index, and the record lock X lock on the same page, but the heap no location is different, that is, the lock on different rows:

* * (2) WAITING FOR THIS LOCK TO BE GRANTED:

RECORD LOCKS space id 441 page no 3 n bits 72 index `PRIMARY` of table `xiaoboluo`.`test _ lock`trx id D20853 lock_mode X locks rec but not gap waiting

Record lock, heap no 2 PHYSICAL RECORD: n_fields 4; compact format; info bits 0

0: len 4; hex 00000001; asc

1: len 6; hex 000000d20808; asc

2: len 7; hex ad000001ab0110; asc

3: len 4; hex 00000001; asc

* WE ROLL BACK TRANSACTION (2) # this means that transaction 2 is rolled back, because the rollback cost of the two transactions is the same, so the later committed transaction is selected for rollback. If the rollback cost of the two transactions is different (the number of undo is different), then the transaction with the least overhead is rolled back.

When a transaction holds locks needed by other transactions and wants to acquire locks held by other transactions, there is a loop on the waiting diagram. Innodb does not show all held and waiting locks, but it shows enough information to help you determine which indexes are being used by the query operation, which is of great value in determining whether deadlocks can be avoided.

If you can make two queries scan the same index in the same direction, you can reduce the number of deadlocks, because queries do not create loops when they request locks in the same order, which is sometimes easy to do. for example, to update many records in a transaction, you can sort them by the primary key in the application's memory, and then update them to the database in the same order In this way, there will be no deadlock, but at other times, this method will not work (if two processes operate on the same table using different index intervals).

6. The following section contains some summary information about innodb transactions, followed by a list of currently active transactions, such as:

-

TRANSACTIONS

-

Trx id counter 4E0132AD

Purge done for trx's n:o

< 4E01090B undo n:o < 0 History list length 1853 LIST OF TRANSACTIONS FOR EACH SESSION: ---TRANSACTION 4E0131D3, not started MySQL thread id 26208218, OS thread handle 0x7fec7c582700, query id 5274800318 10.207.162.69 gdsser ---TRANSACTION 4E01323F, not started MySQL thread id 26208217, OS thread handle 0x7fec7c1b3700, query id 5274800938 10.207.162.69 gdsser .................... ---TRANSACTION 4E0132AC, ACTIVE 0 sec preparing 2 lock struct(s), heap size 376, 1 row lock(s), undo log entries 1 MySQL thread id 26208200, OS thread handle 0x7fec567e0700, query id 5274801557 10.207.162.69 gdsser commit ---TRANSACTION 4E0110E7, ACTIVE 188 sec mysql tables in use 1, locked 0 MySQL thread id 26208154, OS thread handle 0x7fec7c235700, query id 5274800671 10.143.90.228 root Sending data SELECT /*!40001 SQL_NO_CACHE */ * FROM `m_flowskillpoint` Trx read view will not see trx with id >

= 4E0110E8, sees

< 4E0108EE ---TRANSACTION 4E0108EF, ACTIVE 233 sec fetching rows mysql tables in use 1, locked 0 MySQL thread id 26208131, OS thread handle 0x7fec578e3700, query id 5274801341 10.143.90.228 root Sending data SELECT /*!40001 SQL_NO_CACHE */ * FROM `m_flowsilver` Trx read view will not see trx with id >

= 4E0108F0, sees

< 4E0108EC ---TRANSACTION 4E0108EE, ACTIVE 233 sec fetching rows mysql tables in use 1, locked 0 MySQL thread id 26208132, OS thread handle 0x7fec7c78a700, query id 5274797797 10.143.90.228 root Sending data SELECT /*!40001 SQL_NO_CACHE */ * FROM `m_flowmail` Trx read view will not see trx with id >

= 4E0108EF, sees

< 4E0108EC 这部分内容比较多，下面分段逐一进行解释： 6.1. Trx id counter 4E0132AD #这行表示当前事务ID，这是一个系统变量，每创建一个新事务都会增加 Purge done for trx's n:o < 4E01090B undo n:o < 0 #这是innodb清除旧MVCC行时所用的事务ID，将这个值和当前事务ID进行比较，就可以知道有多少老版本的数据未被清除。这个数字多大才可以安全的取值没有硬性和速成的规定，如果数据没做过任何更新，那么一个巨大的数字也不意味着有未清除的数据，因为实际上所有事务在数据库里查看的都是同一个版本的数据（此时只是事务ID在增加，而数据没有变更），另一方面，如果有很多行被更新，那每一行就会有一个或多个版本留在内存里，减少此类开销的最好办法就是确保事务已完成就立即提交，不要让它长时间地处于打开状态，因为一个打开的事务即使不做任何操作，也会影响到innodb清理旧版本的行数据。 undo n:o < 0这个是innodb清理进程正在使用的撤销日志编号，为0 0时说明清理进程处于空闲状态。 History list length 1853 #历史记录的长度，即位于innodb数据文件的撤销空间里的页面的数目，如果事务执行了更新并提交，这个数字就会增加，而当清理进程移除旧版本数据时，它就会减少，清理进程也会更新Purge done for.....这行中的数值。 6.2. 头部信息之后就是一个事务列表，当前版本的mysql还不支持嵌套事务，因此，在某个时间点上，每个客户端连接能够拥有的事务数量是有一个上限的，而且每一个事务只能属于单一连接（即一个事务只能使用单个线程执行，不能使用多个线程）。在输出信息里，每一个事务至少占有两行内容，如： ---TRANSACTION 4E0131D3, not started #每个事务的第一行以事务的ID和状态开始，not started表示这个事务已经提交并且没有再发起影响事务的语句，可能刚好空闲 MySQL thread id 26208218, OS thread handle 0x7fec7c582700, query id 5274800318 10.207.162.69 gdsser#然后每个事务的第二行是一些线程等信息，MySQL thread id 部分和是hi用show full processlist;命令看到的id列相同。紧随其后的是一个内部查询id和一些连接信息，这些信息同样与show full processlist中的输出相同。 ---TRANSACTION 4E01323F, not started MySQL thread id 26208217, OS thread handle 0x7fec7c1b3700, query id 5274800938 10.207.162.69 gdsser 6.3. 上面是not started状态的事务信息，下面来看看为ACTIVE状态的事务信息： ---TRANSACTION 4E0110E7, ACTIVE 188 sec #这行显示次事务处于活跃状态已经188s，可能的所有状态有not started，active，prepared和committed in memory，一旦事务日志落盘了就会变成not started状态。在时间后面会显示出当前事务正在做什么（在这里为空没有显示出来），在源代码中有超过30个字符串常量可以显示在时间后面，如：fetching，preparing，rows，adding foreign keys等等 mysql tables in use 1, locked 0 #该事务用到的表数和涉及表锁的表数，Innodb一般不会锁定表，但对有些语句会锁定，如果mysql服务器在高于innodb层之上将表锁定，这里也是能够显示出来的，如果事务已经锁定了几行数据，这里将会有一行信息显示出锁定结构的数目（注意，这跟行锁是两回事）和和堆大小，如：2 lock struct(s), heap size 376, 1 row lock(s), undo log entries 1，堆的大小指的是为了持有这些行锁而占用的内存大小，Innodb是用一种特殊的位图表来实现行锁的，从理论上讲，它可将每一个锁定的行表示为一个比特，经测试显示，每个锁通常不超过4比特。 MySQL thread id 26208154, OS thread handle 0x7fec7c235700, query id 5274800671 10.143.90.228 root Sending data #与show processlist输出结果大部分相同 SELECT /*!40001 SQL_NO_CACHE */ * FROM `m_flowskillpoint` #如果事务正在运行一个查询，那么这里就会显示事务涉及的SQL，注意：有些版本可能只显示其中一小段，而不是完整的SQL Trx read view will not see trx with id >

The line = 4E0110E8, sees < 4E0108EE # shows the read view of the transaction, which shows the scope of the ID for both visible and invisible transactions due to versioning. Here, there is a transaction gap between the two numbers, in which transactions may not be visible. When innodb executes the query, it also checks the visibility of the rows where the transaction ID happens to be in this gap.

Note: if the transaction is waiting for a lock, you will see the lock information after the query SQL text. In the deadlock example above, you have seen a lot of this information. Unfortunately, the output does not say which other transaction the lock is being held by, but you can find this through the three tables innodb_trx,innodb_lock_waits,innodb_locks under the information_ schema library. If there are many transactions in the output message, innodb may limit the number of transactions to be printed so that the output information does not grow too much. Truncated... Hint.

The 7.FILE I _ peg O section shows the status of the I _ map O worker thread, as well as the status of the performance counter, as shown below:

-

FILE I/O

-

Waiting for O thread 0 state: waiting for iAccord o request (insert buffer thread) # insert buffer thread

Waiting for O thread 1 state: waiting for iUnip o request (log thread) # log thread

I thread 2 state: waiting for I request (read thread)

I thread 3 state: waiting for I request (read thread)

Waiting for O thread 4 state: waiting for iUnip o request (read thread)

Doing file O thread 5 state: doing file iUnip o (read thread) ev set # and above are the default 4 read thread

Waiting for O thread 6 state: waiting for iUnip o request (write thread)

Waiting for O thread 7 state: waiting for iUnip o request (write thread)

Waiting for O thread 8 state: waiting for iUnip o request (write thread)

I thread 9 state: waiting for I request (write thread) # and above are the default 4 write thread

Pending normal aio reads: 128 [0,0,0,128], aio writes: 0 [0,0,0,0], # number of pending operations on read thread and write thread, etc. Aio means asynchronous Imax O

Ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0 # insert buffer thread number of pending fsync () operations, etc.

Pending flushes (fsync) log: 0; buffer pool: 0 # log thread number of pending fsync () operations, etc.

The line 146246831 OS file reads, 760501349 OS file writes, 247143684 OS fsyncs # shows the number of read, write, and fsync () calls executed. These absolute values may vary under your machine environment load, so it is more important to monitor how they have changed over time.

1 pending preads, 0 pending pwrites # this line shows the number of read and write operations currently pending

145.49 reads/s, 783677 avg bytes/read, 28.75 writes/s, 10.67 fsyncs/s # this line shows the average per second over the time period shown in the header (referring to the time in part 1).

Note: the values of statistics for three lines of pending read / write threads, buffer pool threads, and log threads are a good way to detect applications where Imax O is limited, if most of these Imax O have pending operations, then the load may be Imax O limited. In the linux system, use the parameters: innodb_read_io_threads and innodb_write_io_threads to configure the number of read and write threads, the default is 4 threads.

Insert buffer thread: responsible for insert buffer merging, for example, records are merged from insert buffer to tablespace

Log thread: responsible for brushing transaction logs asynchronously

Read thread: perform a pre-read operation to try to read the data needed by innodb premonition in advance

Write thread: refresh the dirty page buffer

8. This section shows the state of the structure of the insert buffer and adaptive hash index parts

-

INSERT BUFFER AND ADAPTIVE HASH INDEX

-

Ibuf: size 12, free list len 27559, seg size 27572, 18074934 merges # this line shows information about size (size 12 represents the number of pages that have been merged), free list (which represents the length of the free list in the insert buffer), and seg size size (seg size 27572 shows the length of the current insert buffer, with a size of about 27572*16K=440M). 18074934 merges represents the number of merge inserts

The line of information insert,delete mark,delete under the tag merged operations: # indicates how many insert buffer,delete buffer,purge buffer have been merged by the merge operation.

Insert 81340470, delete mark 8893610, delete 818579

A line of information under the tag discarded operations: # indicates that the table has been deleted when merge occurs in change buffer, so there is no need to merge records into the secondary index.

Insert 0, delete mark 0, delete 0

Hash table size 87709057, node heap has 10228 buffer (s) # this line shows the status of self-using hash indexes, where Hash table size 87709057 represents the size of AHI and node heap has 10228 buffer (s) indicates AHI usage

1741.05 hash searches/s, 539.48 non-hash searches/s # this line shows how many hash indexing operations per second Innodb completed during the time mentioned in part 1 of the header, 1741.05 hash searches/s indicates the use of AHI search per second, and 539.48 non-hash searches/s indicates no use of AHI search per second (because hash indexes can only be used for equivalent queries, while range queries, fuzzy queries cannot use hash indexes.) The efficiency of hash indexing can be known by the ratio of hash searches to non-hash searches. The ratio of hash index lookup to non-hash index lookup is for reference only. Adaptive hash index cannot be configured, but you can choose whether this feature is needed through the parameter innodb_adaptive_hash_index=ON | OFF.

Note:

Innodb has introduced change buffer since 1.0.x, which can be regarded as an upgrade of insert buffer. From this version, innodb can buffer all DML operations (insert,delete,update). They are insert buffer,delete buffer,purge buffer, of course, like the previous insert buffer, the applicable object of change buffer is still the secondary index of a non-unique index. Because there is no update buffer, the operation of update on a record can be divided into two processes:

A: Mark the record for deletion

B: actually delete the record

Therefore, the delete buffer corresponds to the first process of the update operation, that is, the record is marked as deleted, and the purge buffer corresponds to the second process of update, which is about to record the real deletion.

9. This section shows statistics about the innodb transaction log (redo log) subsystem:

-

LOG

-

Log sequence number 1351392990515 # this line shows the log sequence number generated by the current latest data

Log flushed up to 1351392989504 # this line shows where the log has been refreshed (down to the log sequence number in the transaction log)

Last checkpoint at 1351373900020 # this line shows the location of the last checkpoint (a checkpoint indicates the moment when a data and log file are in a consistent state and can be used to recover data). If the last checkpoint lags too much behind the previous line and the difference is close to the size of the transaction log file, Innodb will trigger a "crazy brush", which is very bad for performance.

The line 0 pending log writes, 0 pending chkp writes # shows the current pending log read and write operations. You can compare the value of this line with the corresponding value of part 7 FILE I and O to see how much of your FILE O is caused by the log system.

286879989 log i/o's done, 15.92 log i/o's/second # this line shows the statistics of log operations and the number of log I picks O per second. You can compare the value of this line with the corresponding value of part 7 FILE FILE O to see how much of your Imax O is caused by the logging system.

9. This section shows statistics about the innodb buffer pool and how it uses memory:

9.1.

--

BUFFER POOL AND MEMORY

--

Total memory allocated 45357793280 The line in additional pool allocated 0 # shows the total memory allocated by innodb, and how much of it is allocated by the additional memory pool, which allocates only a small portion of the memory, allocated by the internal memory allocator. The current version of innodb generally uses the operating system's memory allocator, but the older version uses its own, because some operating systems at that time did not provide a very good memory allocation implementation.

Dictionary memory allocated 12681573

Buffer pool size 2705015 # the next four lines starting from this line show buffer pool metrics in pages, which include the total buffer pool size, the number of free pages, the number of pages allocated to store database pages, and the number of dirty database pages. This line shows the total number of pages in the buffer pool, that is, 2705015016K, with a total of 43G buffer pools

Free buffers 5 # this line shows the number of free pages in the buffer pool

Database pages 2694782 # this line shows the number of pages allocated to store database pages, that is, the number of pages in the LRU list, including young sublist and old sublist

Old database pages 994651 # this line shows the number of old sublist partial pages in LRU

Modified db pages 10610 # this line shows the number of dirty database pages

Pending reads 128 # this line shows the number of pending reads

Pending writes: LRU 0, flush list 0, single page 0 # this line shows the number of pending writes

# Note that the pending read and write operations here do not match the value of the FILE I FILE O part, because Innodb may merge many logical read and write operations into a physical Imax O operation. LRU represents the recently used number of hangs, which is a way to free up space for frequently used pages by flushing pages that are not frequently used in the buffer. The flushing list flush list stores the number of old pages that need to be washed by checkpoint processing, and the number of single-page single page suspended (single page writes are separate page writes and will not be merged).

Pages made young 3014373561, not young 0 # this line shows the number of times the page in the LRU list was moved to the head of LRU, because the server did not reach the innodb_old_blocks_time threshold at run time, so not young is 0

6960.42 youngs/s, 0.00 non-youngs/s # indicates the number of young and non-youngs operations per second

Pages read 2946570833, created 43450158, written 574214278 # this line shows how many pages innodb was read, created, and written. The value of read / write pages refers to data read from disk to buffer pool, or written to disk from buffer pool. Creating pages refers to pages that innodb allocates in the buffer pool but does not read content from data files, because it does not care what the content is (for example, they may belong to a deleted table)

6960.54 reads/s, 4.42 creates/s, 9.33 writes/s # this line shows the number of read,create,write pages per second corresponding to the above line

Buffer pool hit rate 1000 / 1000, young-making rate 45 / 1000 not 0 / 1000 # this line shows the hit ratio of the buffer pool, which is used to measure the percentage of pages innodb found in the buffer pool, and it measures the hit rate since the last Innodb status output to this output, so if the server has been quiet since then, you will see No buffer pool page gets since the last printout. It is not useful for measuring the size of the cache pool.

Pages read ahead 6928.54Universe, evicted without access 8.21Universe, Random read ahead 0.00Univer # this line shows the number of pages per second that are pre-read and randomly read

LRU len: 2694782, unzip_LRU len: 0 # innodb1.0.x start to support the compression of the page function, the original 16K page compressed into 1K Magi 2K 4K Magi 8K, and because the page size has changed, the LRU list has also changed, for non-16K pages, is managed through the unzip_LRU list, you can see that unzip_LRU len is 0 means that there is no use of compressed pages.

I/O sum [60790]: cur [30], unzip sum [0]: cur [0]

For tables that compress pages, the compression ratio of each table may be different. There may be some tables with a page size of 8K or a page size of 2K. How does unzip_LRUs allocate memory from the cache pool?

First, the pages with different compressed page sizes are managed separately in the unzip_LRU list, and secondly, memory is allocated through the partner algorithm, for example, the page size of 4K needs to be requested from the cache pool, the process is as follows:

A: check the unzip_LRU list of 4K to see if there are free pages available

B: if so, use it directly.

C: if not, check the unzip_LRU list of 8K

D: if you can get free pages, divide the pages into two 4K pages and store them in the 4K unzip_LRU list

E: if you can't get free pages, apply for a 16K page from the LRU list, divide the page into one 8K page and two 4K pages, and store them in the unzip_LRU list corresponding to their respective sizes.

Note: it may occur that the sum of Free buffers and Database pages is not equal to Buffer pool size, because the pages in the buffer pool will be assigned to adaptive hash index, lock information, insert buffer, etc., and this part of the page does not need to be maintained by the LRU algorithm, so it is not in the LRU list.

9.2. If innodb buffer pool uses the parameter innodb

If more than 1 buffer pool instance is set for _ buffer_pool_instances=num, the innodb_buffer_pool_size=xxx will be divided equally into num shares according to this parameter. The information of each copy is similar to the following, and the content of this section is similar to that of section 9.1, so I won't say any more.

--

INDIVIDUAL BUFFER POOL INFO

--

-BUFFER POOL 0

Buffer pool size 541003

Free buffers 1

Database pages 538965

Old database pages 198933

Modified db pages 2190

Pending reads 128

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

Pages made young 603372180, not young 0

1441.81 youngs/s, 0.00 non-youngs/s

Pages read 589705199, created 8703138, written 116954697

1441.61 reads/s, 0.75 creates/s, 1.83 writes/s

Buffer pool hit rate 955 / 1000, young-making rate 45 / 1000 not 0 / 1000

Pages read ahead 1436.98/s, evicted without access 0.87/s, Random read ahead 0.00/s

LRU len: 538965, unzip_LRU len: 0

I/O sum [12158]: cur [6], unzip sum [0]: cur [0]

-BUFFER POOL 1

Buffer pool size 541003

Free buffers 1

Database pages 538959

Old database pages 198931

Modified db pages 2025

Pending reads 0

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

Pages made young 602366394, not young 0

1481.35 youngs/s, 0.00 non-youngs/s

Pages read 588738997, created 8708171, written 113209540

1480.56 reads/s, 0.83 creates/s, 1.92 writes/s

Buffer pool hit rate 958 / 1000, young-making rate 42 / 1000 not 0 / 1000

Pages read ahead 1473.73/s, evicted without access 1.96/s, Random read ahead 0.00/s

LRU len: 538959, unzip_LRU len: 0

I/O sum [12158]: cur [6], unzip sum [0]: cur [0]

10. This section shows innodb statistics for other items:

-

ROW OPERATIONS

-

The line 0 queries inside InnoDB, 0 queries in queue # shows how many threads are in the innodb kernel and how many threads are in the queue. The queries in the queue are threads that innodb does not run into the kernel in order to limit the number of threads that can execute concurrently. The query sleeps and waits before entering the queue.

5 read views open inside InnoDB # this line shows how many innodb read views are open. The read view is a MVCC snapshot of the database content containing the starting point of the transaction. You can see if a particular transaction has a read view in part 6 TRANSACTIONS.

Main thread process no. 4368, id 140653691242240, state: sleeping # this line shows the main thread status of the kernel

Number of rows inserted 3429012215, updated 153529675, deleted 112310240, read 3739562987410 # this line shows how many rows have been inserted, updated and deleted, read

428.52 inserts/s, 7.21 updates/s, 0.46 deletes/s, 1047933.92 reads/s # this line shows the average per second corresponding to the above line. If you want to see how much work innodb has in progress, then these two lines are good reference values.

-

END OF INNODB MONITOR OUTPUT # be aware that if you don't see this line of output, there may be a large number of transactions or a large deadlock that truncates the output

= =

Note: the possible state values for the main thread state of the kernel are as follows:

A:doing background drop tables

B:doing insert buffer merge

C:flushing buffer pool pages

D:making checkpoint

E:purging

F:reserving kernel mutex

G:sleeping

H:suspending

I:waiting for buffer pool flush to end

J:waiting for server activity

Welcome to subscribe "Shulou Technology Information " to get latest news, interesting things and hot topics in the IT industry, and controls the hottest and latest Internet news, technology news and IT industry trends.