Bug #103708 shutdown of replica takes too long if MTS worker waits for MDL lock
Submitted: 15 May 2021 7:32
Reporter: Shane Bester (Platinum Quality Contributor) Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: Replication Severity:S3 (Non-critical)
Version:8.0.23 OS:CentOS
Assigned to: CPU Architecture:x86

[15 May 2021 7:32] Shane Bester
Description:
Before shutdown there's a readonly transaction, and the processlist looks like:

mysql> show processlist;
+----+-----------------+-----------------+------+---------+------+----------------------------------------------------------+-----------------------+
| Id | User            | Host            | db   | Command | Time | State                                                    | Info                  |
+----+-----------------+-----------------+------+---------+------+----------------------------------------------------------+-----------------------+
|  5 | event_scheduler | localhost       | NULL | Daemon  |   53 | Waiting on empty queue                                   | NULL                  |
| 10 | system user     | connecting host | NULL | Connect |   44 | Waiting for source to send event                         | NULL                  |
| 11 | system user     |                 | NULL | Query   |    6 | Replica has read all relay log; waiting for more updates | NULL                  |
| 12 | system user     |                 |      | Query   |    6 | Waiting for table metadata lock                          | truncate table test.t |
| 13 | system user     |                 | NULL | Connect |   44 | Waiting for an event from Coordinator                    | NULL                  |
| 14 | system user     |                 | NULL | Connect |   44 | Waiting for an event from Coordinator                    | NULL                  |
| 15 | system user     |                 | NULL | Connect |   44 | Waiting for an event from Coordinator                    | NULL                  |
| 17 | root            | localhost:41746 | test | Query   |    0 | init                                                     | show processlist      |
+----+-----------------+-----------------+------+---------+------+----------------------------------------------------------+-----------------------+
8 rows in set (0.00 sec)

Check the gap in times:

2021-05-15T07:17:43.804191Z 10 [Note] [MY-011179] [Repl] Slave I/O thread: Start semi-sync replication to master 'root@127.0.0.1:3333' in log 'FIRST' at position 4.
2021-05-15T07:17:43.804291Z 10 [Warning] [MY-010897] [Repl] Storing MySQL user name or password information in the master info repository is not secure and is therefore not recommended. Please consider using the USER and PASSWORD connection options for START SLAVE; see the 'START SLAVE Syntax' in the MySQL Manual for more information.
2021-05-15T07:17:43.805150Z 10 [System] [MY-010562] [Repl] Slave I/O thread for channel '': connected to master 'root@127.0.0.1:3333',replication started in log 'FIRST' at position 4
2021-05-15T07:17:43.808861Z 11 [Note] [MY-010581] [Repl] Slave SQL thread for channel '' initialized, starting replication in log 'FIRST' at position 0, relay log './fc30-relay-bin.000001' position: 4
2021-05-15T07:18:35.830196Z 18 [System] [MY-013172] [Server] Received SHUTDOWN from user root. Shutting down mysqld (Version: 8.0.23-commercial).
2021-05-15T07:18:35.830929Z 0 [Note] [MY-010067] [Server] Giving 8 client threads a chance to die gracefully
2021-05-15T07:18:35.830997Z 0 [Note] [MY-010117] [Server] Shutting down slave threads
2021-05-15T07:18:35.831071Z 11 [Note] [MY-010596] [Repl] Error reading relay log event for channel '': slave SQL thread was killed
2021-05-15T07:18:50.907240Z 10 [Note] [MY-011026] [Repl] Slave I/O thread killed while reading event for channel ''.
2021-05-15T07:18:50.907320Z 10 [Note] [MY-010570] [Repl] Slave I/O thread exiting for channel '', read up to log 'binlog.000001', position 977
<<<<<<<<<< HERE >>>>>>>>>>>>>
2021-05-15T07:23:37.844046Z 0 [Note] [MY-010054] [Server] Event Scheduler: Killing the scheduler thread, thread id 5
2021-05-15T07:23:37.844147Z 0 [Note] [MY-010050] [Server] Event Scheduler: Waiting for the scheduler thread to reply
2021-05-15T07:23:37.844322Z 0 [Note] [MY-010048] [Server] Event Scheduler: Stopped
2021-05-15T07:23:39.844455Z 0 [Note] [MY-010118] [Server] Forcefully disconnecting 3 remaining clients
2021-05-15T07:23:39.844547Z 0 [Warning] [MY-010909] [Server] /home/anon/mysql/release/mysql-commercial-8.0.23-linux-glibc2.12-x86_64/bin/mysqld: Forcing close of thread 17  user: 'root'.
2021-05-15T07:23:39.844686Z 0 [Note] [MY-010043] [Server] Event Scheduler: Purging the queue. 0 events
2021-05-15T07:23:39.904027Z 11 [Note] [MY-010587] [Repl] Slave SQL thread for channel '' exiting, replication stopped in log 'binlog.000001' at position 977
2021-05-15T07:23:39.908870Z 0 [Note] [MY-012330] [InnoDB] FTS optimize thread exiting.
2021-05-15T07:23:40.581221Z 0 [Note] [MY-010120] [Server] Binlog end
---

How to repeat:
setup MTS master/slave with given my.cnf's.
On master create a table;
On slave read from table but do not commit transaction.
On master truncate table.
Shutdown slave - notice it takes long.

Suggested fix:
It would be acceptable to kill connections before the various *timeout* expires in the case of shutting down server, while there's read-only transactions.
[15 May 2021 7:33] MySQL Verification Team
also reproduced on current trunk:
(mysqld 8.0.27-tr)  (Built on 13 May 2021, commit b27e2c8c0c0093f7062dcac4bbd5855c60c6e33b with gcc (GCC) 10.3.1 20210422 (Red Hat 10.3.1-1)).