Bug #100968 count star transaction doesn't response to kill command
Submitted: 27 Sep 2020 6:54 Modified: 23 Oct 2020 14:37
Reporter: Brian Yue (OCA) Email Updates:
Status: Duplicate Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S2 (Serious)
Version:MySQL8.0.20, 8.0.21 OS:Any (rhel-7.4)
Assigned to: CPU Architecture:Any (intel x86)
Tags: Contribution

[27 Sep 2020 6:54] Brian Yue
Description:
Dear Verification team:
  Here I found a case, kill command doesn't works for `select count(*)` transaction. 

  (1) I execute `insert into t1 select * from f`, in which t is a big table.
  (2) After several minutes (maybe 1 or 2 minutes), I start a new session and execute `select count(*) from t1`.
  (3) Then after several seconds, start a new session to kill the `select count(*)` connection.
  (4) After I kill the `select count(*)` connection, the transaction still exists after 30 minutes, and goes on and on.
  Please reference `How to repeat` part for detail.

How to repeat:
[session 1]
mysql> use test_sj
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Database changed
mysql> show tables;
+---------------------+
| Tables_in_test_sj   |
+---------------------+
| user_card_info_hash |
+---------------------+
1 row in set (0.01 sec)

mysql> create table user_card_info_hash_1 like user_card_info_hash;
Query OK, 0 rows affected (0.11 sec)

mysql> begin;
Query OK, 0 rows affected (0.00 sec)

mysql> insert into user_card_info_hash_1 select * from user_card_info_hash;
# here is a big table, so it keeps executing for hours....

# after several minutes
[session 2]
mysql> select count(*) from user_card_info_hash_1;

# after several seconds
[session 3]
mysql> show processlist;
+-----+-----------------+-----------------+---------+---------+---------+------------------------+---------------------------------------------------------------------+
| Id  | User            | Host            | db      | Command | Time    | State                  | Info                                                                |
+-----+-----------------+-----------------+---------+---------+---------+------------------------+---------------------------------------------------------------------+
|   5 | system user     | connecting host | NULL    | Connect | 3295729 | Connecting to master   | NULL                                                                |
|  12 | event_scheduler | localhost       | NULL    | Daemon  | 3295729 | Waiting on empty queue | NULL                                                                |
| 198 | root            | localhost       | test_sj | Query   |      75 | executing              | select count(*) from user_card_info_hash_1                          |
| 199 | root            | localhost       | test_sj | Query   |    1156 | executing              | insert into user_card_info_hash_1 select * from user_card_info_hash |
| 201 | root            | localhost       | NULL    | Query   |       0 | starting               | show processlist                                                    |
+-----+-----------------+-----------------+---------+---------+---------+------------------------+---------------------------------------------------------------------+
5 rows in set (0.00 sec)

we can see that, `insert select` and `select count(*)` transaction are all working

now kill the `select count(*)` connection.
mysql> kill 198;
Query OK, 0 rows affected (0.00 sec)

mysql> show processlist;
+-----+-----------------+-----------------+---------+---------+---------+------------------------+---------------------------------------------------------------------+
| Id  | User            | Host            | db      | Command | Time    | State                  | Info                                                                |
+-----+-----------------+-----------------+---------+---------+---------+------------------------+---------------------------------------------------------------------+
|   5 | system user     | connecting host | NULL    | Connect | 3295738 | Connecting to master   | NULL                                                                |
|  12 | event_scheduler | localhost       | NULL    | Daemon  | 3295738 | Waiting on empty queue | NULL                                                                |
| 198 | root            | localhost       | test_sj | Killed  |      84 | executing              | select count(*) from user_card_info_hash_1                          |
| 199 | root            | localhost       | test_sj | Query   |    1165 | executing              | insert into user_card_info_hash_1 select * from user_card_info_hash |
| 201 | root            | localhost       | NULL    | Query   |       0 | starting               | show processlist                                                    |
+-----+-----------------+-----------------+---------+---------+---------+------------------------+---------------------------------------------------------------------+
5 rows in set (0.00 sec)

we can see that Command of the `select count(*)` transaction has changed to `Killed`

wait, wait, wait ...
after 30 minutes ...

mysql> show processlist;
+-----+-----------------+-----------------+---------+---------+---------+------------------------+---------------------------------------------------------------------+
| Id  | User            | Host            | db      | Command | Time    | State                  | Info                                                                |
+-----+-----------------+-----------------+---------+---------+---------+------------------------+---------------------------------------------------------------------+
|   5 | system user     | connecting host | NULL    | Connect | 3297528 | Connecting to master   | NULL                                                                |
|  12 | event_scheduler | localhost       | NULL    | Daemon  | 3297528 | Waiting on empty queue | NULL                                                                |
| 198 | root            | localhost       | test_sj | Killed  |    1874 | executing              | select count(*) from user_card_info_hash_1                          |
| 199 | root            | localhost       | test_sj | Query   |    2955 | executing              | insert into user_card_info_hash_1 select * from user_card_info_hash |
| 201 | root            | localhost       | NULL    | Query   |       0 | starting               | show processlist                                                    |
+-----+-----------------+-----------------+---------+---------+---------+------------------------+---------------------------------------------------------------------+
5 rows in set (0.00 sec)

so, after 30 minutes, the `select count(*)` are still working ...

Suggested fix:
fixed like this (In MySQL8.0.18 version, similar as MySQL8.0.21):

--- a/storage/innobase/row/row0pread.cc
+++ b/storage/innobase/row/row0pread.cc
@@ -502,6 +502,12 @@ dberr_t Parallel_reader::Ctx::traverse() {
     auto cur = pcur->get_page_cur();

     if (page_cur_is_after_last(cur)) {
+      // if interrupted, finish the job as early as possible
+      if (unlikely(trx_is_interrupted(m_scan_ctx->m_trx))) {
+        err = DB_INTERRUPTED;
+        break;
+      }
+
       mem_heap_empty(heap);
[6 Oct 2020 13:00] MySQL Verification Team
Hello Brian Yue,

Thank you for the report and supplying patch.
Please note that in order to submit contributions you must first sign the Oracle Contribution Agreement (OCA). More details are described in "Contributions" tab, please ensure to re-send the patch via that tab. Otherwise we would not be able to accept it.

regards,
Umesh
[6 Oct 2020 13:01] MySQL Verification Team
MySQL Server 8.0.21 test results

Attachment: 100968.results (application/octet-stream, text), 26.46 KiB.

[17 Oct 2020 14:22] Brian Yue
Basing on MySQL version 8.0.18

(*) I confirm the code being submitted is offered under the terms of the OCA, and that I am authorized to contribute it.

Contribution: bug100968_patch.txt (text/plain), 497 bytes.

[18 Oct 2020 5:44] MySQL Verification Team
Thank you for the contribution.

regards,
Umesh
[23 Oct 2020 14:37] Ståle Deraas
Thank you for your contribution! The bug is fixed in 8.0.22 but did not use your contribution.