Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[MDEV-34614] mysqlbinlog warn on EOF before GTID in --stop-position #3600

Open
wants to merge 2 commits into
base: 10.11
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
19 changes: 18 additions & 1 deletion client/mysqlbinlog.cc
Original file line number Diff line number Diff line change
Expand Up @@ -3489,7 +3489,7 @@ static Exit_status dump_local_log_entries(PRINT_EVENT_INFO *print_event_info,

/*
Emit a warning in the event that we finished processing input
before reaching the boundary indicated by --stop-position.
before reaching the boundary indicated by --stop-position index.
*/
if (((longlong)stop_position != stop_position_default) &&
stop_position > my_b_tell(file))
Expand All @@ -3511,6 +3511,23 @@ static Exit_status dump_local_log_entries(PRINT_EVENT_INFO *print_event_info,
"before end of input", stop_datetime_str);
}

/*
Emit warning(s) in the event that we finished processing input
before reaching all boundaries indicated by --stop-position GTID(s).
When implemented, replace `position_gtid_filter` in the condition with
`gtid_event_filter`, and it will also warn if we finished
processing before reaching all --start-position GTID(s)
and touching all --ignore-domain/server-ids.
*/
// Gtid_event_filter::has_finished() isn't necessarily a O(1) happy path.
if (position_gtid_filter && position_gtid_filter->verify_completed_state())
{
// The condition covers the warnings but not this step -
if (result_file)
fflush(result_file);
retval = OK_STOP;
}

goto end;
}
last_ev_when= ev->when;
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -12,8 +12,6 @@ Case: Default, must not see warning.
# MYSQL_BINLOG --short-form MYSQLD_DATADIR/master-bin.000001 --result-file=ignored_output_file
Case: Stop datetime before EOF, must not see warning.
# MYSQL_BINLOG --short-form --stop-datetime='2001-09-08 21:46:50' MYSQLD_DATADIR/master-bin.000001 --result-file=ignored_output_file
Case: Stop datetime between records, must not see warning.
# MYSQL_BINLOG --short-form --stop-datetime='2001-09-08 21:46:55' MYSQLD_DATADIR/master-bin.000001 --result-file=ignored_output_file
Case: Stop datetime at EOF, must not see warning.
# MYSQL_BINLOG --short-form --stop-datetime='2001-09-08 21:46:55' MYSQLD_DATADIR/master-bin.000001 --result-file=ignored_output_file
Case: Stop datetime after EOF, must see warning.
Expand Down
33 changes: 33 additions & 0 deletions mysql-test/suite/binlog/r/binlog_mysqlbinlog_warn_stop_gtid.result
Original file line number Diff line number Diff line change
@@ -0,0 +1,33 @@

# MDEV-34614 mysqlbinlog warn on EOF before GTID in --stop-position

RESET MASTER;
SET @@session.gtid_domain_id= 0;
SET @@session.server_id= 1;
SET @@session.gtid_seq_no= 1;
CREATE TABLE t1(a int);
INSERT INTO t1 VALUES (1), (2);
SET @@session.gtid_domain_id= 1;
CREATE TABLE t2(a int);
INSERT INTO t2 VALUES (3);
FLUSH LOGS;
Case: Default, must not see warning.
# MYSQL_BINLOG --short-form MYSQLD_DATADIR/master-bin.000001 --result-file=ignored_output_file
Case: Stop GTID at EOF, must not see warning.
# MYSQL_BINLOG --short-form --skip-gtid-strict-mode --stop-position=0-1-2 MYSQLD_DATADIR/master-bin.000001 --result-file=ignored_output_file
Case: Stop GTID after EOF, must see warning.
# MYSQL_BINLOG --short-form --skip-gtid-strict-mode --stop-position=1-1-9 MYSQLD_DATADIR/master-bin.000001 --result-file=ignored_output_file
WARNING: Did not reach stop position 1-1-9 before end of input
Case: Stop GTID nonexistent, must see warning.
# MYSQL_BINLOG --short-form --skip-gtid-strict-mode --stop-position=9-1-1 MYSQLD_DATADIR/master-bin.000001 --result-file=ignored_output_file
WARNING: Did not reach stop position 9-1-1 before end of input
Case: Stop GTID at EOF + after EOF, must see only one warning.
# MYSQL_BINLOG --short-form --skip-gtid-strict-mode --stop-position=0-1-2,1-1-9 MYSQLD_DATADIR/master-bin.000001 --result-file=ignored_output_file
WARNING: Did not reach stop position 1-1-9 before end of input
Case: Stop GTID after EOF + nonexistent, must see two warnings.
# MYSQL_BINLOG --short-form --skip-gtid-strict-mode --stop-position=1-1-9,9-1-1 MYSQLD_DATADIR/master-bin.000001 --result-file=ignored_output_file
WARNING: Did not reach stop position 9-1-1 before end of input
WARNING: Did not reach stop position 1-1-9 before end of input
DROP TABLE t1;
DROP TABLE t2;
# End of binlog_mysqlbinlog_warn_stop_gtid.test
Original file line number Diff line number Diff line change
Expand Up @@ -23,10 +23,6 @@ flush logs;
--echo # MYSQL_BINLOG --short-form --stop-datetime='2001-09-08 21:46:50' MYSQLD_DATADIR/master-bin.000001 --result-file=ignored_output_file
--exec $MYSQL_BINLOG --short-form --stop-datetime='2001-09-08 21:46:50' $MYSQLD_DATADIR/master-bin.000001 --result-file=$ignored_output_file 2>&1

