Details
-
Bug
-
Status: Open (View Workflow)
-
Major
-
Resolution: Unresolved
-
11.4, 11.8, 12.3
-
None
-
Can result in data loss
Description
With slave_connections_needed_for_purge=1 (the default), the master
retains binary logs until at least one connected slave has processed
them. Despite that, a slave that connects and requests binary logs
which still exist on the master can have exactly those logs purged
during the connect. The slave IO thread stops with a fatal error:
Got fatal error 1236 from master when reading data from binary log: 'Could not open log file'
|
In GTID mode the purged file held transactions the slave had not yet
received, so the slave cannot resume from its gtid_slave_pos and must
be reprovisioned.
As a disclaimer: with slave_connections_needed_for_purge=0 the server
is explicitly configured to purge binary logs without regard to
slaves, so a slave losing events to purge is expected behavior there.
This report is about slave_connections_needed_for_purge=1, where the
logs are supposed to be retained for the slave.
The scenario a user would see: a slave falls behind or disconnects
(a network hiccup, a restart, a failover), binary logs accumulate on
the master, and the slave reconnects at the same moment a purge runs.
The purge can be a manual PURGE BINARY LOGS statement, or automatic
purge (binlog_expire_logs_seconds, max_binlog_total_size) when another
connected slave satisfies the required count of 1. The reconnecting
slave requested files the master still had, yet the connection fails
with error 1236 as if the logs were long gone.
The cause is the order of operations while a slave connects. The
master normally protects a file a slave is reading: each dump thread
registers the file it is currently sending, and every purge path
checks the registrations (MYSQL_BIN_LOG::can_purge_log() calling
log_in_use()) and refuses to remove a file any slave is on. During a
connect, however, init_binlog_sender() (sql/sql_repl.cc) does this:
1. Resolve the slave's request to a file name. A GTID connect resolves
through gtid_find_binlog_pos(), which reads through binlog files to
find the right starting point, so this step spans file IO.
2. Register the resolved file as in use (THD::set_current_linfo()).
3. Open the file and start sending.
Between steps 1 and 2 nothing marks the resolved file as in use, so a
purge running at that moment sees no reader and deletes it. At step 3
the dump thread fails to open the file and sends the slave error 1236.
slave_connections_needed_for_purge=1 does not close this window. PURGE
BINARY LOGS is exempt from the count entirely and honors only the in
use check, which cannot see the connecting slave yet. Automatic purge
does refuse to run while the connecting slave is the only binlog
reader, but only because an unregistered slave is not counted; the
file the slave was promised is not itself protected, and any other
connected slave satisfies the count and lets automatic purge proceed.
How to reproduce:
Hitting the window in the wild is timing dependent, so the patch below
adds a DEBUG_SYNC pause inside it (debug builds only, compiled under
ENABLED_DEBUG_SYNC). The test sets
slave_connections_needed_for_purge=1 and uses the pause to run PURGE
BINARY LOGS while a connecting dump thread is parked between resolving
and registering its file.
diff --git a/sql/sql_repl.cc b/sql/sql_repl.cc
|
index 546988000d1..dbf17239e0b 100644
|
--- a/sql/sql_repl.cc
|
+++ b/sql/sql_repl.cc
|
@@ -2458,6 +2458,24 @@ static int init_binlog_sender(binlog_send_info *info,
|
|
|
// set current pos too
|
linfo->pos= *pos;
|
+
|
+#ifdef ENABLED_DEBUG_SYNC
|
+ DBUG_EXECUTE_IF("dump_thread_wait_before_register_linfo",
|
+ {
|
+ const char act[]=
|
+ "now SIGNAL dump_thread_before_register_linfo "
|
+ "WAIT_FOR dump_thread_continue_register_linfo";
|
+ DBUG_ASSERT(!debug_sync_set_action(thd,
|
+ STRING_WITH_LEN(act)));
|
+ };);
|
+#endif
|
+
|
// note: publish that we use file, before we open it
|
thd->set_current_linfo(linfo);
|
|
The test:
--source include/have_innodb.inc
|
--source include/have_debug.inc
|
--source include/have_debug_sync.inc
|
# Test is binlog format independent
|
--source include/have_binlog_format_row.inc
|
--source include/master-slave.inc
|
|
|
--connection slave
|
--source include/stop_slave.inc
|
--echo # GTID mode is the mode under test: the slave requests its
|
--echo # position as a GTID state and the master resolves it to a binary
|
--echo # log file
|
CHANGE MASTER TO master_use_gtid=slave_pos;
|
|
|
--connection master
|
set @old_dbug= @@global.debug_dbug;
|
set @old_slave_connections_needed_for_purge=
|
@@global.slave_connections_needed_for_purge;
|
--echo # Binary logs must be retained until a connected slave has
|
--echo # processed them
|
set @@global.slave_connections_needed_for_purge= 1;
|
--echo # Wait for the old dump thread to go away, so it cannot mark a
|
--echo # file as in use
|
--let $wait_condition= SELECT count(*)= 0 FROM information_schema.processlist WHERE command LIKE 'Binlog Dump%'
|
--source include/wait_condition.inc
|
|
|
--echo # Write the transactions the slave will request into
|
--echo # master-bin.000001, and rotate so it is not the active file
|
create table t1 (a int) engine=innodb;
|
insert into t1 values (1);
|
flush binary logs;
|
--echo # Ensure the binlog checkpoint has moved to the active file, so a
|
--echo # purge refusal below can only mean a file is in use, never that
|
--echo # it is needed for crash recovery (XID)
|
--source include/wait_for_binlog_checkpoint.inc
|
set @@global.debug_dbug= "+d,dump_thread_wait_before_register_linfo";
|
|
|
--connection slave
|
--echo # Start the slave; on the master, its dump thread pauses after
|
--echo # resolving the requested file and before registering it as in
|
--echo # use
|
START SLAVE;
|
|
|
--connection master
|
set debug_sync= "now WAIT_FOR dump_thread_before_register_linfo";
|
--echo # The requested master-bin.000001 must survive this purge
|
--let $purge_to_binlog= query_get_value(SHOW MASTER STATUS, File, 1)
|
--eval PURGE BINARY LOGS TO '$purge_to_binlog'
|
set @@global.debug_dbug= @old_dbug;
|
--echo # Release the paused dump thread
|
set debug_sync= "now SIGNAL dump_thread_continue_register_linfo";
|
--source include/save_master_gtid.inc
|
|
|
--connection slave
|
--echo # A connected slave must receive every transaction from its
|
--echo # requested GTID position onward. If the following wait fails
|
--echo # with Last_IO_Errno = 1236, the master purged the binary log
|
--echo # file it had already resolved for this slave's dump request,
|
--echo # and the transactions in it are lost
|
--let $slave_param= Gtid_IO_Pos
|
--let $slave_param_value= $master_pos
|
--let $slave_error_param= Last_IO_Errno
|
--source include/wait_for_slave_param.inc
|
--source include/sync_with_master_gtid.inc
|
select * from t1;
|
Attachments
Issue Links
- relates to
-
MDEV-31404 Implement binlog_space_limit
-
- Closed
-
