Skip to content

Commit f51a654

Browse files
abhinav04sharmaabhinav04sharma
committed
[mysql_raft] Adding a flag to delay auto binlog rotation when a raft purge is active
Summary: Purging logs in raft is very expensive because we read logs to find the last opid for every to-be-purged binlog. Ideally we should be storing this info in the index file like the prev gtid set but that is a big work item. Purge can cause stalls in the commit pipeline when auto rotation is triggered (current binlog goes beyond max_binlog_size). To quick fix added an atomic to indicate if a raft purge is active, if yes, we delay to auto rotate operation in group commit, avoiding stalls at the cost of slighly exceeding max_binlog_size. Test Plan: mtr Reviewers: arahut Reviewed By: arahut Subscribers: webscalesql-eng@fb.com Differential Revision: https://phabricator.intern.facebook.com/D40743288 Tasks: T130891182 (cherry picked from commit 002c1059a64aa42c037454f668e994f41831d267)
1 parent 474c6a7 commit f51a654

10 files changed

+188
-4
lines changed

‎mysql-test/r/mysqld--help-notwin.result‎

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -386,6 +386,11 @@ The following options may be given as the first argument:
386386
tables
387387
--default-week-format=#
388388
The default week format used by WEEK() functions
389+
--delay-auto-rotation-on-raft-log-purge
390+
On the leader, when raft logs are being purged delay
391+
automatic log rotation until purge is done even if we go
392+
a beyond the max binlog size.
393+
(Defaults to on; use --skip-delay-auto-rotation-on-raft-log-purge to disable.)
389394
--delay-key-write[=name]
390395
Type of DELAY_KEY_WRITE
391396
--delayed-insert-limit=#
@@ -3099,6 +3104,7 @@ default-table-encryption FALSE
30993104
default-time-zone (No default value)
31003105
default-tmp-storage-engine InnoDB
31013106
default-week-format 0
3107+
delay-auto-rotation-on-raft-log-purge TRUE
31023108
delay-key-write ON
31033109
delayed-insert-limit 100
31043110
delayed-insert-timeout 300

‎mysql-test/suite/rpl_raft/r/rpl_raft_delay_rotation_on_raft_log_purge.result‎

Lines changed: 52 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,52 @@
1+
include/raft_3_node.inc
2+
Warnings:
3+
Note #### Sending passwords in plain text without SSL/TLS is extremely insecure.
4+
Note #### 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.
5+
Warnings:
6+
Note #### Sending passwords in plain text without SSL/TLS is extremely insecure.
7+
Note #### 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.
8+
[connection master]
9+
include/rpl_connect.inc [creating server_4]
10+
include/rpl_connect.inc [creating server_5]
11+
show status like 'rpl_raft_role';
12+
Variable_name Value
13+
Rpl_raft_role LEADER
14+
show status like 'rpl_raft_role';
15+
Variable_name Value
16+
Rpl_raft_role FOLLOWER
17+
reset master;
18+
show status like 'rpl_raft_role';
19+
Variable_name Value
20+
Rpl_raft_role FOLLOWER
21+
reset master;
22+
FLUSH BINARY LOGS;
23+
FLUSH BINARY LOGS;
24+
FLUSH BINARY LOGS;
25+
FLUSH BINARY LOGS;
26+
SELECT SLEEP(1);
27+
SLEEP(1)
28+
0
29+
SET @@GLOBAL.max_binlog_size = 4096;
30+
CREATE TABLE t1(a INT PRIMARY KEY, b TEXT);
31+
SET debug_sync='raft_purge_flag_set SIGNAL purge_reached WAIT_FOR purge_continue';
32+
PURGE RAFT LOGS BEFORE NOW();
33+
SET debug_sync='now WAIT_FOR purge_reached';
34+
INSERT INTO t1 VALUES(1, REPEAT('a', 5000));
35+
SET debug_sync='now SIGNAL purge_continue';
36+
Warnings:
37+
Warning 1868 file ./binary-logs-13000.000006 was not purged because it is the active log file.
38+
"There should be only one raft log:"
39+
SHOW RAFT LOGS;
40+
Log_name File_size Encrypted
41+
# # No
42+
INSERT INTO t1 VALUES(2, "");
43+
"Now we should have two raft logs:"
44+
SHOW RAFT LOGS;
45+
Log_name File_size Encrypted
46+
# # No
47+
# # No
48+
SET @@GLOBAL.max_binlog_size = default;
49+
DROP TABLE t1;
50+
include/sync_slave_sql_with_master.inc
51+
include/sync_slave_sql_with_master.inc
52+
include/rpl_end.inc

‎mysql-test/suite/rpl_raft/t/rpl_raft_delay_rotation_on_raft_log_purge.test‎

