Commit 5cc348a6 authored by sven@riska.(none)'s avatar sven@riska.(none)

BUG#32407: Impossible to do point-in-time recovery from older binlog

Problem: it is unsafe to read base64-printed events without first
reading the Format_description_log_event (FD).  Currently, mysqlbinlog
cannot print the FD.

As a side effect, another bug has also been fixed: When mysqlbinlog
--start-position=X was specified, no ROLLBACK was printed. I changed
this, so that ROLLBACK is always printed.

This patch does several things:

 - Format_description_log_event (FD) now print themselves in base64
   format.

 - mysqlbinlog is now able to print FD events.  It has three modes:
    --base64-output=auto    Print row events in base64 output, and print
                            FD event.  The FD event is printed even if
                            it is outside the range specified with
                            --start-position, because it would not be
                            safe to read row events otherwise. This is
                            the default.

    --base64-output=always  Like --base64-output=auto, but also print
                            base64 output for query events.  This is
                            like the old --base64-output flag, which
                            is also a shorthand for
                            --base64-output=always

    --base64-output=never   Never print base64 output, generate error if
                            row events occur in binlog.  This is
                            useful to suppress the FD event in binlogs
                            known not to contain row events (e.g.,
                            because BINLOG statement is unsafe,
                            requires root privileges, is not SQL, etc)

 - the BINLOG statement now handles FD events correctly, by setting
   the thread's rli's relay log's description_event_for_exec to the
   loaded event.

   In fact, executing a BINLOG statement is almost the same as reading
   an event from a relay log.  Before my patch, the code for this was
   separated (exec_relay_log_event in slave.cc executes events from
   the relay log, mysql_client_binlog_statement in sql_binlog.cc
   executes BINLOG statements).  I needed to augment
   mysql_client_binlog_statement to do parts of what
   exec_relay_log_event does.  Hence, I did a small refactoring and
   moved parts of exec_relay_log_event to a new function, which I
   named apply_event_and_update_pos.  apply_event_and_update_pos is
   called both from exec_relay_log_event and from
   mysql_client_binlog_statement.

 - When a non-FD event is executed in a BINLOG statement, without
   previously executing a FD event in a BINLOG statement, it generates
   an error, because that's unsafe.  I took a new error code for that:
   ER_NO_FORMAT_DESCRIPTION_EVENT_BEFORE_BINLOG_STATEMENTS.

   In order to get a decent error message containing the name of the
   event, I added the class method char*
   Log_event::get_type_str(Log_event_type type), which returns a
   string name for the given Log_event_type.  This is just like the
   existing char* Log_event::get_type_str(), except it is a class
   method that takes the log event type as parameter.

   I also added PRE_GA_*_ROWS_LOG_EVENT to Log_event::get_type_str(),
   so that names of old rows event are properly printed.

 - When reading an event, I added a check that the event type is known
   by the current Format_description_log_event. Without this, it may
   crash on bad input (and I was struck by this several times).

 - I patched the following test cases, which all contain BINLOG
   statements for row events which must be preceded by BINLOG
   statements for FD events:
    - rpl_bug31076

While I was here, I fixed some small things in log_event.cc:

 - replaced hard-coded 4 by EVENT_TYPE_OFFSET in 3 places

 - replaced return by DBUG_VOID_RETURN in one place

 - The name of the logfile can be '-' to indicate stdin.  Before my
   patch, the code just checked if the first character is '-'; now it
   does a full strcmp().  Probably, all arguments that begin with a -
   are already handled somewhere else as flags, but I still think it
   is better that the code reflects what it is supposed to do, with as
   little dependencies as possible on other parts of the code.  If we
   one day implement that all command line arguments after -- are
   files (as most unix tools do), then we need this.

I also fixed the following in slave.cc:

 - next_event() was declared twice, and queue_event was not static but
   should be static (not used outside the file).