--echo Case: Stop datetime between records, must not see warning.
ParadoxV5 marked this conversation as resolved.
Show resolved Hide resolved
--echo # MYSQL_BINLOG --short-form --stop-datetime='2001-09-08 21:46:55' MYSQLD_DATADIR/master-bin.000001 --result-file=ignored_output_file
--exec $MYSQL_BINLOG --short-form --stop-datetime='2001-09-08 21:46:55' $MYSQLD_DATADIR/master-bin.000001 --result-file=$ignored_output_file 2>&1

--echo Case: Stop datetime at EOF, must not see warning.
--echo # MYSQL_BINLOG --short-form --stop-datetime='2001-09-08 21:46:55' MYSQLD_DATADIR/master-bin.000001 --result-file=ignored_output_file
--exec $MYSQL_BINLOG --short-form --stop-datetime='2001-09-08 21:46:55' $MYSQLD_DATADIR/master-bin.000001 --result-file=$ignored_output_file 2>&1
Expand Down
50 changes: 50 additions & 0 deletions mysql-test/suite/binlog/t/binlog_mysqlbinlog_warn_stop_gtid.test
Original file line number Diff line number Diff line change
@@ -0,0 +1,50 @@
--echo
--echo # MDEV-34614 mysqlbinlog warn on EOF before GTID in --stop-position
--echo

--source include/have_log_bin.inc

--let ignored_output_file= $MYSQLTEST_VARDIR/tmp/warn_pos_test_file.out

RESET MASTER;
SET @@session.gtid_domain_id= 0;
SET @@session.server_id= 1;
SET @@session.gtid_seq_no= 1;
CREATE TABLE t1(a int);
INSERT INTO t1 VALUES (1), (2);
SET @@session.gtid_domain_id= 1;
CREATE TABLE t2(a int);
INSERT INTO t2 VALUES (3);
--let MYSQLD_DATADIR= `SELECT @@datadir;`
FLUSH LOGS;

--echo Case: Default, must not see warning.
--echo # MYSQL_BINLOG --short-form MYSQLD_DATADIR/master-bin.000001 --result-file=ignored_output_file
--exec $MYSQL_BINLOG --short-form $MYSQLD_DATADIR/master-bin.000001 --result-file=$ignored_output_file 2>&1

--echo Case: Stop GTID at EOF, must not see warning.
--echo # MYSQL_BINLOG --short-form --skip-gtid-strict-mode --stop-position=0-1-2 MYSQLD_DATADIR/master-bin.000001 --result-file=ignored_output_file
--exec $MYSQL_BINLOG --short-form --skip-gtid-strict-mode --stop-position=0-1-2 $MYSQLD_DATADIR/master-bin.000001 --result-file=$ignored_output_file 2>&1

--echo Case: Stop GTID after EOF, must see warning.
--echo # MYSQL_BINLOG --short-form --skip-gtid-strict-mode --stop-position=1-1-9 MYSQLD_DATADIR/master-bin.000001 --result-file=ignored_output_file
--exec $MYSQL_BINLOG --short-form --skip-gtid-strict-mode --stop-position=1-1-9 $MYSQLD_DATADIR/master-bin.000001 --result-file=$ignored_output_file 2>&1

