Bug #93572 parallel workers+slave_preserve_commit_order+flushtables with read lock deadlock
Submitted: 12 Dec 2018 11:37 Modified: 22 Jan 2:55
Reporter: ashe sun (OCA) Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: Locking Severity:S3 (Non-critical)
Version:5.7.18 OS:Any
Assigned to: CPU Architecture:Any

[12 Dec 2018 11:37] ashe sun
Description:
Description:
slave config:
mysql> show global variables like '%slave%'
    -> ;
+-------------------------------------------+-----------------------+
| Variable_name                             | Value                 |
+-------------------------------------------+-----------------------+
| init_slave                                |                       |
| log_slave_updates                         | ON                    |
| log_slow_slave_statements                 | ON                    |
| rpl_semi_sync_master_wait_for_slave_count | 1                     |
| rpl_semi_sync_master_wait_no_slave        | ON                    |
| rpl_semi_sync_slave_enabled               | OFF                   |
| rpl_semi_sync_slave_trace_level           | 32                    |
| rpl_stop_slave_timeout                    | 31536000              |
| slave_allow_batching                      | OFF                   |
| slave_checkpoint_group                    | 512                   |
| slave_checkpoint_period                   | 300                   |
| slave_compressed_protocol                 | OFF                   |
| slave_exec_mode                           | STRICT                |
| slave_load_tmpdir                         | /data/mysql/mysql_tmp |
| slave_max_allowed_packet                  | 1073741824            |
| slave_net_timeout                         | 30                    |
| slave_parallel_type                       | LOGICAL_CLOCK         |
| slave_parallel_workers                    | 16                    |
| slave_pending_jobs_size_max               | 16777216              |
| slave_preserve_commit_order               | ON                    |
| slave_rows_search_algorithms              | INDEX_SCAN,HASH_SCAN  |
| slave_skip_errors                         | OFF                   |
| slave_sql_verify_checksum                 | ON                    |
| slave_transaction_retries                 | 128                   |
| slave_type_conversions                    |                       |
| sql_slave_skip_counter                    | 0                     |
+-------------------------------------------+-----------------------+

dead lock:
mysql> show processlist;l
+----+-------------+-----------+--------------------+---------+------+--------------------------------------------------------+--------------------------------------------+
| Id | User        | Host      | db                 | Command | Time | State                                                  | Info                                       |
+----+-------------+-----------+--------------------+---------+------+--------------------------------------------------------+--------------------------------------------+
|  3 | root        | localhost | test_dead_lock     | Query   | 2264 | Waiting for commit lock                                | flush tables with read lock                |
|  4 | system user |           | NULL               | Connect | 2708 | Waiting for master to send event                       | NULL                                       |
|  5 | system user |           | NULL               | Connect | 2289 | Slave has read all relay log; waiting for more updates | NULL                                       |
|  6 | system user |           | NULL               | Connect | 2319 | Waiting for global read lock                           | insert into ashe(id,name) values(40,'aaa') |
|  7 | system user |           | NULL               | Connect | 2308 | Waiting for preceding transaction to commit            | NULL                                       |
|  8 | system user |           | NULL               | Connect | 2708 | Waiting for an event from Coordinator                  | NULL                                       |
|  9 | system user |           | NULL               | Connect | 2708 | Waiting for an event from Coordinator                  | NULL                                       |
| 10 | system user |           | NULL               | Connect | 2708 | Waiting for an event from Coordinator                  | NULL                                       |
| 11 | system user |           | NULL               | Connect | 2708 | Waiting for an event from Coordinator                  | NULL                                       |
| 12 | system user |           | NULL               | Connect | 2708 | Waiting for an event from Coordinator                  | NULL                                       |
| 13 | system user |           | NULL               | Connect | 2708 | Waiting for an event from Coordinator                  | NULL                                       |
| 14 | system user |           | NULL               | Connect | 2708 | Waiting for an event from Coordinator                  | NULL                                       |
| 15 | system user |           | NULL               | Connect | 2708 | Waiting for an event from Coordinator                  | NULL                                       |
| 16 | system user |           | NULL               | Connect | 2708 | Waiting for an event from Coordinator                  | NULL                                       |

deadlock:
flush tables with read lock --> thread 7 --> thread 6 --> flush tables with read lock

How to repeat:
Prepare your environment with master-slave replication and open parallel slave sql workers.

step 0
on master 
create table ashe(id int not null auto_increment primary key,name varchar(10));
create table delay_table(id int);

step1

