1# BUG#46166: MYSQL_BIN_LOG::new_file_impl is not propagating error
2#            when generating new name.
3#
4# WHY
5# ===
6#
7# We want to check whether error is reported or not when
8# new_file_impl fails (this may happen when rotation is not
9# possible because there is some problem finding an
10# unique filename).
11#
12# HOW
13# ===
14#
15# Test cases are documented inline.
16#
17# The size of the data is tuned to match file sizes and rotations, so
18# it is only executed in statement-based replication.
19
20-- source include/have_innodb.inc
21-- source include/have_debug.inc
22-- source include/master-slave.inc
23-- source include/have_binlog_format_statement.inc
24
25-- echo #######################################################################
26-- echo ####################### PART 1: MASTER TESTS ##########################
27-- echo #######################################################################
28
29
30### ACTION: stopping slave as it is not needed for the first part of
31###         the test
32
33-- connection slave
34-- source include/stop_slave.inc
35-- connection master
36
37--disable_query_log
38call mtr.add_suppression("Can't generate a unique log-filename");
39call mtr.add_suppression("Writing one row to the row-based binary log failed.*");
40call mtr.add_suppression("Warning: [+-]?\d+ files and [+-]?\d+ streams is left open");
41call mtr.add_suppression("Error writing file .*");
42call mtr.add_suppression("The server was unable to create a new log file. "
43                         "An incident event has been written to the binary "
44                         "log which will stop the slaves.");
45--enable_query_log
46
47--let $old_debug = `select @@global.debug`
48
49### ACTION: create a large file (> 4096 bytes) that will be later used
50###         in LOAD DATA INFILE to check binlog errors in its vacinity
51-- let $load_file= $MYSQLTEST_VARDIR/tmp/bug_46166.data
52-- let $MYSQLD_DATADIR= `select @@datadir`
53-- replace_result $MYSQLTEST_VARDIR MYSQLTEST_VARDIR
54-- eval SELECT repeat('x',8192) INTO OUTFILE '$load_file'
55
56### ACTION: create a small file (< 4096 bytes) that will be later used
57###         in LOAD DATA INFILE to check for absence of binlog errors
58###         when file loading this file does not force flushing and
59###         rotating the binary log
60-- let $load_file2= $MYSQLTEST_VARDIR/tmp/bug_46166-2.data
61-- let $MYSQLD_DATADIR= `select @@datadir`
62-- replace_result $MYSQLTEST_VARDIR MYSQLTEST_VARDIR
63-- eval SELECT repeat('x',10) INTO OUTFILE '$load_file2'
64
65RESET MASTER;
66
67-- echo ###################### TEST #1
68
69### ASSERTION: no problem flushing logs (should show two binlogs)
70FLUSH LOGS;
71-- echo # assert: must show two binlogs
72-- source include/show_binary_logs.inc
73
74-- echo ###################### TEST #2
75
76### ASSERTION: check that FLUSH LOGS actually fails and reports
77###            failure back to the user if find_uniq_filename fails
78###            (should show just one binlog)
79
80RESET MASTER;
81--disable_query_log
82eval SET GLOBAL debug=IF(LENGTH('$old_debug') > 0, CONCAT('$old_debug', ":d,error_unique_log_filename"), 'd,error_unique_log_filename');
83--enable_query_log
84-- error ER_NO_UNIQUE_LOGFILE
85FLUSH LOGS;
86-- echo # assert: must show one binlog
87--list_files $MYSQLD_DATADIR *master-bin.0*
88
89### ACTION: clean up and move to next test
90--disable_query_log
91eval SET GLOBAL debug='$old_debug';
92--enable_query_log
93# Restart the server to enable binary log.
94--let $rpl_server_number= 1
95--source include/rpl_restart_server.inc
96RESET MASTER;
97
98-- echo ###################### TEST #3
99
100### ACTION: create some tables (t1, t2, t4) and insert some values in
101###         table t1
102CREATE TABLE t1 (a INT);
103CREATE TABLE t2 (a VARCHAR(16384)) Engine=InnoDB;
104CREATE TABLE t4 (a VARCHAR(16384)) Engine=MyISAM;
105INSERT INTO t1 VALUES (1);
106RESET MASTER;
107
108### ASSERTION: we force rotation of the binary log because it exceeds
109###            the max_binlog_size option (should show three binary
110###            logs)
111
112-- replace_result $MYSQLTEST_VARDIR MYSQLTEST_VARDIR
113-- eval LOAD DATA INFILE '$load_file' INTO TABLE t2
114
115# shows two binary logs
116-- echo # assert: must show three binlog
117-- source include/show_binary_logs.inc
118
119# clean up the table and the binlog to be used in next part of test
120--disable_query_log
121eval SET GLOBAL debug='$old_debug';
122--enable_query_log
123DELETE FROM t2;
124RESET MASTER;
125
126-- echo ###################### TEST #4
127
128# Loading a row using LOAD DATA INFILE causing a binary log error
129# should be rolled back.
130
131--disable_query_log
132eval SET GLOBAL debug=IF(LENGTH('$old_debug') > 0, CONCAT('$old_debug', ":d,info,debug,enter,return,query,error_unique_log_filename"), 'd,info,debug,enter,return,query,error_unique_log_filename');
133--enable_query_log
134
135# Table should be empty to start with
136SELECT count(*) FROM t2;
137
138-- replace_result $MYSQLTEST_VARDIR MYSQLTEST_VARDIR
139-- error ER_NO_UNIQUE_LOGFILE
140-- eval LOAD DATA INFILE '$load_file' INTO TABLE t2
141
142# show table
143-- echo # assert: must still be empty since the LOAD DATA INFILE failed
144SELECT count(*) FROM t2;
145
146# clean up the table and the binlog to be used in next part of test
147--disable_query_log
148eval SET GLOBAL debug='$old_debug';
149--enable_query_log
150DELETE FROM t2;
151# Restart the server to enable binary log.
152--let $rpl_server_number= 1
153--source include/rpl_restart_server.inc
154RESET MASTER;
155
156-- echo ###################### TEST #5
157
158### ASSERTION: load the small file into a transactional table and
159###            check that it succeeds
160
161--disable_query_log
162eval SET GLOBAL debug=IF(LENGTH('$old_debug') > 0, CONCAT('$old_debug', ":d,error_unique_log_filename"), 'd,error_unique_log_filename');
163--enable_query_log
164-- replace_result $MYSQLTEST_VARDIR MYSQLTEST_VARDIR
165-- eval LOAD DATA INFILE '$load_file2' INTO TABLE t2
166
167# show table
168-- echo # assert: must show one entry
169SELECT count(*) FROM t2;
170
171# clean up the table and the binlog to be used in next part of test
172--disable_query_log
173eval SET GLOBAL debug='$old_debug';
174--enable_query_log
175DELETE FROM t2;
176RESET MASTER;
177
178-- echo ###################### TEST #6
179
180# A failing LOAD DATA INFILE inside a transaction cause the commit to
181# fail, rolling back the entire statement.
182
183--disable_query_log
184eval SET GLOBAL debug=IF(LENGTH('$old_debug') > 0, CONCAT('$old_debug', ":d,error_unique_log_filename"), 'd,error_unique_log_filename');
185--enable_query_log
186
187-- echo # Table should be empty
188SELECT count(*) FROM t2;
189
190SET AUTOCOMMIT=0;
191INSERT INTO t2 VALUES ('muse');
192-- replace_result $MYSQLTEST_VARDIR MYSQLTEST_VARDIR
193-- eval LOAD DATA INFILE '$load_file' INTO TABLE t2
194INSERT INTO t2 VALUES ('muse');
195-- error ER_NO_UNIQUE_LOGFILE
196COMMIT;
197
198### ACTION: Show the contents of the table after the test
199-- echo # Table should still be empty since the commit failed.
200SELECT count(*) FROM t2;
201
202### ACTION: clean up and move to the next test
203SET AUTOCOMMIT= 1;
204--disable_query_log
205eval SET GLOBAL debug='$old_debug';
206--enable_query_log
207DELETE FROM t2;
208# Restart the server to enable binary log.
209--let $rpl_server_number= 1
210--source include/rpl_restart_server.inc
211RESET MASTER;
212
213-- echo ###################### TEST #7
214
215### ASSERTION: check that on a non-transactional table, if rotation
216###            fails then an error is reported and an incident event
217###            is written to the current binary log.
218
219--disable_query_log
220eval SET GLOBAL debug=IF(LENGTH('$old_debug') > 0, CONCAT('$old_debug', ":d,error_unique_log_filename"), 'd,error_unique_log_filename');
221--enable_query_log
222SELECT count(*) FROM t4;
223-- replace_result $MYSQLTEST_VARDIR MYSQLTEST_VARDIR
224-- error ER_NO_UNIQUE_LOGFILE
225-- eval LOAD DATA INFILE '$load_file' INTO TABLE t4
226
227-- echo # assert: must show 1 entry
228SELECT count(*) FROM t4;
229
230--disable_query_log
231eval SET GLOBAL debug='$old_debug';
232--enable_query_log
233
234# clean up and move to next test
235DELETE FROM t4;
236# Restart the server to enable binary log.
237--let $rpl_server_number= 1
238--source include/rpl_restart_server.inc
239RESET MASTER;
240
241-- echo ###################### TEST #8
242
243### ASSERTION: check that statements end up in error but they succeed
244###            on changing the data.
245
246# Insert some rows into t2, we will both try to insert and delete from
247# it.
248
249SET @xxx = REPEAT('xxx', 1000);
250SET @yyy = REPEAT('yyy', 1000);
251INSERT INTO t2 VALUES (@xxx),(@yyy);
252
253--disable_query_log
254eval SET GLOBAL debug=IF(LENGTH('$old_debug') > 0, CONCAT('$old_debug', ":d,error_unique_log_filename"), 'd,error_unique_log_filename');
255--enable_query_log
256-- echo # must show 0 entries
257SELECT count(*) FROM t4;
258-- echo # must show 2 entries
259SELECT count(*) FROM t2;
260
261-- replace_result $MYSQLTEST_VARDIR MYSQLTEST_VARDIR
262-- error ER_NO_UNIQUE_LOGFILE
263-- 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
270eval 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
273-- replace_result $MYSQLTEST_VARDIR MYSQLTEST_VARDIR
274-- error ER_NO_UNIQUE_LOGFILE
275-- 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
282eval 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
284set @aaa = repeat('aaa',1000);
285set @bbb = repeat('bbb',1000);
286set @ccc = repeat('ccc',1000);
287-- error ER_NO_UNIQUE_LOGFILE
288INSERT INTO t2 VALUES (@aaa), (@bbb), (@ccc);
289
290-- echo # INFO: Count(*) Before Offending DELETEs
291-- echo # assert: must show 1 entry
292SELECT count(*) FROM t4;
293-- echo # assert: must show 2 entries since the LOAD DATA INFILE and
294-- echo # INSERT INTO above was rolled back due to error. Only the
295-- echo # original rows remain
296SELECT count(*) FROM t2;
297
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
303eval 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
306SET @xxx = REPEAT('xxx', 1000);
307SET @yyy = REPEAT('yyy', 1000);
308-- error ER_NO_UNIQUE_LOGFILE
309DELETE 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
316eval 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
319set @aaa = repeat('aaa',1000);
320set @bbb = repeat('bbb',1000);
321set @ccc = repeat('ccc',1000);
322-- error ER_NO_UNIQUE_LOGFILE
323DELETE FROM t2 WHERE a IN (@aaa, @bbb, @ccc) OR 1;
324
325-- echo # INFO: Count(*) After Offending DELETEs
326-- echo # assert: must show zero entries
327SELECT count(*) FROM t4;
328-- echo # assert: must show 2 entries: the original two rows
329SELECT count(*) FROM t2;
330
331# remove fault injection
332--disable_query_log
333eval SET GLOBAL debug='$old_debug';
334--enable_query_log
335
336# Empty t2 for following testing
337DELETE FROM t2;
338
339-- echo ###################### TEST #9
340
341### ASSERTION: check that if we disable binlogging, then statements
342###            succeed.
343--disable_query_log
344eval SET GLOBAL debug=IF(LENGTH('$old_debug') > 0, CONCAT('$old_debug', ":d,error_unique_log_filename"), 'd,error_unique_log_filename');
345--enable_query_log
346SET SQL_LOG_BIN=0;
347INSERT INTO t2 VALUES ('aaa'), ('bbb'), ('ccc'), ('ddd');
348INSERT INTO t4 VALUES ('eee'), ('fff'), ('ggg'), ('hhh');
349-- echo # assert: must show four entries
350SELECT count(*) FROM t2;
351SELECT count(*) FROM t4;
352DELETE FROM t2;
353DELETE FROM t4;
354-- echo # assert: must show zero entries
355SELECT count(*) FROM t2;
356SELECT count(*) FROM t4;
357SET SQL_LOG_BIN=1;
358--disable_query_log
359eval SET GLOBAL debug='$old_debug';
360--enable_query_log
361
362-- echo ###################### TEST #10
363
364### ASSERTION: check that error is reported if there is a failure
365###            while registering the index file and the binary log
366###            file or failure to write the rotate event.
367
368call mtr.add_suppression("MYSQL_BIN_LOG::open failed to sync the index file.");
369call mtr.add_suppression("Could not open .*");
370
371# Restart the server to enable binary log.
372--let $rpl_server_number= 1
373--source include/rpl_restart_server.inc
374RESET MASTER;
375SHOW WARNINGS;
376
377# +d,fault_injection_registering_index => injects fault on MYSQL_BIN_LOG::open
378# normalize strerror message for solaris10-sparc-64bit as long as errno is OK
379--disable_query_log
380eval SET GLOBAL debug=IF(LENGTH('$old_debug') > 0, CONCAT('$old_debug', ":d,fault_injection_registering_index"), 'd,fault_injection_registering_index');
381--enable_query_log
382-- replace_regex /\.[\\\/]master/master/ /errno: 1 - .*\)/errno: 1 - Operation not permitted)/
383-- error ER_CANT_OPEN_FILE
384FLUSH LOGS;
385--disable_query_log
386eval SET GLOBAL debug='$old_debug';
387--enable_query_log
388
389-- error ER_NO_BINARY_LOGGING
390SHOW BINARY LOGS;
391
392# issue some statements and check that they don't fail
393CREATE TABLE t5 (a INT);
394INSERT INTO t4 VALUES ('bbbbb');
395INSERT INTO t2 VALUES ('aaaaa');
396DELETE FROM t4;
397DELETE FROM t2;
398DROP TABLE t5;
399
400-- echo ###################### TEST #11
401
402### ASSERTION: check that error is reported if there is a failure
403###            while opening the index file and the binary log file or
404###            failure to write the rotate event.
405
406# restart the server so that we have binlog again
407--let $rpl_server_number= 1
408--source include/rpl_restart_server.inc
409
410# +d,fault_injection_openning_index => injects fault on MYSQL_BIN_LOG::open_index_file
411--disable_query_log
412eval SET GLOBAL debug=IF(LENGTH('$old_debug') > 0, CONCAT('$old_debug', ":d,fault_injection_openning_index"), 'd,fault_injection_openning_index');
413--enable_query_log
414# normalize strerror message for solaris10-sparc-64bit as long as errno is OK
415-- replace_regex /\.[\\\/]master/master/ /errno: 1 - .*\)/errno: 1 - Operation not permitted)/
416-- error ER_CANT_OPEN_FILE
417FLUSH LOGS;
418--disable_query_log
419eval SET GLOBAL debug='$old_debug';
420--enable_query_log
421
422-- error ER_FLUSH_MASTER_BINLOG_CLOSED
423RESET MASTER;
424
425# issue some statements and check that they don't fail
426CREATE TABLE t5 (a INT);
427INSERT INTO t4 VALUES ('bbbbb');
428INSERT INTO t2 VALUES ('aaaaa');
429DELETE FROM t4;
430DELETE FROM t2;
431DROP TABLE t5;
432
433# restart the server so that we have binlog again
434--let $rpl_server_number= 1
435--source include/rpl_restart_server.inc
436
437-- echo ###################### TEST #12
438
439### ASSERTION: check that error is reported if there is a failure
440###            while writing the rotate event when creating a new log
441###            file.
442
443# +d,fault_injection_new_file_rotate_event => injects fault on MYSQL_BIN_LOG::MYSQL_BIN_LOG::new_file_impl
444--disable_query_log
445eval SET GLOBAL debug=IF(LENGTH('$old_debug') > 0, CONCAT('$old_debug', ":d,fault_injection_new_file_rotate_event"), 'd,fault_injection_new_file_rotate_event');
446--enable_query_log
447-- error ER_ERROR_ON_WRITE
448FLUSH LOGS;
449--disable_query_log
450eval SET GLOBAL debug='$old_debug';
451--enable_query_log
452
453-- error ER_FLUSH_MASTER_BINLOG_CLOSED
454RESET MASTER;
455# issue some statements and check that they don't fail
456CREATE TABLE t5 (a INT);
457INSERT INTO t4 VALUES ('bbbbb');
458INSERT INTO t2 VALUES ('aaaaa');
459DELETE FROM t4;
460DELETE FROM t2;
461DROP TABLE t5;
462
463# restart the server so that we have binlog again
464--let $rpl_server_number= 1
465--source include/rpl_restart_server.inc
466
467## clean up
468--disable_query_log
469eval SET GLOBAL debug= '$old_debug';
470--enable_query_log
471DROP TABLE t1, t2, t4;
472RESET MASTER;
473
474# restart slave again
475-- connection slave
476-- source include/start_slave.inc
477-- connection master
478
479-- echo #######################################################################
480-- echo ####################### PART 2: SLAVE TESTS ###########################
481-- echo #######################################################################
482
483### setup
484--source include/rpl_reset.inc
485-- connection slave
486
487# slave suppressions
488
489call mtr.add_suppression("Slave I/O: Relay log write failure: could not queue event from master.*");
490call mtr.add_suppression("Error writing file .*");
491call mtr.add_suppression("Could not open .*");
492call mtr.add_suppression("MYSQL_BIN_LOG::open failed to sync the index file.");
493call mtr.add_suppression("Can't generate a unique log-filename .*");
494-- echo ###################### TEST #13
495
496#### ASSERTION: check against unique log filename error
497-- let $io_thd_injection_fault_flag= error_unique_log_filename
498-- let $slave_io_errno= 1595
499-- let $show_slave_io_error= 1
500-- source include/io_thd_fault_injection.inc
501
502-- echo ###################### TEST #14
503
504#### ASSERTION: check against rotate failing
505-- let $io_thd_injection_fault_flag= fault_injection_new_file_rotate_event
506-- let $slave_io_errno= 1595
507-- let $show_slave_io_error= 1
508-- source include/io_thd_fault_injection.inc
509
510-- echo ###################### TEST #15
511
512#### ASSERTION: check against relay log open failure
513-- let $io_thd_injection_fault_flag= fault_injection_registering_index
514-- let $slave_io_errno= 1595
515-- let $show_slave_io_error= 1
516-- source include/io_thd_fault_injection.inc
517
518-- echo ###################### TEST #16
519
520#### ASSERTION: check against relay log index open failure
521-- let $io_thd_injection_fault_flag= fault_injection_openning_index
522-- let $slave_io_errno= 1595
523-- let $show_slave_io_error= 1
524-- source include/io_thd_fault_injection.inc
525
526### clean up
527-- source include/stop_slave_sql.inc
528--disable_query_log
529eval SET GLOBAL debug='$old_debug';
530--enable_query_log
531-- remove_file $MYSQLTEST_VARDIR/tmp/bug_46166.data
532-- remove_file $MYSQLTEST_VARDIR/tmp/bug_46166-2.data
533RESET SLAVE;
534RESET MASTER;
535--let $rpl_only_running_threads= 1
536--source include/rpl_end.inc
537