--echo Case: Stop GTID nonexistent, must see warning.
--echo # MYSQL_BINLOG --short-form --skip-gtid-strict-mode --stop-position=9-1-1 MYSQLD_DATADIR/master-bin.000001 --result-file=ignored_output_file
--exec $MYSQL_BINLOG --short-form --skip-gtid-strict-mode --stop-position=9-1-1 $MYSQLD_DATADIR/master-bin.000001 --result-file=$ignored_output_file 2>&1

--echo Case: Stop GTID at EOF + after EOF, must see only one warning.
--echo # MYSQL_BINLOG --short-form --skip-gtid-strict-mode --stop-position=0-1-2,1-1-9 MYSQLD_DATADIR/master-bin.000001 --result-file=ignored_output_file
--exec $MYSQL_BINLOG --short-form --skip-gtid-strict-mode --stop-position=0-1-2,1-1-9 $MYSQLD_DATADIR/master-bin.000001 --result-file=$ignored_output_file 2>&1

--echo Case: Stop GTID after EOF + nonexistent, must see two warnings.
--echo # MYSQL_BINLOG --short-form --skip-gtid-strict-mode --stop-position=1-1-9,9-1-1 MYSQLD_DATADIR/master-bin.000001 --result-file=ignored_output_file
--exec $MYSQL_BINLOG --short-form --skip-gtid-strict-mode --stop-position=1-1-9,9-1-1 $MYSQLD_DATADIR/master-bin.000001 --result-file=$ignored_output_file 2>&1

DROP TABLE t1;
DROP TABLE t2;

--remove_file $ignored_output_file

--echo # End of binlog_mysqlbinlog_warn_stop_gtid.test
Original file line number Diff line number Diff line change
Expand Up @@ -2,25 +2,25 @@
--echo # MDEV-27037 mysqlbinlog emits a warning when reaching EOF before stop-condition
--echo

--let assert_file= $MYSQLTEST_VARDIR/tmp/warn_pos_test_file.out

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This renaming is fine, but IMHO not worth the churn.

--let ignored_output_file= $MYSQLTEST_VARDIR/tmp/warn_pos_test_file.out
--let data_file= $MYSQLTEST_VARDIR/std_data/master-bin.000001

--echo Case: Default stop position, WARNING must not appear
--echo # MYSQL_BINLOG --short-form --start-position=4 mysql-test/std_data/master-bin.000001 --result-file=warn_pos_test_file.out 2>&1
--exec $MYSQL_BINLOG --short-form --start-position=4 $data_file --result-file=$assert_file 2>&1
--exec $MYSQL_BINLOG --short-form --start-position=4 $data_file --result-file=$ignored_output_file 2>&1

--echo Case: Stop position before EOF, WARNING must not appear
--echo # MYSQL_BINLOG --short-form --start-position=4 --stop-position=97 mysql-test/std_data/master-bin.000001 --result-file=warn_pos_test_file.out 2>&1
--exec $MYSQL_BINLOG --short-form --start-position=4 --stop-position=97 $data_file --result-file=$assert_file 2>&1
--exec $MYSQL_BINLOG --short-form --start-position=4 --stop-position=97 $data_file --result-file=$ignored_output_file 2>&1

--echo Case: Stop position at EOF, WARNING must not appear
--echo # MYSQL_BINLOG --short-form --start-position=4 --stop-position=98 mysql-test/std_data/master-bin.000001 --result-file=warn_pos_test_file.out 2>&1
--exec $MYSQL_BINLOG --short-form --start-position=4 --stop-position=98 $data_file --result-file=$assert_file 2>&1
--exec $MYSQL_BINLOG --short-form --start-position=4 --stop-position=98 $data_file --result-file=$ignored_output_file 2>&1

--echo Case: Stop position after EOF, WARNING must appear
--echo # MYSQL_BINLOG --short-form --start-position=4 --stop-position=99 mysql-test/std_data/master-bin.000001 --result-file=warn_pos_test_file.out 2>&1
--exec $MYSQL_BINLOG --short-form --start-position=4 --stop-position=99 $data_file --result-file=$assert_file 2>&1
--exec $MYSQL_BINLOG --short-form --start-position=4 --stop-position=99 $data_file --result-file=$ignored_output_file 2>&1

