HiveBrain v1.2.0
Get Started
← Back to all entries
snippetsqlMinor

How to understand the output of SHOW ENGINE INNODB STATUS. Is it actually doing something?

Submitted by: @import:stackexchange-dba··
0
Viewed 0 times
showenginetheinnodbdoingoutputstatusunderstandactuallyhow

Problem

I am running a query that I expect to take a long time although I got no idea how long. I found out about SHOW ENGINE INNODB STATUS but I am not sure whether it is actually doing something or maybe it is stuck somewhere. Here's what I've tried to find out:

System monitor:
By looking at the system monitor, I noticed the MySQL processes are not really using much memory nor CPU. However, I got 1 CPU at 100% continuously so some process is doing something although no progress on the list appears to be responsible for this. The db is 3GB and the query should be accessing pretty much all of it (24 million rows). Could it be that the resources are not shown on the mysql process but some sub-thread?

SHOW ENGINE INNODB STATUS \G

This is the output.

```
SHOW ENGINE INNODB STATUS \G
1. row
Type: InnoDB
Name:
Status:
=====================================
2023-04-23 12:53:09 0x7ff1c440c700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 33 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 98 srv_active, 0 srv_shutdown, 5181 srv_idle
srv_master_thread log flush and writes: 5279
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 2305
OS WAIT ARRAY INFO: signal count 2040
RW-shared spins 123, rounds 2059, OS waits 60
RW-excl spins 113, rounds 1833, OS waits 49
RW-sx spins 224, rounds 6342, OS waits 209
Spin rounds per wait: 16.74 RW-shared, 16.22 RW-excl, 28.31 RW-sx
------------
TRANSACTIONS
------------
Trx id counter 9498291
Purge done for trxs n:o < 9498290 undo n:o < 0 state: running
History list length 58
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 422151665308056, ACTIVE 1235 sec fetching rows
mysql tables in use 3, locked 3
209503 lock struct(s), heap size 26271864, 26067821 row lock(s)
MySQL thread id 39, OS thread handle 140676356118272, query id 127 localhost root Sending data
UPDATE events
INNER JOIN sessions_view_3
ON events.user_id

Solution

In ROW OPERATIONS says state:sleeping

The line about "state:sleeping" is referring to the InnoDB main thread, not the user threads that are running a query. The main thread runs a loop to do background tasks like flushing pages to disk. Sleeping is a normal state even if you have queries in progress on other threads.

Think of a bagpipe player, who must blow into the mouthpiece to keep the bag inflated, but this is asynchronous with respect to any notes he's playing on the pipe. There are times when the player can take a breath even during a note.

In ROW OPERATIONS says there are 0 queries in queue

It also shows zeroes in several other fields of that block.

You might be running SHOW ENGINE INNODB STATUS repeatedly? Keep in mind that some figures reported by this status are reset to 0 when you run the command. So if you run it in rapid succession, there isn't enough data since the last reset for it to recalculate rates and averages. So you get odd looking numbers sometimes. Look for the line near the top of the status output like "Per second averages calculated from the last 20 seconds". If the duration is like 0 or 1 seconds, I'd take the numbers with a grain of salt.

The InnoDB status monitor also resets itself every 20 seconds (IIRC) even if you're not querying the status, so the amount of status data can vary when you view it. The InnoDB monitor is not like a proper monitoring service like DataDog that keeps weeks of status values.

All threads are waiting for completed aio requests, does this mean no thread is doing anything?

It looks to like your system is quite busy. The string "waiting for completed aio requests" means it has aio requests in progress and it's waiting for one to complete.

The fact that you have many I/O threads occupied and waiting for I/O to complete tells me that it is indeed busy. If the threads were idle, they would say "waiting for i/o request".

I'm a bit surprised that your write threads are also occupied, although the line that shows the write I/O rate says "0.00 writes/s".

It make sense that you have low CPU activity, since the threads are waiting for I/O. Those two resources often have an inverse relationship. While waiting for I/O to complete, the CPU has nothing to do. And likewise if CPU is busy, it's likely that I/O is done.

You can use the top command (if your server is Linux) to view individual threads, and you can enable a column to show which CPU each thread is currently using. You can also open a display of individual CPU states. I'm not sure you're using Linux.

All tables and rows are locked. This is normal since the update, but I worry the update is locking the rows the view needs to read. Although I believe MySQL should first retrieve the data from the view, and then update.

The thread that acquired the lock can still read and write the row. You don't have a conflict if a subquery locked it. Stated another way, the thread owns the locks, not the query.

The fact that no process is using much memory. My total memory usage is only 6GB, and around 3 of them are used by PyCharm

It's probably creating large temp tables as a byproduct of the query. I'd guess multiple temp files for this query, because it's using a view, and also using window functions. If temp tables exceed tmp_table_size, they get spooled to disk. This could also account for the high rate of I/O.

Context

StackExchange Database Administrators Q#326313, answer score: 3

Revisions (0)

No revisions yet.