From ba2452f092acdb519043a23d72065d559a92ec21 Mon Sep 17 00:00:00 2001 From: "gbichot@dl145h.mysql.com" <> Date: Fri, 23 Feb 2007 22:23:54 +0100 Subject: [PATCH] Fix for BUG#25628: "mysqlbinlog crashes while processing binary logs". mysqlbinlog prints all row-based events of a single statement as a single "BINLOG" statement containing the concatenation of those events. Big (i.e. >64k) concatenations of row-based events (e.g. Write_rows_log_event) caused mysqlbinlog's IO_CACHE to overflow to a temporary file but the IO_CACHE had not been inited with open_cached_file(), so it tried to create a temporary file in an uninitialized directory (thus failing to create, then to write; some OS errors were printed, and it finally segfaulted). After fixing this, it appeared that mysqlbinlog was printing only a piece of big concatenations of row-based events (it printed at most the size of the IO_CACHE's buffer i.e. 64k); that caused data loss at restore. We fix and test that. Last, mysqlbinlog's printouts looked a bit strange with the informative header (#-prefixed) of groupped Rows_log_event all on one line, so we insert \n. After that, a small bug in the --hexdump code appeared (only if the string to hex-print had its length a multiple of 16), we fix it. --- client/mysqlbinlog.cc | 10 ++++----- mysql-test/r/mysqlbinlog_base64.result | 20 ++++++++++++++++++ mysql-test/t/mysqlbinlog_base64.test | 28 ++++++++++++++++++++++++++ mysys/mf_iocache2.c | 17 +++++++--------- sql/log_event.cc | 9 +++++++-- sql/log_event.h | 15 ++++++++------ 6 files changed, 76 insertions(+), 23 deletions(-) diff --git a/client/mysqlbinlog.cc b/client/mysqlbinlog.cc index 8242a481c5b..8d63ec56a30 100644 --- a/client/mysqlbinlog.cc +++ b/client/mysqlbinlog.cc @@ -487,18 +487,15 @@ write_event_header_and_base64(Log_event *ev, FILE *result_file, DBUG_ENTER("write_event_header_and_base64"); /* Write header and base64 output to cache */ IO_CACHE result_cache; - if (init_io_cache(&result_cache, -1, 0, WRITE_CACHE, 0L, FALSE, - MYF(MY_WME | MY_NABP))) - { + if (open_cached_file(&result_cache, NULL, NULL, 0, MYF(MY_WME | MY_NABP))) return 1; - } ev->print_header(&result_cache, print_event_info, FALSE); ev->print_base64(&result_cache, print_event_info, FALSE); /* Read data from cache and write to result file */ my_b_copy_to_file(&result_cache, result_file); - end_io_cache(&result_cache); + close_cached_file(&result_cache); DBUG_RETURN(0); } @@ -1016,6 +1013,9 @@ static int dump_log_entries(const char* logname) { int rc; PRINT_EVENT_INFO print_event_info; + + if (!print_event_info.init_ok()) + return 1; /* Set safe delimiter, to dump things like CREATE PROCEDURE safely diff --git a/mysql-test/r/mysqlbinlog_base64.result b/mysql-test/r/mysqlbinlog_base64.result index 33047a8774d..b62023e0ccf 100644 --- a/mysql-test/r/mysqlbinlog_base64.result +++ b/mysql-test/r/mysqlbinlog_base64.result @@ -86,5 +86,25 @@ Aberdeen Abernathy aberrant aberration +flush logs; +drop table t2; +create table t2 (word varchar(20)); +load data infile '../std_data_ln/words.dat' into table t2; +insert into t2 select * from t2; +insert into t2 select * from t2; +insert into t2 select * from t2; +insert into t2 select * from t2; +insert into t2 select * from t2; +insert into t2 select * from t2; +insert into t2 select * from t2; +insert into t2 select * from t2; +insert into t2 select * from t2; +select count(*) from t2; +count(*) +35840 +flush logs; +select count(*) from t2; +count(*) +35840 drop table t1; drop table t2; diff --git a/mysql-test/t/mysqlbinlog_base64.test b/mysql-test/t/mysqlbinlog_base64.test index 1ca018218b2..1b5dc67c150 100644 --- a/mysql-test/t/mysqlbinlog_base64.test +++ b/mysql-test/t/mysqlbinlog_base64.test @@ -31,6 +31,34 @@ drop table t2; select * from t1; select * from t2; +# +# Verify that events larger than the default IO_CACHE buffer +# are handled correctly (BUG#25628). +# +flush logs; +drop table t2; +create table t2 (word varchar(20)); +load data infile '../std_data_ln/words.dat' into table t2; +insert into t2 select * from t2; +insert into t2 select * from t2; +insert into t2 select * from t2; +insert into t2 select * from t2; +insert into t2 select * from t2; +insert into t2 select * from t2; +insert into t2 select * from t2; +insert into t2 select * from t2; +insert into t2 select * from t2; +select count(*) from t2; + +flush logs; +--exec $MYSQL_BINLOG --hexdump $MYSQLTEST_VARDIR/log/master-bin.000003 > $MYSQLTEST_VARDIR/tmp/mysqlbinlog_base64.sql +--exec $MYSQL test < $MYSQLTEST_VARDIR/tmp/mysqlbinlog_base64.sql + +# +# Verify that all binlog events have been executed +# +select count(*) from t2; + # # Test cleanup # diff --git a/mysys/mf_iocache2.c b/mysys/mf_iocache2.c index 7b3393da4f5..a85f741bd67 100644 --- a/mysys/mf_iocache2.c +++ b/mysys/mf_iocache2.c @@ -50,7 +50,6 @@ int my_b_copy_to_file(IO_CACHE *cache, FILE *file) { - byte buf[IO_SIZE]; uint bytes_in_cache; DBUG_ENTER("my_b_copy_to_file"); @@ -58,19 +57,17 @@ my_b_copy_to_file(IO_CACHE *cache, FILE *file) if (reinit_io_cache(cache, READ_CACHE, 0L, FALSE, FALSE)) DBUG_RETURN(1); bytes_in_cache= my_b_bytes_in_cache(cache); - while (bytes_in_cache > 0) { - uint const read_bytes= min(bytes_in_cache, sizeof(buf)); - DBUG_PRINT("debug", ("Remaining %u bytes - Reading %u bytes", - bytes_in_cache, read_bytes)); - if (my_b_read(cache, buf, read_bytes)) + do + { + if (my_fwrite(file, cache->read_pos, bytes_in_cache, + MYF(MY_WME | MY_NABP)) == (uint) -1) DBUG_RETURN(1); - if (my_fwrite(file, buf, read_bytes, MYF(MY_WME | MY_NABP)) == (uint) -1) - DBUG_RETURN(1); - bytes_in_cache -= read_bytes; - } + cache->read_pos= cache->read_end; + } while ((bytes_in_cache= my_b_fill(cache))); DBUG_RETURN(0); } + my_off_t my_b_append_tell(IO_CACHE* info) { /* diff --git a/sql/log_event.cc b/sql/log_event.cc index a326e226320..e4df8d71dc6 100644 --- a/sql/log_event.cc +++ b/sql/log_event.cc @@ -1144,13 +1144,18 @@ void Log_event::print_header(IO_CACHE* file, char emit_buf[256]; int const bytes_written= my_snprintf(emit_buf, sizeof(emit_buf), - "# %8.8lx %-48.48s |%s|\n# ", + "# %8.8lx %-48.48s |%s|\n", (unsigned long) (hexdump_from + (i & 0xfffffff0)), hex_string, char_string); DBUG_ASSERT(bytes_written >= 0); DBUG_ASSERT(static_cast(bytes_written) < sizeof(emit_buf)); my_b_write(file, (byte*) emit_buf, bytes_written); } + /* + need a # to prefix the rest of printouts for example those of + Rows_log_event::print_helper(). + */ + my_b_write(file, "# ", 2); } DBUG_VOID_RETURN; } @@ -6106,7 +6111,7 @@ void Rows_log_event::print_helper(FILE *file, { bool const last_stmt_event= get_flags(STMT_END_F); print_header(head, print_event_info, !last_stmt_event); - my_b_printf(head, "\t%s: table id %lu", name, m_table_id); + my_b_printf(head, "\t%s: table id %lu\n", name, m_table_id); print_base64(body, print_event_info, !last_stmt_event); } diff --git a/sql/log_event.h b/sql/log_event.h index 20a3ca1b97e..ac7bc0cb082 100644 --- a/sql/log_event.h +++ b/sql/log_event.h @@ -546,16 +546,19 @@ typedef struct st_print_event_info bzero(db, sizeof(db)); bzero(charset, sizeof(charset)); bzero(time_zone_str, sizeof(time_zone_str)); - strcpy(delimiter, ";"); - uint const flags = MYF(MY_WME | MY_NABP); - init_io_cache(&head_cache, -1, 0, WRITE_CACHE, 0L, FALSE, flags); - init_io_cache(&body_cache, -1, 0, WRITE_CACHE, 0L, FALSE, flags); + delimiter[0]= ';'; + delimiter[1]= 0; + myf const flags = MYF(MY_WME | MY_NABP); + open_cached_file(&head_cache, NULL, NULL, 0, flags); + open_cached_file(&body_cache, NULL, NULL, 0, flags); } ~st_print_event_info() { - end_io_cache(&head_cache); - end_io_cache(&body_cache); + close_cached_file(&head_cache); + close_cached_file(&body_cache); } + bool init_ok() /* tells if construction was successful */ + { return my_b_inited(&head_cache) && my_b_inited(&body_cache); } /* Settings on how to print the events */