--remove_file $assert_file
--remove_file $ignored_output_file

--echo # End of binlog_mysqlbinlog_warn_stop_position.test
66 changes: 66 additions & 0 deletions sql/rpl_gtid.cc
Original file line number Diff line number Diff line change
Expand Up @@ -3315,6 +3315,7 @@ struct gtid_report_ctx
my_bool contains_err;
};

/** Iteration block for Binlog_gtid_state_validator::report */
ParadoxV5 marked this conversation as resolved.
Show resolved Hide resolved
static my_bool report_audit_findings(void *entry, void *report_ctx_arg)
{
struct Binlog_gtid_state_validator::audit_elem *audit_el=
Expand Down Expand Up @@ -3525,6 +3526,32 @@ my_bool Window_gtid_event_filter::has_finished()
return m_has_stop ? m_has_passed : FALSE;
}

my_bool Window_gtid_event_filter::verify_completed_state()
{
/*TODO: validate `--start-position` (::m_start)
Normally with ::m_has_start, the states goes from inactive to ::m_is_active,
then to ::m_has_passed if ::m_has_stop (::has_finished()).
However, the filter can finish at ::m_has_passed without ever becoming
::m_is_active if ::is_range_invalid(), complicating checks.
Ideally, ::is_range_invalid() should warn outside of
`--gtid-strict-mode` as well, but that's its own distinct discussion.
*/
if (m_has_stop && !m_has_passed)
{
/*XXX:
`mysqlbinlog.cc`'s `static warning()` family is all duplicate
code of the Binlog_gtid_state_validator::warn() family, except
it specifies stderr and has a `fflush(result_file)` step.
*/
Binlog_gtid_state_validator::warn(stderr,
"Did not reach stop position %u-%u-%llu before end of input",
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

%u-%u-%llu is used throughout this file (and likely more); but GTID struct fields are actually fixed-size, whereas these formats varies by platform.
I’ll file this mismatch as a separate subissue of #3360 (review) (MDEV-21978).

PARAM_GTID(m_stop)
);
return TRUE;
}
return FALSE;
}

void free_u32_gtid_filter_element(void *p)
{
gtid_filter_element<uint32> *gfe= (gtid_filter_element<uint32> *) p;
Expand Down Expand Up @@ -3607,6 +3634,31 @@ my_bool Id_delegating_gtid_event_filter<T>::has_finished()
m_num_completed_filters == m_num_stateful_filters;
}

/**
Iteration block for Id_delegating_gtid_event_filter::verify_completed_state()
*/
static my_bool
verify_subfilter_completed_state(void *entry, void *is_any_incomplete)
{
if (entry && reinterpret_cast<
gtid_filter_element<decltype(rpl_gtid::domain_id)> *
>(entry)->filter->verify_completed_state())
*(my_bool *)is_any_incomplete= TRUE;
return FALSE; // do not terminate early
}

template <typename T>
my_bool Id_delegating_gtid_event_filter<T>::verify_completed_state()
{
if (has_finished()) // fast happy path
return FALSE;
// If a user-defined filters is not deactivated, it may not be complete.
my_bool is_any_incomplete= FALSE;
my_hash_iterate(&m_filters_by_id_hash,
verify_subfilter_completed_state, &is_any_incomplete);
Comment on lines +3657 to +3658
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Instead of iterating the hash (and segfault myself from the hash’s untypedness), I could’ve directly iterated the Domain_gtid_event_filter::m_stop_filters.
Iterating Id_delegating_gtid_event_filter::m_filters_by_id_hash

  • future-proofs for --start-position warnings – if we want to.
  • is possible in the superclass, so Server_gtid_event_filter (used by --ignore-server-ids) can inherit the method override.

Any preference?

return is_any_incomplete;
}

template <typename T>
my_bool Id_delegating_gtid_event_filter<T>::exclude(rpl_gtid *gtid)
{
Expand Down Expand Up @@ -4067,3 +4119,17 @@ my_bool Intersecting_gtid_event_filter::has_finished()
}
return FALSE;
}

