| 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: | |
| 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 11:24]
MySQL Verification Team
Hello zhang xiaojian, Thank you for the report. Verified as described with 8.0.18 source build. Thanks, Umesh
[11 Dec 2019 11:27]
MySQL Verification Team
Test results - 8.0.18
Attachment: 97955_8.0.18.results (application/octet-stream, text), 4.64 KiB.
[11 Dec 2019 11:27]
MySQL Verification Team
I'll add 5.6/5.7 results later on this week.
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.