Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Incomplete
-
10.5.22
-
None
Description
Stop the database instance using mysqladmin shutdown,More than 24 hours without stopping.
Msyqld has been unable to stop and runs until "InnoDB: FTS optimize thread exiting”
2023-09-22 9:16:30 0 [Note] C:\Server\mysql\bin\mysqld.exe (initiated by: sysdba[sysdba] @ [127.0.0.1]): Normal shutdown
2023-09-22 9:16:30 0 [Note] Event Scheduler: Killing the scheduler thread, thread id 2
2023-09-22 9:16:30 0 [Note] Event Scheduler: Waiting for the scheduler thread to reply
2023-09-22 9:16:30 0 [Note] Event Scheduler: Stopped
2023-09-22 9:16:30 0 [Note] Event Scheduler: Purging the queue. 52 events
2023-09-22 9:16:30 0 [Note] InnoDB: FTS optimize thread exiting.
The information seen by ProcessMonitor has been undergoing flushbufferfile and readfile operations
Attachments
Issue Links
- relates to
-
-
- Closed
-
Activity
For the record, with the bench.sh inside adaptive_purge.tar.gz of MDEV-26356, I got a slow shutdown like this:
|
10.6 |
Version: '10.6.16-MariaDB' socket: '/mnt/sbtest/mysqld.sock' port: 3306 Source distribution
|
2023-09-27 17:06:47 0 [Note] /dev/shm/10.6g/sql/mariadbd (initiated by: root[root] @ localhost []): Normal shutdown
|
2023-09-27 17:06:47 0 [Note] InnoDB: FTS optimize thread exiting.
|
2023-09-27 17:06:47 0 [Note] InnoDB: to purge 26366271 transactions
|
2023-09-27 17:12:19 0 [Note] InnoDB: Starting shutdown...
|
2023-09-27 17:12:19 0 [Note] InnoDB: Dumping buffer pool(s) to /mnt/sbtest/ib_buffer_pool
|
2023-09-27 17:12:19 0 [Note] InnoDB: Buffer pool(s) dump completed at 230927 17:12:19
|
2023-09-27 17:12:19 0 [Note] InnoDB: Removed temporary tablespace data file: "./ibtmp1"
|
2023-09-27 17:12:19 0 [Note] InnoDB: Shutdown completed; log sequence number 73559731602; transaction id 173642215
|
2023-09-27 17:12:19 0 [Note] /dev/shm/10.6g/sql/mariadbd: Shutdown complete
|
This was with 12GiB of data in a 40GiB buffer pool but a tiny redo log compared to the workload (innodb_log_file_size=10g). As you can see, there was a message about the purge, but no further progress report for almost 6 minutes.
This reported case could also be due to a change buffer merge. At least here we always get a message about the purge of history.
The missing "to purge" messages should be a 10.6+ only problem. As far as I can tell, that was caused by the merge of MDEV-31382 from 10.5 to 10.6.
kennyliao, can you provide some stacktraces, as described in https://jira.mariadb.org/browse/MDEV-32247?focusedCommentId=270421&page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#comment-270421?
There already was a bug fix related to this:
MDEV-22577innodb_fast_shutdown=0 fails to report progressSpecific to 10.6 (not sure if it could affect 10.5), while debugging
MDEV-32050I noticed that there would be only one message at the start of slow shutdown, mentioning the number of rows of history that needs to be purged. After my test workload, purging the history would take 30 to 90 seconds.We still need some stack traces to understand what exactly is going on here.