Lines changed: 43 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,43 @@
1+
source include/have_debug_sync.inc;
2+
source ../include/raft_3_node.inc;
3+
4+
connection server_1;
5+
FLUSH BINARY LOGS;
6+
FLUSH BINARY LOGS;
7+
FLUSH BINARY LOGS;
8+
FLUSH BINARY LOGS;
9+
SELECT SLEEP(1);
10+
11+
SET @@GLOBAL.max_binlog_size = 4096;
12+
CREATE TABLE t1(a INT PRIMARY KEY, b TEXT);
13+
14+
SET debug_sync='raft_purge_flag_set SIGNAL purge_reached WAIT_FOR purge_continue';
15+
send PURGE RAFT LOGS BEFORE NOW();
16+
17+
connection server_1_1;
18+
SET debug_sync='now WAIT_FOR purge_reached';
19+
INSERT INTO t1 VALUES(1, REPEAT('a', 5000));
20+
SET debug_sync='now SIGNAL purge_continue';
21+
22+
connection server_1;
23+
reap;
24+
25+
echo "There should be only one raft log:";
26+
replace_column 1 # 2 #;
27+
SHOW RAFT LOGS;
28+
INSERT INTO t1 VALUES(2, "");
29+
echo "Now we should have two raft logs:";
30+
replace_column 1 # 2 #;
31+
SHOW RAFT LOGS;
32+
33+
# Cleanup
34+
connection server_1;
35+
SET @@GLOBAL.max_binlog_size = default;
36+
DROP TABLE t1;
37+
38+
let $sync_slave_connection= server_2;
39+
source include/sync_slave_sql_with_master.inc;
40+
let $sync_slave_connection= server_3;
41+
source include/sync_slave_sql_with_master.inc;
42+
43+
source include/rpl_end.inc;

‎mysql-test/suite/sys_vars/r/delay_auto_rotation_on_raft_log_purge_basic.result‎

Lines changed: 20 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,20 @@
1+
Default value of delay_auto_rotation_on_raft_log_purge is 1
2+
SELECT @@global.delay_auto_rotation_on_raft_log_purge;
3+
@@global.delay_auto_rotation_on_raft_log_purge
4+
1
5+
SELECT @@session.delay_auto_rotation_on_raft_log_purge;
6+
ERROR HY000: Variable 'delay_auto_rotation_on_raft_log_purge' is a GLOBAL variable
7+
Expected error 'Variable is a GLOBAL variable'
8+
delay_auto_rotation_on_raft_log_purge is a dynamic variable
9+
SET @@global.delay_auto_rotation_on_raft_log_purge = 1;
10+
SELECT @@global.delay_auto_rotation_on_raft_log_purge;
11+
@@global.delay_auto_rotation_on_raft_log_purge
12+
1
13+
SET @@global.delay_auto_rotation_on_raft_log_purge = 0;
14+
SELECT @@global.delay_auto_rotation_on_raft_log_purge;
15+
@@global.delay_auto_rotation_on_raft_log_purge
16+
0
17+
SET @@global.delay_auto_rotation_on_raft_log_purge = default;
18+
SELECT @@global.delay_auto_rotation_on_raft_log_purge;
19+
@@global.delay_auto_rotation_on_raft_log_purge
20+
1

‎mysql-test/suite/sys_vars/t/delay_auto_rotation_on_raft_log_purge_basic.test‎

Lines changed: 27 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,27 @@
1+
-- source include/load_sysvars.inc
2+
3+
####
4+
# Verify default value 1
5+
####
6+
--echo Default value of delay_auto_rotation_on_raft_log_purge is 1
7+
SELECT @@global.delay_auto_rotation_on_raft_log_purge;
8+
9+
####
10+
# Verify that this is not a session variable #
11+
####
12+
--Error ER_INCORRECT_GLOBAL_LOCAL_VAR
13+
SELECT @@session.delay_auto_rotation_on_raft_log_purge;
14+
--echo Expected error 'Variable is a GLOBAL variable'
15+
16+
####
17+
## Verify that the variable is dynamic
18+
####
19+
--echo delay_auto_rotation_on_raft_log_purge is a dynamic variable
20+
SET @@global.delay_auto_rotation_on_raft_log_purge = 1;
21+
SELECT @@global.delay_auto_rotation_on_raft_log_purge;
22+
23+
SET @@global.delay_auto_rotation_on_raft_log_purge = 0;
24+
SELECT @@global.delay_auto_rotation_on_raft_log_purge;
25+
26+
SET @@global.delay_auto_rotation_on_raft_log_purge = default;
27+
SELECT @@global.delay_auto_rotation_on_raft_log_purge;

‎sql/binlog.cc‎

