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 = sessions_view_3.user_id
AND events.timestamp = sessions_view_3.timestamp
AND events.kind = sessions_view_3.kind
SET events.session_id_3 = sessions_view_3.global_session_id_3
---TRANSACTION 422151665303832, not started
0 lock struct(s), heap size 1128, 0 row lock(s)
--------
FILE I/O
--------
I/O thread 0 state: waiting for completed aio requests (insert buffer thread)
I/O thread 1 state: waiting for completed aio requests (log thread)
I/O thread 2 state: waiting for completed aio requests (read thread)
I/O thread 3 state: waiting for completed aio requests (read thread)
I/O thread 4 state: waiting for completed aio requests (read thread)
I/O thread 5 state: waiting for completed aio requests (read thread)
I/O thread 6 state: waiting for completed aio requests (write thread)
I/O thread 7 state: waiting for completed aio requests (write thread)
I/O thread 8 state: waiting for completed aio requests (write thread)
I/O thread 9 state: waiting for completed aio requests (write thread)
Pending normal aio reads: [0, 0, 0, 0] , aio writes: [0, 0, 0, 0] ,
ibuf aio reads:, log i/o's:, sync i/o's:
Pending flushes (fsync) log: 0; buffer pool: 0
6622929 OS file reads, 239404 OS file writes, 8494 OS fsyncs
4944.03 reads/s, 16384 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 810, seg size 812, 1 merges
merged operations:
insert 0, delete mark 1, delete 0
discarded operations:
insert 0, delete mark 0, delete 0
Hash table size 34679, node heap has 0 buffer(s)
Hash table size 34679, node heap has 468 buffer(s)
Hash table size 34679, node heap has 0 buffer(s)
Hash table size 34679, node heap has 0 buffer(s)
Hash table size 34679, node heap has 0 buffer(s)
Hash table size 34679, node heap has 0 buffer(s)
Hash table size 34679, node heap has 0 buffer(s)
Hash table size 34679, node heap has 0 buffer(s)
143846.58 hash searches/s, 43181.66 non-hash searches/s
---
LOG
---
Log sequence number 43884780118
Log flushed up to 43884780118
Pages flushed up to 43884780118
Last checkpoint at 43884780109
0 pending log flushes, 0 pending chkp writes
2498 log i/o's done, 0.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total large memory allocated 167772160
Dictionary memory allocated 41208
Buffer pool size 8027
Free buffers 1
Database pages 5955
Old database pages 2194
Modified db pages 0
Percent of dirty pages(LRU & free pages): 0.000
Max dirty pages percent: 75.000
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 2123, not young 529215348
0.00 youngs/s, 504929.52 non-youngs/s
Pages read 6593275, created 201671, written 202463
4944.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 992 / 1000, young-making rate 0 / 1000 not 772 / 1000
Pages read ahead 21.33/s, evicted without access 21.00/s, Random read ahead 0.00/s
LRU len: 5955, unzip_LRU len: 0
I/O sum[237723]:cur[2426], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
0 read views open inside InnoDB
Process ID=1131, Main thread ID=140676039636736, state: sleeping
Number of rows inserted 0, updated 0, deleted 0, read 261938483
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 187028.15 reads/s
Number of system rows inserted 0, updated 0, 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
============================
The query
The query is updating a whole table, based on the results of a view that also reads the whole table. I have not found a more optimized way to do so.
UPDATE events
INNER JOIN sessions_view_3
ON events.user_id = sessions_view_3.user_id
AND events.timestamp = sessions_view_3.timestamp
AND events.kind = sessions_view_3.kind
SET events.session_id_3 = sessions_view_3.global_session_id_3;
CREATE VIEW sessions_view_3 AS
SELECT user_id, `timestamp`, kind,
SUM(is_new_session) OVER (ORDER BY user_id, `timestamp`) AS global_session_id_3,
SUM(is_new_session) OVER (PARTITION BY user_id ORDER BY `timestamp`) AS user_session_id_3
FROM (
SELECT *,
CASE WHEN
last_event_timestamp IS NULL OR
(page_type != 'theory' AND page_type != 'theory_section' AND exercise_id IS NOT NULL
AND NOT EXISTS(SELECT 1 FROM events e2
WHERE (session_id = e2.session_id
AND exercise_id = e2.exercise_id
AND e2.timestamp < timestamp)
OR (session_id = e2.session_id
AND last_event_exercise_id = e2.exercise_id
AND e2.timestamp > last_event_timestamp)
)
)
THEN 1 ELSE 0 END AS is_new_session
FROM (
SELECT *,
LAG(`timestamp`,1) OVER (PARTITION BY session_id ORDER BY `timestamp`) AS last_event_timestamp,
LAG(`exercise_id`,1) OVER (PARTITION BY session_id ORDER BY `timestamp`) AS last_event_exercise_id
FROM events
) e
) final
;
My conclusions
What seems good:
- The transaction appears to be running and active
- In ROW OPERATIONS, the total reads and reads/s keeps increasing / changing so it seems to be doing something
What seems odd:
- In ROW OPERATIONS says
state:sleeping - In ROW OPERATIONS says there are 0 queries in queue
- All threads are
waiting for completed aio requests, does this mean no thread is doing anything? - 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 fact that no process is using much memory. My total memory usage is only 6GB, and around 3 of them are used by PyCharm
UPDATE: adding top output
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
1131 mysql 20 0 2222320 389264 22700 S 100,0 1,2 422:15.44 mysqld