my_bool Intersecting_gtid_event_filter::verify_completed_state()
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This isn’t currently called, but I implemented the override anyway for potential future-proofing.
(position_gtid_filter is never an Intersecting_gtid_event_filter, but gtid_event_filter may be.)

{
my_bool is_any_incomplete= FALSE;
Gtid_event_filter *subfilter;
for (size_t i= 0; i < m_filters.elements; i++)
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This method was based on ::has_finished().
Besides formatting, a difference is that this uses size_t to match the type of m_filters.elements.
The former had a ulong; it’s a potential bug, but I’m yet to review which earliest (supported) version this fix should apply on.

{
subfilter= *(Gtid_event_filter **)dynamic_array_ptr(&m_filters, i);
DBUG_ASSERT(subfilter);
if (subfilter->verify_completed_state())
is_any_incomplete= TRUE;
}
return is_any_incomplete;
}
36 changes: 23 additions & 13 deletions sql/rpl_gtid.h
Original file line number Diff line number Diff line change
Expand Up @@ -568,7 +568,25 @@ class Gtid_event_filter

Returns TRUE when completed, and FALSE when the filter has not finished.
*/
virtual my_bool has_finished() = 0;
virtual my_bool has_finished() { return FALSE; }

/**
Check that this filter implementation is at a *completely* final state,
and warn if it is not.

For a filter that can maintain their own state,
this not only validates if the filter ::has_finished(),
but may also print specific warnings for its variety of non-finished states.

For a filter that manage multiple subfilters, this should iterate through
*all* subfilters to have each self-report if it wasn't fully effective.
This cumulative result may not correlate with the ::has_finished() state.

@return
FALSE if the filter is at a completed state, or TRUE if it warned
its state (This scheme is the opposite of ::has_finished()!)
*/
virtual my_bool verify_completed_state() { return FALSE; }
};

/*
Expand All @@ -585,7 +603,6 @@ class Accept_all_gtid_filter : public Gtid_event_filter
~Accept_all_gtid_filter() {}
my_bool exclude(rpl_gtid *) override { return FALSE; }
uint32 get_filter_type() override { return ACCEPT_ALL_GTID_FILTER_TYPE; }
my_bool has_finished() override { return FALSE; }
};

/*
Expand All @@ -598,7 +615,6 @@ class Reject_all_gtid_filter : public Gtid_event_filter
~Reject_all_gtid_filter() {}
my_bool exclude(rpl_gtid *) override { return TRUE; }
uint32 get_filter_type() override { return REJECT_ALL_GTID_FILTER_TYPE; }
my_bool has_finished() override { return FALSE; }
};

/*
Expand All @@ -618,6 +634,7 @@ class Window_gtid_event_filter : public Gtid_event_filter

my_bool exclude(rpl_gtid*) override;
my_bool has_finished() override;
my_bool verify_completed_state() override;

/*
Set the GTID that begins this window (exclusive)
Expand Down Expand Up @@ -663,15 +680,6 @@ class Window_gtid_event_filter : public Gtid_event_filter
m_stop= {0, 0, 0};
}

protected:

/*
When processing GTID streams, the order in which they are processed should
be sequential with no gaps between events. If a gap is found within a
window, warn the user.
*/
void verify_gtid_is_expected(rpl_gtid *gtid);

private:

enum warning_flags
Expand Down Expand Up @@ -701,7 +709,7 @@ class Window_gtid_event_filter : public Gtid_event_filter

/*
m_has_passed : Indicates whether or not the program is currently reading
events from within this window.
events from beyond this window.
*/
my_bool m_has_passed;

Expand Down Expand Up @@ -738,6 +746,7 @@ class Id_delegating_gtid_event_filter : public Gtid_event_filter

my_bool exclude(rpl_gtid *gtid) override;
my_bool has_finished() override;
my_bool verify_completed_state() override;
void set_default_filter(Gtid_event_filter *default_filter);

uint32 get_filter_type() override { return DELEGATING_GTID_FILTER_TYPE; }
Expand Down Expand Up @@ -919,6 +928,7 @@ class Intersecting_gtid_event_filter : public Gtid_event_filter
*/
my_bool has_finished() override;

my_bool verify_completed_state() override;
uint32 get_filter_type() override { return INTERSECTING_GTID_FILTER_TYPE; }

/*
Expand Down