Bug #97955 Multi 'show binary logs' statement may block transaction commit
Submitted: 11 Dec 2019 4:26 Modified: 11 Dec 2019 11:24
Reporter: zhang xiaojian Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: Replication Severity:S2 (Serious)
Version:5.6/5.7/8.0, 8.0.18 OS:Any
Assigned to: CPU Architecture:Any
Tags: block, show binary logs, transaction commit

[11 Dec 2019 4:26] zhang xiaojian
Description:
The statement 'show binary logs' would acquire LOCK_log and LOCK_index. The code is :

```cpp
bool show_binlogs(THD *thd)
{
  mysql_mutex_lock(mysql_bin_log.get_log_lock());    // lock LOCK_log
  mysql_bin_log.lock_index();                                        // lock LOCK_index
  index_file = mysql_bin_log.get_index_file();

  mysql_bin_log.raw_get_current_log(&cur);  
  mysql_mutex_unlock(mysql_bin_log.get_log_lock()); // unlock LOCK_log

  while ((length = my_b_gets(index_file, fname, sizeof(fname))) > 1){
     
     protocol->store()                // store information of index file
     if (protocol->end_row())    // Write to net buffer 
        ....
  }
  mysql_bin_log.unlock_index();      // unlock LOCK_index
  
}
```
The problem is if net buffer is used up,   protocol->end_row()  would wait until net packet received by client. That's depend on the net respond time.. Don't forget we still hold the  LOCK_index mutex.

If we got mutil  'show binary logs' statement,  the next one would acquire LOCK_log 
mutex first and wait for the LOCK_index mutex.

The worst thing is  all user transactions wait to acquire LOCK_log mutex in the flush stage of MYSQL_BIN_LOG::ordered_commit.

How to repeat:
Simulate the net blocking :

```cpp

  DBUG_EXECUTE_IF("simulate_network_blocking", sleep(50););
  if (protocol->end_row()) 
  ....

```

Session 1:
mysql> SET @@GLOBAL.DEBUG= '+d,simulate_network_blocking';
Query OK, 0 rows affected (0.00 sec)

mysql> show binary logs;

Session 2:
mysql> show binary logs;

Session 3:
mysql> insert into t values(10);
Query OK, 1 row affected (1 min 29.39 sec)

The insert statement cost 89.39 sec 

Suggested fix:
Use a local buffer store the result, release LOCK_index before write to the net.
[11 Dec 2019 11:24] Umesh Shastry
Hello zhang xiaojian,

Thank you for the report.
Verified as described with 8.0.18 source build.

Thanks,
Umesh
[11 Dec 2019 11:27] Umesh Shastry
Test results - 8.0.18

Attachment: 97955_8.0.18.results (application/octet-stream, text), 4.64 KiB.

[11 Dec 2019 11:27] Umesh Shastry
I'll add 5.6/5.7 results later on this week.