Skip to content

Commit ffa4a65

Browse files
author
Sujatha Sivakumar
committed
Bug#20805298: BINLOG_ERROR_ACTION DOESN'T HANDLE SOME
FAILURES DURING BINLOG ROTATION Analysis: ======== In case of hardware errors in binlog partition during binlog rotate, we can see the following error being reported. [ERROR] The server was unable to create a new log file. An incident event has been written to the binary log which will stop the slaves. [ERROR] Can't generate a unique log-filename master-bin.(1-999) All replicas break either due to seeing incident event or simply because the dump thread cannot access binlog partition. binlog_error_action was developed for these purposes (i,e; to avoid server accepting writes even though binlog writes are failing), but it doesn't handle the above case. Fix: === An error handler has been added in such a way that, on hardware failure during rotate, it will do the specific action defined as part 'binlog_error_action' variable. Also incident event will not be written to the binary log in the above mentioned scenario.
1 parent 3db5326 commit ffa4a65

10 files changed

Lines changed: 158 additions & 56 deletions

‎mysql-test/extra/rpl_tests/rpl_binlog_error.inc‎

Lines changed: 57 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -84,12 +84,15 @@ eval SET GLOBAL debug=IF(LENGTH('$old_debug') > 0, CONCAT('$old_debug', ":d,erro
8484
-- error ER_NO_UNIQUE_LOGFILE
8585
FLUSH LOGS;
8686
-- echo # assert: must show one binlog
87-
-- source include/show_binary_logs.inc
87+
--list_files $MYSQLD_DATADIR *master-bin.0*
8888

8989
### ACTION: clean up and move to next test
9090
--disable_query_log
9191
eval SET GLOBAL debug='$old_debug';
9292
--enable_query_log
93+
# Restart the server to enable binary log.
94+
--let $rpl_server_number= 1
95+
--source include/rpl_restart_server.inc
9396
RESET MASTER;
9497

9598
-- echo ###################### TEST #3
@@ -145,6 +148,9 @@ SELECT count(*) FROM t2;
145148
eval SET GLOBAL debug='$old_debug';
146149
--enable_query_log
147150
DELETE FROM t2;
151+
# Restart the server to enable binary log.
152+
--let $rpl_server_number= 1
153+
--source include/rpl_restart_server.inc
148154
RESET MASTER;
149155

150156
-- echo ###################### TEST #5
@@ -199,6 +205,9 @@ SET AUTOCOMMIT= 1;
199205
eval SET GLOBAL debug='$old_debug';
200206
--enable_query_log
201207
DELETE FROM t2;
208+
# Restart the server to enable binary log.
209+
--let $rpl_server_number= 1
210+
--source include/rpl_restart_server.inc
202211
RESET MASTER;
203212

204213
-- echo ###################### TEST #7
@@ -218,15 +227,15 @@ SELECT count(*) FROM t4;
218227
-- echo # assert: must show 1 entry
219228
SELECT count(*) FROM t4;
220229

221-
-- echo ### check that the incident event is written to the current log
222230
--disable_query_log
223231
eval SET GLOBAL debug='$old_debug';
224232
--enable_query_log
225-
-- let $binlog_limit= 1
226-
-- source include/show_binlog_events.inc
227233

228234
# clean up and move to next test
229235
DELETE FROM t4;
236+
# Restart the server to enable binary log.
237+
--let $rpl_server_number= 1
238+
--source include/rpl_restart_server.inc
230239
RESET MASTER;
231240

232241
-- echo ###################### TEST #8
@@ -252,9 +261,26 @@ SELECT count(*) FROM t2;
252261
-- replace_result $MYSQLTEST_VARDIR MYSQLTEST_VARDIR
253262
-- error ER_NO_UNIQUE_LOGFILE
254263
-- eval LOAD DATA INFILE '$load_file' INTO TABLE t4
264+
265+
# Restart the server to enable binary log.
266+
--let $rpl_server_number= 1
267+
--source include/rpl_restart_server.inc
268+
269+
--disable_query_log
270+
eval SET GLOBAL debug=IF(LENGTH('$old_debug') > 0, CONCAT('$old_debug', ":d,error_unique_log_filename"), 'd,error_unique_log_filename');
271+
--enable_query_log
272+
255273
-- replace_result $MYSQLTEST_VARDIR MYSQLTEST_VARDIR
256274
-- error ER_NO_UNIQUE_LOGFILE
257275
-- eval LOAD DATA INFILE '$load_file' INTO TABLE t2
276+
277+
# Restart the server to enable binary log.
278+
--let $rpl_server_number= 1
279+
--source include/rpl_restart_server.inc
280+
281+
--disable_query_log
282+
eval SET GLOBAL debug=IF(LENGTH('$old_debug') > 0, CONCAT('$old_debug', ":d,error_unique_log_filename"), 'd,error_unique_log_filename');
283+
--enable_query_log
258284
set @aaa = repeat('aaa',1000);
259285
set @bbb = repeat('bbb',1000);
260286
set @ccc = repeat('ccc',1000);
@@ -269,8 +295,30 @@ SELECT count(*) FROM t4;
269295
-- echo # original rows remain
270296
SELECT count(*) FROM t2;
271297

298+
# Restart the server to enable binary log.
299+
--let $rpl_server_number= 1
300+
--source include/rpl_restart_server.inc
301+
302+
--disable_query_log
303+
eval SET GLOBAL debug=IF(LENGTH('$old_debug') > 0, CONCAT('$old_debug', ":d,error_unique_log_filename"), 'd,error_unique_log_filename');
304+
--enable_query_log
305+
306+
SET @xxx = REPEAT('xxx', 1000);
307+
SET @yyy = REPEAT('yyy', 1000);
272308
-- error ER_NO_UNIQUE_LOGFILE
273309
DELETE FROM t4 WHERE a IN (@xxx, @yyy) OR 1;
310+
311+
# Restart the server to enable binary log.
312+
--let $rpl_server_number= 1
313+
--source include/rpl_restart_server.inc
314+
315+
--disable_query_log
316+
eval SET GLOBAL debug=IF(LENGTH('$old_debug') > 0, CONCAT('$old_debug', ":d,error_unique_log_filename"), 'd,error_unique_log_filename');
317+
--enable_query_log
318+
319+
set @aaa = repeat('aaa',1000);
320+
set @bbb = repeat('bbb',1000);
321+
set @ccc = repeat('ccc',1000);
274322
-- error ER_NO_UNIQUE_LOGFILE
275323
DELETE FROM t2 WHERE a IN (@aaa, @bbb, @ccc) OR 1;
276324

@@ -320,6 +368,9 @@ eval SET GLOBAL debug='$old_debug';
320368
call mtr.add_suppression("MYSQL_BIN_LOG::open failed to sync the index file.");
321369
call mtr.add_suppression("Could not open .*");
322370

371+
# Restart the server to enable binary log.
372+
--let $rpl_server_number= 1
373+
--source include/rpl_restart_server.inc
323374
RESET MASTER;
324375
SHOW WARNINGS;
325376

@@ -477,6 +528,8 @@ call mtr.add_suppression("Can't generate a unique log-filename .*");
477528
--disable_query_log
478529
eval SET GLOBAL debug='$old_debug';
479530
--enable_query_log
531+
-- remove_file $MYSQLTEST_VARDIR/tmp/bug_46166.data
532+
-- remove_file $MYSQLTEST_VARDIR/tmp/bug_46166-2.data
480533
RESET SLAVE;
481534
RESET MASTER;
482535
--let $rpl_only_running_threads= 1

‎mysql-test/suite/binlog/r/binlog_error_action.result‎

Lines changed: 17 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -74,4 +74,21 @@ INSERT INTO t1 VALUES (2);
7474
include/assert.inc [Count of elements in t1 should be 1.]
7575
DROP table t1;
7676
SET SESSION debug="-d,simulate_error_during_flush_cache_to_file";
77+
"Test case10"
78+
CREATE TABLE t1 (a INT) ENGINE=InnoDB;
79+
SET SESSION debug='+d,error_unique_log_filename';
80+
FLUSH LOGS;
81+
ERROR HY000: Can't generate a unique log-filename master-bin.(1-999)
82+
83+
DROP TABLE t1;
84+
SET SESSION debug="";
85+
SHOW BINARY LOGS;
86+
ERROR HY000: You are not using binary logging
87+
"Test case11"
88+
CREATE TABLE t1 (a INT) ENGINE=InnoDB;
89+
SET GLOBAL binlog_error_action=ABORT_SERVER;
90+
SET SESSION debug='+d,error_unique_log_filename';
91+
FLUSH LOGS;
92+
ERROR HY000: Binary logging not possible. Message: Either disk is full or file system is read only while rotating the binlog. Aborting the server
93+
DROP TABLE t1;
7794
SET SESSION debug="";

‎mysql-test/suite/binlog/r/binlog_index.result‎

Lines changed: 0 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -4,9 +4,6 @@ call mtr.add_suppression('MYSQL_BIN_LOG::open failed to sync the index file');
44
call mtr.add_suppression('Turning logging off for the whole duration of the MySQL server process.');
55
call mtr.add_suppression('Could not open .*');
66
call mtr.add_suppression('MYSQL_BIN_LOG::purge_logs failed to clean registers before purging logs.');
7-
call mtr.add_suppression("The server was unable to create a new log file. "
8-
"An incident event has been written to the binary "
9-
"log which will stop the slaves.");
107
RESET MASTER;
118
flush logs;
129
flush logs;

‎mysql-test/suite/binlog/r/binlog_max_extension.result‎

Lines changed: 1 addition & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -1,9 +1,7 @@
11
call mtr.add_suppression("Next log extension: 2147483647. Remaining log filename extensions: 0.");
22
call mtr.add_suppression("Log filename extension number exhausted:");
33
call mtr.add_suppression("Can't generate a unique log-filename");
4-
call mtr.add_suppression("The server was unable to create a new log file. "
5-
"An incident event has been written to the binary "
6-
"log which will stop the slaves.");
4+
call mtr.add_suppression("Could not open .*");
75
RESET MASTER;
86
FLUSH LOGS;
97
ERROR HY000: Can't generate a unique log-filename master-bin.(1-999)

‎mysql-test/suite/binlog/t/binlog_error_action.test‎

Lines changed: 45 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -165,5 +165,50 @@ DROP table t1;
165165
SET SESSION debug="-d,simulate_error_during_flush_cache_to_file";
166166
--source include/restart_mysqld.inc
167167

168+
###############################################################################
169+
# Bug#20805298: BINLOG_ERROR_ACTION DOESN'T HANDLE SOME
170+
# FAILURES DURING BINLOG ROTATION
171+
#
172+
# Problem:
173+
# ========
174+
# Hardware errors in binlog partition during binlog rotate are not handled by
175+
# binlog_error_action.
176+
#
177+
# Test:
178+
# =====
179+
# Simulate failure during creation of new binary log file name. Set
180+
# binlog_error_action to "IGNORE_ERROR" and observe that the binary log gets
181+
# disabled and the server continues by logging an appropriate error message in
182+
# error log file. Set binlog_error_action to "ABORT_ERROR" and observe that
183+
# the
184+
# server aborts when creation of new binarylog file name fails.
185+
###############################################################################
186+
echo "Test case10";
187+
# Test error scenario with binlog_error_action=IGNORE_ERROR
188+
CREATE TABLE t1 (a INT) ENGINE=InnoDB;
189+
SET SESSION debug='+d,error_unique_log_filename';
190+
--error ER_NO_UNIQUE_LOGFILE
191+
FLUSH LOGS;
192+
DROP TABLE t1;
193+
eval SET SESSION debug="$debug_save";
194+
# Test to prove that binary log is disabled
195+
--error ER_NO_BINARY_LOGGING
196+
SHOW BINARY LOGS;
197+
--source include/restart_mysqld.inc
198+
199+
echo "Test case11";
200+
# Test error scenario with binlog_error_action=ABORT_SERVER
201+
202+
CREATE TABLE t1 (a INT) ENGINE=InnoDB;
203+
SET GLOBAL binlog_error_action=ABORT_SERVER;
204+
SET SESSION debug='+d,error_unique_log_filename';
205+
--exec echo "wait" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
206+
--error ER_BINLOG_LOGGING_IMPOSSIBLE
207+
FLUSH LOGS;
208+
--exec echo "restart" > $MYSQLTEST_VARDIR/tmp/mysqld.1.expect
209+
--enable_reconnect
210+
--source include/wait_until_connected_again.inc
211+
DROP TABLE t1;
212+
168213
# Cleanup
169214
eval SET SESSION debug="$old";

‎mysql-test/suite/binlog/t/binlog_index.test‎

Lines changed: 0 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -14,9 +14,6 @@ call mtr.add_suppression('MYSQL_BIN_LOG::open failed to sync the index file');
1414
call mtr.add_suppression('Turning logging off for the whole duration of the MySQL server process.');
1515
call mtr.add_suppression('Could not open .*');
1616
call mtr.add_suppression('MYSQL_BIN_LOG::purge_logs failed to clean registers before purging logs.');
17-
call mtr.add_suppression("The server was unable to create a new log file. "
18-
"An incident event has been written to the binary "
19-
"log which will stop the slaves.");
2017
let $old=`select @@debug`;
2118

2219
RESET MASTER;

‎mysql-test/suite/binlog/t/binlog_max_extension.test‎

Lines changed: 1 addition & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -22,9 +22,7 @@
2222
call mtr.add_suppression("Next log extension: 2147483647. Remaining log filename extensions: 0.");
2323
call mtr.add_suppression("Log filename extension number exhausted:");
2424
call mtr.add_suppression("Can't generate a unique log-filename");
25-
call mtr.add_suppression("The server was unable to create a new log file. "
26-
"An incident event has been written to the binary "
27-
"log which will stop the slaves.");
25+
call mtr.add_suppression("Could not open .*");
2826
-- source include/have_log_bin.inc
2927
RESET MASTER;
3028

‎mysql-test/suite/rpl/r/rpl_binlog_errors.result‎

Lines changed: 15 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -23,9 +23,8 @@ FLUSH LOGS;
2323
ERROR HY000: Can't generate a unique log-filename master-bin.(1-999)
2424

2525
# assert: must show one binlog
26-
show binary logs;
27-
Log_name File_size
28-
master-bin.000001 #
26+
master-bin.000001
27+
include/rpl_restart_server.inc [server_number=1]
2928
RESET MASTER;
3029
###################### TEST #3
3130
CREATE TABLE t1 (a INT);
@@ -53,6 +52,7 @@ SELECT count(*) FROM t2;
5352
count(*)
5453
1
5554
DELETE FROM t2;
55+
include/rpl_restart_server.inc [server_number=1]
5656
RESET MASTER;
5757
###################### TEST #5
5858
LOAD DATA INFILE 'MYSQLTEST_VARDIR/tmp/bug_46166-2.data' INTO TABLE t2;
@@ -80,6 +80,7 @@ count(*)
8080
3
8181
SET AUTOCOMMIT= 1;
8282
DELETE FROM t2;
83+
include/rpl_restart_server.inc [server_number=1]
8384
RESET MASTER;
8485
###################### TEST #7
8586
SELECT count(*) FROM t4;
@@ -92,11 +93,8 @@ ERROR HY000: Can't generate a unique log-filename master-bin.(1-999)
9293
SELECT count(*) FROM t4;
9394
count(*)
9495
1
95-
### check that the incident event is written to the current log
96-
include/show_binlog_events.inc
97-
Log_name Pos Event_type Server_id End_log_pos Info
98-
master-bin.000001 # Query # # BEGIN
9996
DELETE FROM t4;
97+
include/rpl_restart_server.inc [server_number=1]
10098
RESET MASTER;
10199
###################### TEST #8
102100
SET @xxx = REPEAT('xxx', 1000);
@@ -113,9 +111,11 @@ count(*)
113111
LOAD DATA INFILE 'MYSQLTEST_VARDIR/tmp/bug_46166.data' INTO TABLE t4;
114112
ERROR HY000: Can't generate a unique log-filename master-bin.(1-999)
115113

114+
include/rpl_restart_server.inc [server_number=1]
116115
LOAD DATA INFILE 'MYSQLTEST_VARDIR/tmp/bug_46166.data' INTO TABLE t2;
117116
ERROR HY000: Can't generate a unique log-filename master-bin.(1-999)
118117

118+
include/rpl_restart_server.inc [server_number=1]
119119
set @aaa = repeat('aaa',1000);
120120
set @bbb = repeat('bbb',1000);
121121
set @ccc = repeat('ccc',1000);
@@ -133,9 +133,16 @@ count(*)
133133
SELECT count(*) FROM t2;
134134
count(*)
135135
6
136+
include/rpl_restart_server.inc [server_number=1]
137+
SET @xxx = REPEAT('xxx', 1000);
138+
SET @yyy = REPEAT('yyy', 1000);
136139
DELETE FROM t4 WHERE a IN (@xxx, @yyy) OR 1;
137140
ERROR HY000: Can't generate a unique log-filename master-bin.(1-999)
138141

142+
include/rpl_restart_server.inc [server_number=1]
143+
set @aaa = repeat('aaa',1000);
144+
set @bbb = repeat('bbb',1000);
145+
set @ccc = repeat('ccc',1000);
139146
DELETE FROM t2 WHERE a IN (@aaa, @bbb, @ccc) OR 1;
140147
ERROR HY000: Can't generate a unique log-filename master-bin.(1-999)
141148

@@ -173,6 +180,7 @@ SET SQL_LOG_BIN=1;
173180
###################### TEST #10
174181
call mtr.add_suppression("MYSQL_BIN_LOG::open failed to sync the index file.");
175182
call mtr.add_suppression("Could not open .*");
183+
include/rpl_restart_server.inc [server_number=1]
176184
RESET MASTER;
177185
SHOW WARNINGS;
178186
Level Code Message

0 commit comments

Comments
 (0)