Lines changed: 28 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -3964,7 +3964,19 @@ bool purge_raft_logs(THD *thd, const char *to_log) {
39643964

39653965
// If mysql_bin_log is not an apply log, then it represents the 'raft logs' on
39663966
// leader. Call purge_master_logs() to handle the purge correctly
3967-
if (!mysql_bin_log.is_apply_log) return purge_master_logs(thd, to_log);
3967+
if (!mysql_bin_log.is_apply_log) {
3968+
mysql_bin_log.is_raft_log_purge_active = true;
3969+
const auto start = std::chrono::system_clock::now();
3970+
DEBUG_SYNC(thd, "raft_purge_flag_set");
3971+
bool retval = purge_master_logs(thd, to_log);
3972+
mysql_bin_log.is_raft_log_purge_active = false;
3973+
const auto end = std::chrono::system_clock::now();
3974+
sql_print_information(
3975+
"Raft log purging was active for %f usecs",
3976+
std::chrono::duration_cast<std::chrono::microseconds>(end - start)
3977+
.count());
3978+
return retval;
3979+
}
39683980

39693981
Master_info *active_mi;
39703982
if (!get_and_lock_master_info(&active_mi)) {
@@ -4024,8 +4036,19 @@ bool purge_raft_logs_before_date(THD *thd, time_t purge_time) {
40244036
// If mysql_bin_log is not an apply log, then it represents the 'raft logs' on
40254037
// leader. Call purge_master_logs_before_date() to handle the purge
40264038
// correctly
4027-
if (!mysql_bin_log.is_apply_log)
4028-
return purge_master_logs_before_date(thd, purge_time);
4039+
if (!mysql_bin_log.is_apply_log) {
4040+
mysql_bin_log.is_raft_log_purge_active = true;
4041+
const auto start = std::chrono::system_clock::now();
4042+
DEBUG_SYNC(thd, "raft_purge_flag_set");
4043+
bool retval = purge_master_logs_before_date(thd, purge_time);
4044+
mysql_bin_log.is_raft_log_purge_active = false;
4045+
const auto end = std::chrono::system_clock::now();
4046+
sql_print_information(
4047+
"Raft log purging was active for %f usecs",
4048+
std::chrono::duration_cast<std::chrono::microseconds>(end - start)
4049+
.count());
4050+
return retval;
4051+
}
40294052

40304053
Master_info *active_mi;
40314054
if (!get_and_lock_master_info(&active_mi)) {
@@ -11987,7 +12010,8 @@ int MYSQL_BIN_LOG::ordered_commit(THD *thd, bool all, bool skip_commit) {
1198712010
*/
1198812011
if (DBUG_EVALUATE_IF("force_rotate", 1, 0) ||
1198912012
(do_rotate && thd->commit_error == THD::CE_NONE &&
11990-
!is_rotating_caused_by_incident)) {
12013+
!is_rotating_caused_by_incident &&
12014+
(!delay_auto_rotation_on_raft_log_purge || !is_raft_log_purge_active))) {
1199112015
/*
1199212016
Do not force the rotate as several consecutive groups may
1199312017
request unnecessary rotations.

‎sql/binlog.h‎

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -596,6 +596,8 @@ class MYSQL_BIN_LOG : public TC_LOG {
596596

597597
uint64_t get_ttl_compaction_ts() const { return ttl_compaction_ts.load(); }
598598

599+
std::atomic<bool> is_raft_log_purge_active{false};
600+
599601
private:
600602
/**
601603
Checks binlog error action to identify if the server needs to abort on

‎sql/mysqld.cc‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1239,6 +1239,7 @@ ulong opt_commit_consensus_error_action = 0;
12391239
bool enable_raft_plugin = 0;
12401240
bool disallow_raft = 1; // raft is not allowed by default
12411241
bool override_enable_raft_check = false;
1242+
bool delay_auto_rotation_on_raft_log_purge = true;
12421243
bool abort_on_raft_purge_error = false;
12431244
ulonglong apply_log_retention_num = 0;
12441245
ulonglong apply_log_retention_duration = 0;

‎sql/mysqld.h‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -468,6 +468,7 @@ extern bool disable_raft_log_repointing;
468468
extern ulong opt_raft_signal_async_dump_threads;
469469
extern bool disallow_raft;
470470
extern bool override_enable_raft_check;
471+
extern bool delay_auto_rotation_on_raft_log_purge;
471472
extern bool abort_on_raft_purge_error;
472473
extern ulonglong apply_log_retention_num;
473474
extern ulonglong apply_log_retention_duration;

‎sql/sys_vars.cc‎

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -9038,6 +9038,14 @@ static Sys_var_bool Sys_enable_raft_plugin(
90389038
NO_MUTEX_GUARD, NOT_IN_BINLOG, ON_CHECK(validate_enable_raft),
90399039
ON_UPDATE(update_enable_raft_change));
90409040

9041+
static Sys_var_bool Sys_delay_auto_rotation_on_raft_log_purge(
9042+
"delay_auto_rotation_on_raft_log_purge",
9043+
"On the leader, when raft logs are being purged delay automatic log "
9044+
"rotation until purge is done even if we go a beyond the max binlog size.",
9045+
GLOBAL_VAR(delay_auto_rotation_on_raft_log_purge), CMD_LINE(OPT_ARG),
9046+
DEFAULT(true), NO_MUTEX_GUARD, NOT_IN_BINLOG, ON_CHECK(nullptr),
9047+
ON_UPDATE(nullptr));
9048+
90419049
static Sys_var_bool Sys_abort_on_raft_purge_error(
90429050
"abort_on_raft_purge_error",
90439051
"Any error in raft plugin to purge files will abort the server",

0 commit comments

Comments
 (0)