Description:
After a RESET MASTER is performed, there is a race between any existing Binlog Dump threads and operations which create new files, like CREATE TABLE. This is because the Binlog Dump thread will call my_close using the file descriptor of the files deleted by MYSQL_LOG::reset_logs and those file descriptors will get reused by create / open operations.
Running STOP SLAVE; on all slaves does not fix the problem because doing so does not terminate the Binlog Dump threads which exist on the master.
The order of operations causing the problem is something like this:
a binlog dump thread opens a bin log with a given file descriptor, say 31
binlog dump thread sends all events to slave and blocks at wait_for_update
<context switch>
'RESET MASTER' called and deletes all bin logs including the one with file descriptor 31
'create table' calls open and gets back the file descriptor of the deleted bin log, 31
<context switch>
binlog_dump thread hits an error because the bin logs were deleted out from under it
binlog_dump thread, as part of its shutdown procedure closes the file it opened, 31
<context switch>
'create table' tries to write to, close or do some other operation using file descriptor 31 which fails because it was just closed.
How to repeat:
1) Edit mysql-test/lib/mtr_cases.pl so that it has:
$tinfo->{'slave_num'}= 3; # Default for rpl* tests, use one slave
2) Write a new test, rpl_reset_master which does:
source include/master-slave.inc;
connect (slave2,127.0.0.1,root,,test,$SLAVE_MYPORT1,);
connect (slave3,127.0.0.1,root,,test,$SLAVE_MYPORT2,);
connection slave2;
#we expect STOP SLAVE to produce a warning as the slave is stopped
#(the server was started with skip-slave-start)
--disable_warnings
stop slave;
--enable_warnings
--require r/slave-stopped.result
show status like 'Slave_running';
--disable_warnings
drop table if exists t1,t2,t3,t4,t5,t6,t7,t8,t9;
--enable_warnings
start slave;
connection slave3;
#we expect STOP SLAVE to produce a warning as the slave is stopped
#(the server was started with skip-slave-start)
--disable_warnings
stop slave;
--enable_warnings
--require r/slave-stopped.result
show status like 'Slave_running';
--disable_warnings
drop table if exists t1,t2,t3,t4,t5,t6,t7,t8,t9;
--enable_warnings
start slave;
connection master;
flush logs;
flush logs;
create table t1 (a int, b char(32));
save_master_pos;
connection slave;
sync_with_master;
stop slave;
connection slave2;
sync_with_master;
stop slave;
connection slave3;
sync_with_master;
stop slave;
connection master;
sleep 1;
purge binary logs before now();
reset master;
flush logs;
create table t2 (a int, b char(32));
3) Run:
while ./mysql-test-run.pl rpl_reset_master ; do date ; done
until it fails with something like:
mysqltest: At line 55: query 'create table t2 (a int, b char(32))' failed: 4: Error on close of 'UNOPENED' (Errcode: 9)
Suggested fix:
Change MYSQL_LOG::reset_logs to kill all Binlog Dump threads before deleting the logs out from under them.
Description: After a RESET MASTER is performed, there is a race between any existing Binlog Dump threads and operations which create new files, like CREATE TABLE. This is because the Binlog Dump thread will call my_close using the file descriptor of the files deleted by MYSQL_LOG::reset_logs and those file descriptors will get reused by create / open operations. Running STOP SLAVE; on all slaves does not fix the problem because doing so does not terminate the Binlog Dump threads which exist on the master. The order of operations causing the problem is something like this: a binlog dump thread opens a bin log with a given file descriptor, say 31 binlog dump thread sends all events to slave and blocks at wait_for_update <context switch> 'RESET MASTER' called and deletes all bin logs including the one with file descriptor 31 'create table' calls open and gets back the file descriptor of the deleted bin log, 31 <context switch> binlog_dump thread hits an error because the bin logs were deleted out from under it binlog_dump thread, as part of its shutdown procedure closes the file it opened, 31 <context switch> 'create table' tries to write to, close or do some other operation using file descriptor 31 which fails because it was just closed. How to repeat: 1) Edit mysql-test/lib/mtr_cases.pl so that it has: $tinfo->{'slave_num'}= 3; # Default for rpl* tests, use one slave 2) Write a new test, rpl_reset_master which does: source include/master-slave.inc; connect (slave2,127.0.0.1,root,,test,$SLAVE_MYPORT1,); connect (slave3,127.0.0.1,root,,test,$SLAVE_MYPORT2,); connection slave2; #we expect STOP SLAVE to produce a warning as the slave is stopped #(the server was started with skip-slave-start) --disable_warnings stop slave; --enable_warnings --require r/slave-stopped.result show status like 'Slave_running'; --disable_warnings drop table if exists t1,t2,t3,t4,t5,t6,t7,t8,t9; --enable_warnings start slave; connection slave3; #we expect STOP SLAVE to produce a warning as the slave is stopped #(the server was started with skip-slave-start) --disable_warnings stop slave; --enable_warnings --require r/slave-stopped.result show status like 'Slave_running'; --disable_warnings drop table if exists t1,t2,t3,t4,t5,t6,t7,t8,t9; --enable_warnings start slave; connection master; flush logs; flush logs; create table t1 (a int, b char(32)); save_master_pos; connection slave; sync_with_master; stop slave; connection slave2; sync_with_master; stop slave; connection slave3; sync_with_master; stop slave; connection master; sleep 1; purge binary logs before now(); reset master; flush logs; create table t2 (a int, b char(32)); 3) Run: while ./mysql-test-run.pl rpl_reset_master ; do date ; done until it fails with something like: mysqltest: At line 55: query 'create table t2 (a int, b char(32))' failed: 4: Error on close of 'UNOPENED' (Errcode: 9) Suggested fix: Change MYSQL_LOG::reset_logs to kill all Binlog Dump threads before deleting the logs out from under them.