1.1 Generate  2 transaction that can be apply on slave in parallel.
session1                                                               session2
set binlog_format=statement;                            set binlog_format=statement;
begin;                                                                   begin;
insert into tt select sleep(10);                            
insert into ashe values(40,'aaa');                       insert into ashe values(41,'aaa');
commit;                                                                commit

step 2
on slave
flush tables with read lock .

and then you will see that on slave instance.

mysql> show processlist;
+----+-------------+-----------+----------------+---------+------+--------------------------------------------------------+---------------------------------------+
| Id | User        | Host      | db             | Command | Time | State                                                  | Info                                  |
+----+-------------+-----------+----------------+---------+------+--------------------------------------------------------+---------------------------------------+
|  3 | root        | localhost | NULL           | Query   |   13 | Waiting for commit lock                                | flush  tables with read lock          |
| 22 | root        | localhost | NULL           | Query   |    0 | starting                                               | show processlist                      |
| 41 | root        | localhost | NULL           | Sleep   | 1493 |                                                        | NULL                                  |
| 48 | system user |           | NULL           | Connect |  688 | Waiting for master to send event                       | NULL                                  |
| 49 | system user |           | NULL           | Connect |   20 | Slave has read all relay log; waiting for more updates | NULL                                  |
| 50 | system user |           | test_dead_lock | Connect |   25 | Waiting for global read lock                           | insert into ashe(name) values('aaaa') |
| 51 | system user |           | NULL           | Connect |   33 | Waiting for preceding transaction to commit            | NULL                                  |
| 52 | system user |           | NULL           | Connect |  657 | Waiting for an event from Coordinator                  | NULL                                  |
Legal PoliciesYour Privacy Rig

Suggested fix:
-
[20 Dec 2018 14:24] Sinisa Milivojevic
Hi,

Thank you for your report.

I must admit that I fail to understand what is the problem here. Also, this issue is not related to the replication.

Our Reference Manual explains this in high detail. FTWRL prevents all the commits and holds a mutex for all MDLs, so what you see is expected behaviour. Just as described in our Reference Manual.

Simply, do not use that command, not even for backup, unless you are backing up MyISAM tables.
[20 Dec 2018 14:30] Sinisa Milivojevic
Also, please read already submitted reports, like the following ones:

* 16088
* 29427
* 46420
* 71169

There are also other feature requests along those lines.
[9 Jan 13:10] Sinisa Milivojevic
Hi,

Actually, it turns out that your report is a duplicate of one internal bug.

This internal bug is scheduled already, but our policy does not allow me to inform you of any further details.

In any case, when the bug is fixed, we shall inform you about it on this page.
[9 Jan 14:26] Sinisa Milivojevic
Meanwhile, we can inform you on the workaround available.

Workaround:
------------

Deadlock happens when Flush tables with read lock is issued
along with (Multi threaded slave with LOGICAL_CLOCK +
Slave_preserve_commit_order=ON).

One suggestion would be to STOP SLAVE SQL_THREAD before
starting the backup operation. With this Slave applier
threads will stop. Complete the backup.  Start the applier
threads by issuing START SLAVE SQL_THREAD.
[15 Jan 12:40] ashe sun
Sinisa Milivojevic

You are right,“FTWRL prevents all the commits and holds a mutex for all MDLs”  That is precise,But FTWRL thread should not be pendent.
The FTWRL thread has not owned commit lock in this case(Waiting for commit lock). 
If "I owned lock A,and I need to lock B; You owned lock B,and you need to lock A",Someone has to give up.And deadlock deadlock detection is working for this.

anyway,thanks for your cake.
[15 Jan 13:14] Sinisa Milivojevic
Hi,

Sorry, but you are wrong in your comment.

First of all, FTWRL MUST be pendent. That is how it is designed. It will be there and will hold the lock until UNLOCK TABLES is issued. That is how it works for the last 15 (fifteen) years and having in mind its purpose, like doing a backup of FRM and MyISAM files, that is how it must work. 

Next, deadlock detection is something that is done automatically within Innodb storage engine. Table-level locks (like FTWRL) and MDL locks are totally in the SQL layer, not in the InnoDB SE layer. Hence, it is up to the application programmer, sysadmin and DBA to design the system to work correctly. 

This is a reason why we have described all this behaviour in all details in our Reference Manual.
[22 Jan 2:55] ashe sun
Hi

Sorry,but there are also deadlock detection in the SQL layer:

sql/mdl.cc
MDL_context::acquire_lock()
	void MDL_context::find_deadlock()
		victim= dvisitor.get_victim();
[22 Jan 13:27] Sinisa Milivojevic
I agree with the change of category.