parent ab396c1d
...@@ -77,7 +77,7 @@ enum options_client ...@@ -77,7 +77,7 @@ enum options_client
OPT_SLAP_POST_SYSTEM, OPT_SLAP_POST_SYSTEM,
OPT_SLAP_COMMIT, OPT_SLAP_COMMIT,
OPT_SLAP_DETACH, OPT_SLAP_DETACH,
OPT_MYSQL_REPLACE_INTO, OPT_BASE64_OUTPUT, OPT_SERVER_ID, OPT_MYSQL_REPLACE_INTO, OPT_BASE64_OUTPUT_MODE, OPT_SERVER_ID,
OPT_FIX_TABLE_NAMES, OPT_FIX_DB_NAMES, OPT_SSL_VERIFY_SERVER_CERT, OPT_FIX_TABLE_NAMES, OPT_FIX_DB_NAMES, OPT_SSL_VERIFY_SERVER_CERT,
OPT_DEBUG_INFO, OPT_DEBUG_CHECK, OPT_COLUMN_TYPES, OPT_ERROR_LOG_FILE, OPT_DEBUG_INFO, OPT_DEBUG_CHECK, OPT_COLUMN_TYPES, OPT_ERROR_LOG_FILE,
OPT_WRITE_BINLOG, OPT_DUMP_DATE, OPT_WRITE_BINLOG, OPT_DUMP_DATE,
......
This diff is collapsed.
...@@ -106,6 +106,7 @@ ROLLBACK /* added by mysqlbinlog */; ...@@ -106,6 +106,7 @@ ROLLBACK /* added by mysqlbinlog */;
/*!40019 SET @@session.max_insert_delayed_threads=0*/; /*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/; /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/; DELIMITER /*!*/;
ROLLBACK/*!*/;
SET INSERT_ID=4/*!*/; SET INSERT_ID=4/*!*/;
use test/*!*/; use test/*!*/;
SET TIMESTAMP=1579609946/*!*/; SET TIMESTAMP=1579609946/*!*/;
...@@ -152,6 +153,7 @@ ROLLBACK /* added by mysqlbinlog */; ...@@ -152,6 +153,7 @@ ROLLBACK /* added by mysqlbinlog */;
/*!40019 SET @@session.max_insert_delayed_threads=0*/; /*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/; /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/; DELIMITER /*!*/;
ROLLBACK/*!*/;
SET INSERT_ID=4/*!*/; SET INSERT_ID=4/*!*/;
use test/*!*/; use test/*!*/;
SET TIMESTAMP=1579609946/*!*/; SET TIMESTAMP=1579609946/*!*/;
...@@ -299,6 +301,7 @@ ROLLBACK /* added by mysqlbinlog */; ...@@ -299,6 +301,7 @@ ROLLBACK /* added by mysqlbinlog */;
/*!40019 SET @@session.max_insert_delayed_threads=0*/; /*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/; /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/; DELIMITER /*!*/;
ROLLBACK/*!*/;
SET INSERT_ID=4/*!*/; SET INSERT_ID=4/*!*/;
use test/*!*/; use test/*!*/;
SET TIMESTAMP=1579609946/*!*/; SET TIMESTAMP=1579609946/*!*/;
......
==== Test BUG#32407 ====
select * from t1;
a
1
1
==== Test BINLOG statement w/o FD event ====
BINLOG '
SVtYRxMBAAAAKQAAADQBAAAAABAAAAAAAAAABHRlc3QAAnQxAAEDAAE=
SVtYRxcBAAAAIgAAAFYBAAAQABAAAAAAAAEAAf/+AgAAAA==
';
ERROR HY000: The BINLOG statement of type `Table_map` was not preceded by a format description BINLOG statement.
select * from t1;
a
1
1
==== Test BINLOG statement with FD event ====
BINLOG '
ODdYRw8BAAAAZgAAAGoAAAABAAQANS4xLjIzLXJjLWRlYnVnLWxvZwAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAA4N1hHEzgNAAgAEgAEBAQEEgAAUwAEGggAAAAICAgC
';
BINLOG '
TFtYRxMBAAAAKQAAAH8BAAAAABAAAAAAAAAABHRlc3QAAnQxAAEDAAE=
TFtYRxcBAAAAIgAAAKEBAAAQABAAAAAAAAEAAf/+AwAAAA==
';
select * from t1;
a
1
1
3
==== Test --base64-output=never on a binlog with row events ====
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#ROLLBACK/*!*/;
# at 102
#use test/*!*/;
SET TIMESTAMP=1196959712/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=1, @@session.unique_checks=1/*!*/;
SET @@session.sql_mode=0/*!*/;
/*!\C latin1 *//*!*/;
SET @@session.character_set_client=8,@@session.collation_connection=8,@@session.collation_server=8/*!*/;
create table t1 (a int) engine= myisam/*!*/;
# at 203
==== Test non-matching FD event and Row event ====
BINLOG '
4CdYRw8BAAAAYgAAAGYAAAAAAAQANS4xLjE1LW5kYi02LjEuMjQtZGVidWctbG9nAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAADgJ1hHEzgNAAgAEgAEBAQEEgAATwAEGggICAg=
';
BINLOG '
Dl1YRxMBAAAAKQAAADQBAAAAABAAAAAAAAAABHRlc3QAAnQxAAEDAAE=
Dl1YRxcBAAAAIgAAAFYBAAAQABAAAAAAAAEAAf/+BQAAAA==
';
ERROR 42000: You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use
select * from t1;
a
1
1
3
drop table t1;
# This test case verifies that the mysqlbinlog --base64-output=X flags
# work as expected, and that BINLOG statements with row events fail if
# they are not preceded by BINLOG statements with Format description
# events.
#
# See also BUG#32407.
# Test to show BUG#32407. This reads a binlog created with the
# mysql-5.1-telco-6.1 tree, specifically at the tag
# mysql-5.1.15-ndb-6.1.23, and applies it to the database. The test
# should fail before BUG#32407 was fixed and succeed afterwards.
--echo ==== Test BUG#32407 ====
# The binlog contains row events equivalent to:
# CREATE TABLE t1 (a int) engine = myisam
# INSERT INTO t1 VALUES (1), (1)
exec $MYSQL_BINLOG suite/binlog/std_data/binlog-bug32407.000001 | $MYSQL;
# The above line should succeed and t1 should contain two ones
select * from t1;
# Test that a BINLOG statement encoding a row event fails unless a
# Format_description_event as been supplied with an earlier BINLOG
# statement.
--echo ==== Test BINLOG statement w/o FD event ====
# This is a binlog statement consisting of one Table_map_log_event and
# one Write_rows_log_event. Together, they correspond to the
# following query:
# INSERT INTO TABLE test.t1 VALUES (2)
error ER_NO_FORMAT_DESCRIPTION_EVENT_BEFORE_BINLOG_STATEMENT;
BINLOG '
SVtYRxMBAAAAKQAAADQBAAAAABAAAAAAAAAABHRlc3QAAnQxAAEDAAE=
SVtYRxcBAAAAIgAAAFYBAAAQABAAAAAAAAEAAf/+AgAAAA==
';
# The above line should fail and 2 should not be in the table
select * from t1;
# Test that it works to read a Format_description_log_event with a
# BINLOG statement, followed by a row-event in base64 from the same
# version.
--echo ==== Test BINLOG statement with FD event ====
# This is a binlog statement containing a Format_description_log_event
# from the same version as the Table_map and Write_rows_log_event.
BINLOG '
ODdYRw8BAAAAZgAAAGoAAAABAAQANS4xLjIzLXJjLWRlYnVnLWxvZwAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAA4N1hHEzgNAAgAEgAEBAQEEgAAUwAEGggAAAAICAgC
';
# This is a Table_map_log_event+Write_rows_log_event corresponding to:
# INSERT INTO TABLE test.t1 VALUES (3)
BINLOG '
TFtYRxMBAAAAKQAAAH8BAAAAABAAAAAAAAAABHRlc3QAAnQxAAEDAAE=
TFtYRxcBAAAAIgAAAKEBAAAQABAAAAAAAAEAAf/+AwAAAA==
';
# The above line should succeed and 3 should be in the table
select * from t1;
# Test that mysqlbinlog stops with an error message when the
# --base64-output=never flag is used on a binlog with base64 events.
--echo ==== Test --base64-output=never on a binlog with row events ====
# mysqlbinlog should fail
--replace_regex /#[0-9][0-9][0-9][0-9][0-9][0-9] .*/#/
error 1;
exec $MYSQL_BINLOG --base64-output=never suite/binlog/std_data/binlog-bug32407.000001;
# the above line should output the query log event and then stop
# Test that the following fails cleanly: "First, read a
# Format_description event which has N event types. Then, read an
# event of type M>N"
--echo ==== Test non-matching FD event and Row event ====
# This is the Format_description_log_event from
# binlog-bug32407.000001, encoded in base64. It contains only the old
# row events (number of event types is 22)
BINLOG '
4CdYRw8BAAAAYgAAAGYAAAAAAAQANS4xLjE1LW5kYi02LjEuMjQtZGVidWctbG9nAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAADgJ1hHEzgNAAgAEgAEBAQEEgAATwAEGggICAg=
';
# The following is a Write_rows_log_event with event type 23, i.e.,
# not supported by the Format_description_log_event above. It
# corresponds to the following query:
# INSERT INTO t1 VALUES (5)
error 1149;
BINLOG '
Dl1YRxMBAAAAKQAAADQBAAAAABAAAAAAAAAABHRlc3QAAnQxAAEDAAE=
Dl1YRxcBAAAAIgAAAFYBAAAQABAAAAAAAAEAAf/+BQAAAA==
';
# the above line should fail and 5 should not be in the binlog.
select * from t1;
# clean up
drop table t1;
...@@ -9,3 +9,4 @@ ...@@ -9,3 +9,4 @@
# Do not use any TAB characters for whitespace. # Do not use any TAB characters for whitespace.
# #
############################################################################## ##############################################################################
binlog_base64_flag : BUG#33247 2007-12-14 Sven: mysqlbinlog does not clean up after itself on termination. When compiled in debug mode, this test generates lots of warnings for memory leaks.
...@@ -40,6 +40,10 @@ KEY `data` (`data`) ...@@ -40,6 +40,10 @@ KEY `data` (`data`)
/*!40019 SET @@session.max_insert_delayed_threads=0*/; /*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/; /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
BINLOG ' BINLOG '
O1ZVRw8BAAAAZgAAAGoAAAAAAAQANS4xLjIzLXJjLWRlYnVnLWxvZwAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAA7VlVHEzgNAAgAEgAEBAQEEgAAUwAEGggAAAAICAgC
'/*!*/;
BINLOG '
Bk3vRhO0AQAAOAAAALcLyQkAAJlXFwIAAAAABXRyYWNrAA12aXNpdHNfZXZlbnRzAAYJAwcPDwM= Bk3vRhO0AQAAOAAAALcLyQkAAJlXFwIAAAAABXRyYWNrAA12aXNpdHNfZXZlbnRzAAYJAwcPDwM=
Bk3vRhe0AQAAWgAAABEMyQkQAJlXFwIAAAEABv/AIE4AvvVDAQZN70YAK0Rvd25sb2Fkcy9NeVNR Bk3vRhe0AQAAWgAAABEMyQkQAJlXFwIAAAEABv/AIE4AvvVDAQZN70YAK0Rvd25sb2Fkcy9NeVNR
TC00LjEvbXlzcWwtNC4xLjEyYS13aW4zMi56aXBPaAIC TC00LjEvbXlzcWwtNC4xLjEyYS13aW4zMi56aXBPaAIC
......
...@@ -155,6 +155,7 @@ c1 c3 c4 c5 ...@@ -155,6 +155,7 @@ c1 c3 c4 c5
/*!40019 SET @@session.max_insert_delayed_threads=0*/; /*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/; /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/; DELIMITER /*!*/;
ROLLBACK/*!*/;
use test/*!*/; use test/*!*/;
SET TIMESTAMP=1000000000/*!*/; SET TIMESTAMP=1000000000/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=1, @@session.unique_checks=1/*!*/; SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=1, @@session.unique_checks=1/*!*/;
...@@ -295,6 +296,7 @@ ROLLBACK /* added by mysqlbinlog */; ...@@ -295,6 +296,7 @@ ROLLBACK /* added by mysqlbinlog */;
/*!40019 SET @@session.max_insert_delayed_threads=0*/; /*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/; /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/; DELIMITER /*!*/;
ROLLBACK/*!*/;
use test/*!*/; use test/*!*/;
SET TIMESTAMP=1000000000/*!*/; SET TIMESTAMP=1000000000/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=1, @@session.unique_checks=1/*!*/; SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=1, @@session.unique_checks=1/*!*/;
......
...@@ -39,6 +39,24 @@ CREATE TABLE `visits_events` ( ...@@ -39,6 +39,24 @@ CREATE TABLE `visits_events` (
/*!40019 SET @@session.max_insert_delayed_threads=0*/; /*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/; /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
--delimiter /*!*/; --delimiter /*!*/;
# at 4 (0x4)
#071204 14:29:31 server id 1 end_log_pos 106
# Position Timestamp Type Master ID Size Master Pos Flags
# 4 3b 56 55 47 0f 01 00 00 00 66 00 00 00 6a 00 00 00 00 00
# 17 04 00 35 2e 31 2e 32 33 2d 72 63 2d 64 65 62 75 |..5.1.23.rc.debu|
# 27 67 2d 6c 6f 67 00 00 00 00 00 00 00 00 00 00 00 |g.log...........|
# 37 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
# 47 00 00 00 00 3b 56 55 47 13 38 0d 00 08 00 12 00 |.....VUG.8......|
# 57 04 04 04 04 12 00 00 53 00 04 1a 08 00 00 00 08 |.......S........|
# 67 08 08 02 |...|
# Start: binlog v 4, server v 5.1.23-rc-debug-log created 071204 14:29:31 at startup
BINLOG '
O1ZVRw8BAAAAZgAAAGoAAAAAAAQANS4xLjIzLXJjLWRlYnVnLWxvZwAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAA7VlVHEzgNAAgAEgAEBAQEEgAAUwAEGggAAAAICAgC
'/*!*/;
# at 164170623 # at 164170623
# at 164170679 # at 164170679
#7918 3:59:2 server id 436 end_log_pos 164170679 #7918 3:59:2 server id 436 end_log_pos 164170679
......
...@@ -42,7 +42,7 @@ select "--- Local --" as ""; ...@@ -42,7 +42,7 @@ select "--- Local --" as "";
# #
--replace_regex /[[:<:]][0-9]{6} [0-9 ][0-9]:[0-9]{2}:[0-9]{2}[[:>:]]/{yymmdd} {HH:MM:SS}/ /=[0-9]+ /={integer} / /# at [0-9]+/# at {pos}/ /(pos:?) [0-9]+/\1 {pos}/ /binlog v [0-9]+, server v [^ ]* created/binlog v #, server v ## created/ --replace_regex /[[:<:]][0-9]{6} [0-9 ][0-9]:[0-9]{2}:[0-9]{2}[[:>:]]/{yymmdd} {HH:MM:SS}/ /=[0-9]+ /={integer} / /# at [0-9]+/# at {pos}/ /(pos:?) [0-9]+/\1 {pos}/ /binlog v [0-9]+, server v [^ ]* created/binlog v #, server v ## created/
--exec $MYSQL_BINLOG $MYSQLTEST_VARDIR/log/master-bin.000001 --exec $MYSQL_BINLOG --base64-output=never $MYSQLTEST_VARDIR/log/master-bin.000001
--disable_query_log --disable_query_log
select "--- offset --" as ""; select "--- offset --" as "";
......
...@@ -491,9 +491,9 @@ static void print_set_option(IO_CACHE* file, uint32 bits_changed, ...@@ -491,9 +491,9 @@ static void print_set_option(IO_CACHE* file, uint32 bits_changed,
Log_event::get_type_str() Log_event::get_type_str()
*/ */
const char* Log_event::get_type_str() const char* Log_event::get_type_str(Log_event_type type)
{ {
switch(get_type_code()) { switch(type) {
case START_EVENT_V3: return "Start_v3"; case START_EVENT_V3: return "Start_v3";
case STOP_EVENT: return "Stop"; case STOP_EVENT: return "Stop";
case QUERY_EVENT: return "Query"; case QUERY_EVENT: return "Query";
...@@ -524,6 +524,11 @@ const char* Log_event::get_type_str() ...@@ -524,6 +524,11 @@ const char* Log_event::get_type_str()
} }
} }
const char* Log_event::get_type_str()
{
return get_type_str(get_type_code());
}
/* /*
Log_event::Log_event() Log_event::Log_event()
...@@ -1050,7 +1055,23 @@ Log_event* Log_event::read_log_event(const char* buf, uint event_len, ...@@ -1050,7 +1055,23 @@ Log_event* Log_event::read_log_event(const char* buf, uint event_len,
DBUG_RETURN(NULL); // general sanity check - will fail on a partial read DBUG_RETURN(NULL); // general sanity check - will fail on a partial read
} }
switch(buf[EVENT_TYPE_OFFSET]) { uint event_type= buf[EVENT_TYPE_OFFSET];
if (event_type > description_event->number_of_event_types &&
event_type != FORMAT_DESCRIPTION_EVENT)
{
/*
It is unsafe to use the description_event if its post_header_len
array does not include the event type.
*/
DBUG_PRINT("error", ("event type %d found, but the current "
"Format_description_log_event supports only %d event "
"types", event_type,
description_event->number_of_event_types));
ev= NULL;
}
else
{
switch(event_type) {
case QUERY_EVENT: case QUERY_EVENT:
ev = new Query_log_event(buf, event_len, description_event, QUERY_EVENT); ev = new Query_log_event(buf, event_len, description_event, QUERY_EVENT);
break; break;
...@@ -1139,6 +1160,7 @@ Log_event* Log_event::read_log_event(const char* buf, uint event_len, ...@@ -1139,6 +1160,7 @@ Log_event* Log_event::read_log_event(const char* buf, uint event_len,
ev= NULL; ev= NULL;
break; break;
} }
}
DBUG_PRINT("read_event", ("%s(type_code: %d; event_len: %d)", DBUG_PRINT("read_event", ("%s(type_code: %d; event_len: %d)",
ev ? ev->get_type_str() : "<unknown>", ev ? ev->get_type_str() : "<unknown>",
...@@ -2604,6 +2626,14 @@ void Start_log_event_v3::print(FILE* file, PRINT_EVENT_INFO* print_event_info) ...@@ -2604,6 +2626,14 @@ void Start_log_event_v3::print(FILE* file, PRINT_EVENT_INFO* print_event_info)
my_b_printf(&cache,"ROLLBACK%s\n", print_event_info->delimiter); my_b_printf(&cache,"ROLLBACK%s\n", print_event_info->delimiter);
#endif #endif
} }
if (temp_buf &&
print_event_info->base64_output_mode != BASE64_OUTPUT_NEVER &&
!print_event_info->short_form)
{
my_b_printf(&cache, "BINLOG '\n");
print_base64(&cache, print_event_info, FALSE);
print_event_info->printed_fd_event= TRUE;
}
DBUG_VOID_RETURN; DBUG_VOID_RETURN;
} }
#endif /* MYSQL_CLIENT */ #endif /* MYSQL_CLIENT */
...@@ -5050,7 +5080,7 @@ Create_file_log_event::Create_file_log_event(const char* buf, uint len, ...@@ -5050,7 +5080,7 @@ Create_file_log_event::Create_file_log_event(const char* buf, uint len,
Load_log_event::get_data_size() + Load_log_event::get_data_size() +
create_file_header_len + 1); create_file_header_len + 1);
if (len < block_offset) if (len < block_offset)
return; DBUG_VOID_RETURN;
block = (char*)buf + block_offset; block = (char*)buf + block_offset;
block_len = len - block_offset; block_len = len - block_offset;
} }
......
...@@ -567,6 +567,15 @@ class Format_description_log_event; ...@@ -567,6 +567,15 @@ class Format_description_log_event;
class Relay_log_info; class Relay_log_info;
#ifdef MYSQL_CLIENT #ifdef MYSQL_CLIENT
enum enum_base64_output_mode {
BASE64_OUTPUT_NEVER= 0,
BASE64_OUTPUT_AUTO= 1,
BASE64_OUTPUT_ALWAYS= 2,
BASE64_OUTPUT_UNSPEC= 3,
/* insert new output modes here */
BASE64_OUTPUT_MODE_COUNT
};
/* /*
A structure for mysqlbinlog to know how to print events A structure for mysqlbinlog to know how to print events
...@@ -600,7 +609,8 @@ typedef struct st_print_event_info ...@@ -600,7 +609,8 @@ typedef struct st_print_event_info
st_print_event_info() st_print_event_info()
:flags2_inited(0), sql_mode_inited(0), :flags2_inited(0), sql_mode_inited(0),
auto_increment_increment(1),auto_increment_offset(1), charset_inited(0), auto_increment_increment(1),auto_increment_offset(1), charset_inited(0),
lc_time_names_number(0), charset_database_number(0) lc_time_names_number(0), charset_database_number(0),
base64_output_mode(BASE64_OUTPUT_UNSPEC), printed_fd_event(FALSE)
{ {
/* /*
Currently we only use static PRINT_EVENT_INFO objects, so zeroed at Currently we only use static PRINT_EVENT_INFO objects, so zeroed at
...@@ -627,7 +637,14 @@ typedef struct st_print_event_info ...@@ -627,7 +637,14 @@ typedef struct st_print_event_info
/* Settings on how to print the events */ /* Settings on how to print the events */
bool short_form; bool short_form;
bool base64_output; enum_base64_output_mode base64_output_mode;
/*
This is set whenever a Format_description_event is printed.
Later, when an event is printed in base64, this flag is tested: if
no Format_description_event has been seen, it is unsafe to print
the base64 event, so an error message is generated.
*/
bool printed_fd_event;
my_off_t hexdump_from; my_off_t hexdump_from;
uint8 common_header_len; uint8 common_header_len;
char delimiter[16]; char delimiter[16];
...@@ -936,7 +953,13 @@ class Log_event ...@@ -936,7 +953,13 @@ class Log_event
const char **error, const char **error,
const Format_description_log_event const Format_description_log_event
*description_event); *description_event);
/* returns the human readable name of the event's type */ /**
Returns the human readable name of the given event type.
*/
static const char* get_type_str(Log_event_type type);
/**
Returns the human readable name of this event's type.
*/
const char* get_type_str(); const char* get_type_str();
/* Return start of query time or current time */ /* Return start of query time or current time */
......
...@@ -6116,3 +6116,6 @@ ER_CANT_CREATE_SROUTINE ...@@ -6116,3 +6116,6 @@ ER_CANT_CREATE_SROUTINE
eng "Cannot create stored routine `%-.64s`. Check warnings" eng "Cannot create stored routine `%-.64s`. Check warnings"
ER_SLAVE_AMBIGOUS_EXEC_MODE ER_SLAVE_AMBIGOUS_EXEC_MODE
eng "Ambiguous slave modes combination. %s" eng "Ambiguous slave modes combination. %s"
ER_NO_FORMAT_DESCRIPTION_EVENT_BEFORE_BINLOG_STATEMENT
eng "The BINLOG statement of type `%s` was not preceded by a format description BINLOG statement."
...@@ -13,6 +13,17 @@ ...@@ -13,6 +13,17 @@
along with this program; if not, write to the Free Software along with this program; if not, write to the Free Software
Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA */ Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA */
/**
@addtogroup Replication
@{
@file
@brief Code to run the io thread and the sql thread on the
replication slave.
*/
#include "mysql_priv.h" #include "mysql_priv.h"
#include <mysql.h> #include <mysql.h>
...@@ -33,10 +44,6 @@ ...@@ -33,10 +44,6 @@
#include "rpl_tblmap.h" #include "rpl_tblmap.h"
int queue_event(Master_info* mi,const char* buf,ulong event_len);
static Log_event* next_event(Relay_log_info* rli);
#define FLAGSTR(V,F) ((V)&(F)?#F" ":"") #define FLAGSTR(V,F) ((V)&(F)?#F" ":"")
#define MAX_SLAVE_RETRY_PAUSE 5 #define MAX_SLAVE_RETRY_PAUSE 5
...@@ -132,6 +139,7 @@ static int create_table_from_dump(THD* thd, MYSQL *mysql, const char* db, ...@@ -132,6 +139,7 @@ static int create_table_from_dump(THD* thd, MYSQL *mysql, const char* db,
const char* table_name, bool overwrite); const char* table_name, bool overwrite);
static int get_master_version_and_clock(MYSQL* mysql, Master_info* mi); static int get_master_version_and_clock(MYSQL* mysql, Master_info* mi);
static Log_event* next_event(Relay_log_info* rli); static Log_event* next_event(Relay_log_info* rli);
static int queue_event(Master_info* mi,const char* buf,ulong event_len);
static int terminate_slave_thread(THD *thd, static int terminate_slave_thread(THD *thd,
pthread_mutex_t* term_lock, pthread_mutex_t* term_lock,
pthread_cond_t* term_cond, pthread_cond_t* term_cond,
...@@ -1757,62 +1765,48 @@ static int has_temporary_error(THD *thd) ...@@ -1757,62 +1765,48 @@ static int has_temporary_error(THD *thd)
DBUG_RETURN(0); DBUG_RETURN(0);
} }
static int exec_relay_log_event(THD* thd, Relay_log_info* rli)
{
DBUG_ENTER("exec_relay_log_event");
/* /**
We acquire this mutex since we need it for all operations except Applies the given event and advances the relay log position.
event execution. But we will release it in places where we will
wait for something for example inside of next_event().
*/
pthread_mutex_lock(&rli->data_lock);
/*
This tests if the position of the end of the last previous executed event
hits the UNTIL barrier.
We would prefer to test if the position of the start (or possibly) end of
the to-be-read event hits the UNTIL barrier, this is different if there
was an event ignored by the I/O thread just before (BUG#13861 to be
fixed).
*/
if (rli->until_condition!=Relay_log_info::UNTIL_NONE &&
rli->is_until_satisfied())
{
char buf[22];
sql_print_information("Slave SQL thread stopped because it reached its"
" UNTIL position %s", llstr(rli->until_pos(), buf));
/*
Setting abort_slave flag because we do not want additional message about
error in query execution to be printed.
*/
rli->abort_slave= 1;
pthread_mutex_unlock(&rli->data_lock);
DBUG_RETURN(1);
}
Log_event * ev = next_event(rli); In essence, this function does:
DBUG_ASSERT(rli->sql_thd==thd); @code
ev->apply_event(rli);
ev->update_pos(rli);
@endcode
if (sql_slave_killed(thd,rli)) But it also does some maintainance, such as skipping events if
{ needed and reporting errors.
pthread_mutex_unlock(&rli->data_lock);
delete ev; If the @c skip flag is set, then it is tested whether the event
DBUG_RETURN(1); should be skipped, by looking at the slave_skip_counter and the
} server id. The skip flag should be set when calling this from a
if (ev) replication thread but not set when executing an explicit BINLOG
{ statement.
int const type_code= ev->get_type_code();
@retval 0 OK.
@retval 1 Error calling ev->apply_event().
@retval 2 No error calling ev->apply_event(), but error calling
ev->update_pos().
*/
int apply_event_and_update_pos(Log_event* ev, THD* thd, Relay_log_info* rli,
bool skip)
{
int exec_res= 0; int exec_res= 0;
DBUG_ENTER("apply_event_and_update_pos");
DBUG_PRINT("exec_event",("%s(type_code: %d; server_id: %d)", DBUG_PRINT("exec_event",("%s(type_code: %d; server_id: %d)",
ev->get_type_str(), type_code, ev->server_id)); ev->get_type_str(), ev->get_type_code(),
ev->server_id));
DBUG_PRINT("info", ("thd->options: %s%s; rli->last_event_start_time: %lu", DBUG_PRINT("info", ("thd->options: %s%s; rli->last_event_start_time: %lu",
FLAGSTR(thd->options, OPTION_NOT_AUTOCOMMIT), FLAGSTR(thd->options, OPTION_NOT_AUTOCOMMIT),
FLAGSTR(thd->options, OPTION_BEGIN), FLAGSTR(thd->options, OPTION_BEGIN),
rli->last_event_start_time)); rli->last_event_start_time));
/* /*
Execute the event to change the database and update the binary Execute the event to change the database and update the binary
log coordinates, but first we set some data that is needed for log coordinates, but first we set some data that is needed for
...@@ -1844,6 +1838,8 @@ static int exec_relay_log_event(THD* thd, Relay_log_info* rli) ...@@ -1844,6 +1838,8 @@ static int exec_relay_log_event(THD* thd, Relay_log_info* rli)
ev->when= my_time(0); ev->when= my_time(0);
ev->thd = thd; // because up to this point, ev->thd == 0 ev->thd = thd; // because up to this point, ev->thd == 0
if (skip)
{
int reason= ev->shall_skip(rli); int reason= ev->shall_skip(rli);
if (reason == Log_event::EVENT_SKIP_COUNT) if (reason == Log_event::EVENT_SKIP_COUNT)
--rli->slave_skip_counter; --rli->slave_skip_counter;
...@@ -1870,6 +1866,9 @@ static int exec_relay_log_event(THD* thd, Relay_log_info* rli) ...@@ -1870,6 +1866,9 @@ static int exec_relay_log_event(THD* thd, Relay_log_info* rli)
DBUG_PRINT("skip_event", ("%s event was %s", DBUG_PRINT("skip_event", ("%s event was %s",
ev->get_type_str(), explain[reason])); ev->get_type_str(), explain[reason]));
#endif #endif
}
else
exec_res= ev->apply_event(rli);
DBUG_PRINT("info", ("apply_event error = %d", exec_res)); DBUG_PRINT("info", ("apply_event error = %d", exec_res));
if (exec_res == 0) if (exec_res == 0)
...@@ -1899,20 +1898,107 @@ static int exec_relay_log_event(THD* thd, Relay_log_info* rli) ...@@ -1899,20 +1898,107 @@ static int exec_relay_log_event(THD* thd, Relay_log_info* rli)
" Stopped in %s position %s", " Stopped in %s position %s",
rli->group_relay_log_name, rli->group_relay_log_name,
llstr(rli->group_relay_log_pos, buf)); llstr(rli->group_relay_log_pos, buf));
DBUG_RETURN(2);
}
}
DBUG_RETURN(exec_res ? 1 : 0);
}
/**
Top-level function for executing the next event from the relay log.
This function reads the event from the relay log, executes it, and
advances the relay log position. It also handles errors, etc.
This function may fail to apply the event for the following reasons:
- The position specfied by the UNTIL condition of the START SLAVE
command is reached.
- It was not possible to read the event from the log.
- The slave is killed.
- An error occurred when applying the event, and the event has been
tried slave_trans_retries times. If the event has been retried
fewer times, 0 is returned.
- init_master_info or init_relay_log_pos failed. (These are called
if a failure occurs when applying the event.)</li>
- An error occurred when updating the binlog position.
@retval 0 The event was applied.
@retval 1 The event was not applied.
*/
static int exec_relay_log_event(THD* thd, Relay_log_info* rli)
{
DBUG_ENTER("exec_relay_log_event");
/*
We acquire this mutex since we need it for all operations except
event execution. But we will release it in places where we will
wait for something for example inside of next_event().
*/
pthread_mutex_lock(&rli->data_lock);
/*
This tests if the position of the end of the last previous executed event
hits the UNTIL barrier.
We would prefer to test if the position of the start (or possibly) end of
the to-be-read event hits the UNTIL barrier, this is different if there
was an event ignored by the I/O thread just before (BUG#13861 to be
fixed).
*/
if (rli->until_condition!=Relay_log_info::UNTIL_NONE &&
rli->is_until_satisfied())
{
char buf[22];
sql_print_information("Slave SQL thread stopped because it reached its"
" UNTIL position %s", llstr(rli->until_pos(), buf));
/*
Setting abort_slave flag because we do not want additional message about
error in query execution to be printed.
*/
rli->abort_slave= 1;
pthread_mutex_unlock(&rli->data_lock);
DBUG_RETURN(1); DBUG_RETURN(1);
} }
Log_event * ev = next_event(rli);
DBUG_ASSERT(rli->sql_thd==thd);
if (sql_slave_killed(thd,rli))
{
pthread_mutex_unlock(&rli->data_lock);
delete ev;
DBUG_RETURN(1);
} }
if (ev)
{
int exec_res= apply_event_and_update_pos(ev, thd, rli, TRUE);
/* /*
Format_description_log_event should not be deleted because it will be Format_description_log_event should not be deleted because it will be
used to read info about the relay log's format; it will be deleted when used to read info about the relay log's format; it will be deleted when
the SQL thread does not need it, i.e. when this thread terminates. the SQL thread does not need it, i.e. when this thread terminates.
*/ */
if (type_code != FORMAT_DESCRIPTION_EVENT) if (ev->get_type_code() != FORMAT_DESCRIPTION_EVENT)
{ {
DBUG_PRINT("info", ("Deleting the event after it has been executed")); DBUG_PRINT("info", ("Deleting the event after it has been executed"));
delete ev; delete ev;
} }
/*
update_log_pos failed: this should not happen, so we don't
retry.
*/
if (exec_res == 2)
DBUG_RETURN(1);
if (slave_trans_retries) if (slave_trans_retries)
{ {
int temp_err; int temp_err;
...@@ -3051,7 +3137,7 @@ static int queue_old_event(Master_info *mi, const char *buf, ...@@ -3051,7 +3137,7 @@ static int queue_old_event(Master_info *mi, const char *buf,
any >=5.0.0 format. any >=5.0.0 format.
*/ */
int queue_event(Master_info* mi,const char* buf, ulong event_len) static int queue_event(Master_info* mi,const char* buf, ulong event_len)
{ {
int error= 0; int error= 0;
ulong inc_pos; ulong inc_pos;
...@@ -3937,4 +4023,8 @@ template class I_List_iterator<i_string>; ...@@ -3937,4 +4023,8 @@ template class I_List_iterator<i_string>;
template class I_List_iterator<i_string_pair>; template class I_List_iterator<i_string_pair>;
#endif #endif
/**
@} (end of group Replication)
*/
#endif /* HAVE_REPLICATION */ #endif /* HAVE_REPLICATION */
...@@ -187,6 +187,8 @@ int purge_relay_logs(Relay_log_info* rli, THD *thd, bool just_reset, ...@@ -187,6 +187,8 @@ int purge_relay_logs(Relay_log_info* rli, THD *thd, bool just_reset,
void set_slave_thread_options(THD* thd); void set_slave_thread_options(THD* thd);
void set_slave_thread_default_charset(THD *thd, Relay_log_info const *rli); void set_slave_thread_default_charset(THD *thd, Relay_log_info const *rli);
void rotate_relay_log(Master_info* mi); void rotate_relay_log(Master_info* mi);
int apply_event_and_update_pos(Log_event* ev, THD* thd, Relay_log_info* rli,
bool skip);
pthread_handler_t handle_slave_io(void *arg); pthread_handler_t handle_slave_io(void *arg);
pthread_handler_t handle_slave_sql(void *arg); pthread_handler_t handle_slave_sql(void *arg);
......
...@@ -17,15 +17,14 @@ ...@@ -17,15 +17,14 @@
#include "rpl_rli.h" #include "rpl_rli.h"
#include "base64.h" #include "base64.h"
/* /**
Execute a BINLOG statement Execute a BINLOG statement
TODO: This currently assumes a MySQL 5.x binlog. To execute the BINLOG command properly the server needs to know
When we'll have binlog with a different format, to execute the which format the BINLOG command's event is in. Therefore, the first
BINLOG command properly the server will need to know which format BINLOG statement seen must be a base64 encoding of the
the BINLOG command's event is in. mysqlbinlog should then send Format_description_log_event, as outputted by mysqlbinlog. This
the Format_description_log_event of the binlog it reads and the Format_description_log_event is cached in
server thread should cache this format into
rli->description_event_for_exec. rli->description_event_for_exec.
*/ */
...@@ -54,11 +53,24 @@ void mysql_client_binlog_statement(THD* thd) ...@@ -54,11 +53,24 @@ void mysql_client_binlog_statement(THD* thd)
/* /*
Allocation Allocation
*/ */
/*
If we do not have a Format_description_event, we create a dummy
one here. In this case, the first event we read must be a
Format_description_event.
*/
my_bool have_fd_event= TRUE;
if (!thd->rli_fake) if (!thd->rli_fake)
{
thd->rli_fake= new Relay_log_info; thd->rli_fake= new Relay_log_info;
have_fd_event= FALSE;
const Format_description_log_event *desc= }
if (thd->rli_fake && !thd->rli_fake->relay_log.description_event_for_exec)
{
thd->rli_fake->relay_log.description_event_for_exec=
new Format_description_log_event(4); new Format_description_log_event(4);
have_fd_event= FALSE;
}
const char *error= 0; const char *error= 0;
char *buf= (char *) my_malloc(decoded_len, MYF(MY_WME)); char *buf= (char *) my_malloc(decoded_len, MYF(MY_WME));
...@@ -67,7 +79,9 @@ void mysql_client_binlog_statement(THD* thd) ...@@ -67,7 +79,9 @@ void mysql_client_binlog_statement(THD* thd)
/* /*
Out of memory check Out of memory check
*/ */
if (!(thd->rli_fake && desc && buf)) if (!(thd->rli_fake &&
thd->rli_fake->relay_log.description_event_for_exec &&
buf))
{ {
my_error(ER_OUTOFMEMORY, MYF(0), 1); /* needed 1 bytes */ my_error(ER_OUTOFMEMORY, MYF(0), 1); /* needed 1 bytes */
goto end; goto end;
...@@ -138,7 +152,28 @@ void mysql_client_binlog_statement(THD* thd) ...@@ -138,7 +152,28 @@ void mysql_client_binlog_statement(THD* thd)
goto end; goto end;
} }
ev= Log_event::read_log_event(bufptr, event_len, &error, desc); /*
If we have not seen any Format_description_event, then we must
see one; it is the only statement that can be read in base64
without a prior Format_description_event.
*/
if (!have_fd_event)
{
if (bufptr[EVENT_TYPE_OFFSET] == FORMAT_DESCRIPTION_EVENT)
have_fd_event= TRUE;
else
{
my_error(ER_NO_FORMAT_DESCRIPTION_EVENT_BEFORE_BINLOG_STATEMENT,
MYF(0),
Log_event::get_type_str(
(Log_event_type)bufptr[EVENT_TYPE_OFFSET]));
goto end;
}
}
ev= Log_event::read_log_event(bufptr, event_len, &error,
thd->rli_fake->relay_log.
description_event_for_exec);
DBUG_PRINT("info",("binlog base64 err=%s", error)); DBUG_PRINT("info",("binlog base64 err=%s", error));
if (!ev) if (!ev)
...@@ -176,9 +211,8 @@ void mysql_client_binlog_statement(THD* thd) ...@@ -176,9 +211,8 @@ void mysql_client_binlog_statement(THD* thd)
reporting. reporting.
*/ */
#if !defined(MYSQL_CLIENT) && defined(HAVE_REPLICATION) #if !defined(MYSQL_CLIENT) && defined(HAVE_REPLICATION)
if (IF_DBUG(int err= ) ev->apply_event(thd->rli_fake)) if (apply_event_and_update_pos(ev, thd, thd->rli_fake, FALSE))
{ {
DBUG_PRINT("info", ("apply_event() returned: %d", err));
/* /*
TODO: Maybe a better error message since the BINLOG statement TODO: Maybe a better error message since the BINLOG statement
now contains several events. now contains several events.
...@@ -188,6 +222,13 @@ void mysql_client_binlog_statement(THD* thd) ...@@ -188,6 +222,13 @@ void mysql_client_binlog_statement(THD* thd)
} }
#endif #endif
/*
Format_description_log_event should not be deleted because it
will be used to read info about the relay log's format; it
will be deleted when the SQL thread does not need it,
i.e. when this thread terminates.
*/
if (ev->get_type_code() != FORMAT_DESCRIPTION_EVENT)
delete ev; delete ev;
ev= 0; ev= 0;
} }
...@@ -207,7 +248,6 @@ void mysql_client_binlog_statement(THD* thd) ...@@ -207,7 +248,6 @@ void mysql_client_binlog_statement(THD* thd)
*/ */
thd->net.no_send_ok= nsok; thd->net.no_send_ok= nsok;
delete desc;
my_free(buf, MYF(MY_ALLOW_ZERO_PTR)); my_free(buf, MYF(MY_ALLOW_ZERO_PTR));
DBUG_VOID_RETURN; DBUG_VOID_RETURN;
} }
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment