mysql_client_binlog_statement
Problem: server may read from unassigned memory performing
"wrong" BINLOG queries.
Fix: never read from unassigned memory.
Some of the test cases reference to binlog position and
these position numbers are written into result explicitly.
It is difficult to maintain if log event format changes.
There are a couple of cases explicit position number appears,
we handle them in different ways
A. 'CHANGE MASTER ...' with MASTER_LOG_POS or/and RELAY_LOG_POS options
Use --replace_result to mask them.
B. 'SHOW BINLOG EVENT ...'
Replaced by show_binlog_events.inc or wait_for_binlog_event.inc.
show_binlog_events.inc file's function is enhanced by given
$binlog_file and $binlog_limit.
C. 'SHOW SLAVE STATUS', 'show_slave_status.inc' and 'show_slave_status2.inc'
For the test cases just care a few items in the result of 'SHOW SLAVE STATUS',
only the items related to each test case are showed.
'show_slave_status.inc' is rebuild, only the given items in $status_items
will be showed.
'check_slave_is_running.inc' and 'check_slave_no_error.inc'
and 'check_slave_param.inc' are auxiliary files helping
to show running status and error information easily.
------------------------------------------------------------
revno: 3094
revision-id: vasil.dimov@oracle.com-20100513074652-0cvlhgkesgbb2bfh
parent: vasil.dimov@oracle.com-20100512173700-byf8xntxjur1hqov
committer: Vasil Dimov <vasil.dimov@oracle.com>
branch nick: mysql-trunk-innodb
timestamp: Thu 2010-05-13 10:46:52 +0300
message:
Followup to Bug#51920, fix binlog.binlog_killed
This is a followup to the fix of
Bug#51920 Innodb connections in row lock wait ignore KILL until lock wait
timeout
in that fix (rb://279) the behavior was changed to honor when a trx is
interrupted during lock wait, but the returned error code was still
"lock wait timeout" when it should be "interrupted".
This change fixes the non-deterministically failing test binlog.binlog_killed,
that failed like this:
binlog.binlog_killed 'stmt' [ fail ]
Test ended at 2010-05-12 11:39:08
CURRENT_TEST: binlog.binlog_killed
mysqltest: At line 208: query 'reap' failed with wrong errno 1205: 'Lock wait timeout exceeded; try restarting transaction', instead of 0...
Approved by: Sunny Bains (rb://344)
------------------------------------------------------------
This merge is non-trivial since it has to introduce the DB_INTERRUPTED
error code.
Also revert vasil.dimov@oracle.com-20100408165555-9rpjh24o0sa9ad5y
which adjusted the binlog.binlog_killed test to the new (wrong) behavior
The test case added in previous patch missed a RESET MASTER on
test start up. Without it, showing binary log contents can
sometimes show spurious entries from previously executed tests,
ultimately causing test failure - result mismatch.
The test file was added in:
revid:luis.soares@sun.com-20100224190153-k0bpdx9abe88uoo2
This patch also moves the test case into binlog_innodb_row.test
file. This way we avoid having yet another test file,
binlog_row_innodb_truncate.test, whose only purpose is to host
one test case. This had been actually suggested during original
patch review, but somehow the binlog_innodb_row was missed when
searching for a file to host the test case.
+ failing statements
Implicit DROP event for temporary table is not getting
LOG_EVENT_THREAD_SPECIFIC_F flag, because, in the previous
executed statement in the same thread, which might even be a
failed statement, the thread_specific_used flag is set to
FALSE (in mysql_reset_thd_for_next_command) and not set to TRUE
before connection is shutdown. This means that implicit DROP
event will take the FALSE value from thread_specific_used and
will not set LOG_EVENT_THREAD_SPECIFIC_F in the event header. As
a consequence, mysqlbinlog will not print the pseudo_thread_id
from the DROP event, because one of the requirements for the
printout is that this flag is set to TRUE.
We fix this by setting thread_specific_used whenever we are
binlogging a DROP in close_temporary_tables, and resetting it to
its previous value afterward.
For temporary tables that are created with an engine that does
not provide the HTON_CAN_RECREATE, the truncate operation is
performed resorting to the optimized handler::ha_delete_all_rows
method. However, this means that the truncate will share
execution path, from mysql_delete, with truncate on regular
tables and other delete operations. As a consequence the truncate
operation, for the temporary table is logged, even if in row mode
because there is no distinction between this and the other delete
operations at binlogging time.
We fix this by checking if: (i) the binlog format, when the
truncate operation was issued, is ROW; (ii) if the operation is a
truncate; and (iii) if the table is a temporary table; before
writing to the binary log. If all three conditions are met, we
skip writing to the binlog. A side effect of this fix is that we
limit the scope of setting and resetting the
current_stmt_binlog_row_based. Now we just set and reset it
inside mysql_delete in the boundaries of the
handler::ha_write_row loop. This way we have access to
thd->current_stmt_binlog_row_based real value inside
mysql_delete.
Problem: When RAND() is binlogged in statement mode, the seed is
binlogged too, so the replication slave generates the same
sequence of random numbers. This makes replication work in many
cases, but not in all cases: the order of rows is not guaranteed
for, e.g., UPDATE or INSERT...SELECT statements, so the row data
will be different if master and slave retrieve the rows in
different orders.
Fix: Mark RAND() as unsafe. It will generate a warning if
binlog_format=STATEMENT and switch to row-logging if
binlog_format=ROW.
For tables with metadata sizes ranging from 251 to 255 the size
of the event data (m_data_size) was being improperly calculated
in the Table_map_log_event constructor. This was due to the fact
that when writing the Table_map_log_event body (in
Table_map_log_event::write_data_body) a call to net_store_length
is made for packing the m_field_metadata_size. It happens that
net_store_length uses *one* byte for storing
m_field_metadata_size when it is smaller than 251 but *three*
bytes when it exceeds that value. BUG 42749 had already
pinpointed and fix this fact, but the fix was incomplete, as the
calculation in the Table_map_log_event constructor considers 255
instead of 251 as the threshold to increment m_data_size by
three. Thence, the window for having a mismatch between the
number of bytes written and the number of bytes accounted in the
event length (m_data_size) was left open for
m_field_metadata_size values between 251 and 255.
We fix this by changing the condition in the Table_map_log_event
constructor to match the one in the net_store_length, ie,
increment one byte if m_field_metadata_size < 251 and three if it
exceeds this value.
This patch fixes three bugs as follows. First, aborting the server while purging
binary logs might generate orphan files due to how the purge operation was
implemented:
(purge routine - sql/log.cc - MYSQL_BIN_LOG::purge_logs)
1 - register the files to be removed in a temporary buffer.
2 - update the log-bin.index.
3 - flush the log-bin.index.
4 - erase the files whose names where register in the temporary buffer
in step 1.
Thus a failure while executing step 4 would generate an orphan file. Second,
a similar issue might happen while creating a new binary as follows:
(create routine - sql/log.cc - MYSQL_BIN_LOG::open)
1 - open the new log-bin.
2 - update the log-bin.index.
Thus a failure while executing step 1 would generate an orphan file.
To fix these issues, we record the files to be purged or created before really
removing or adding them. So if a failure happens such records can be used to
automatically remove dangling files. The new steps might be outlined as follows:
(purge routine - sql/log.cc - MYSQL_BIN_LOG::purge_logs)
1 - register the files to be removed in the log-bin.~rec~ placed in
the data directory.
2 - update the log-bin.index.
3 - flush the log-bin.index.
4 - delete the log-bin.~rec~.
(create routine - sql/log.cc - MYSQL_BIN_LOG::open)
1 - register the file to be created in the log-bin.~rec~
placed in the data directory.
2 - open the new log-bin.
3 - update the log-bin.index.
4 - delete the log-bin.~rec~.
(recovery routine - sql/log.cc - MYSQL_BIN_LOG::open_index_file)
1 - open the log-bin.index.
2 - open the log-bin.~rec~.
3 - for each file in log-bin.~rec~.
3.1 Check if the file is in the log-bin.index and if so ignore it.
3.2 Otherwise, delete it.
The third issue can be described as follows. The purge operation was allowing
to remove a file in use thus leading to the loss of data and possible
inconsistencies between the master and slave. Roughly, the routine was only
taking into account the dump threads and so if a slave was not connect the
file might be delete even though it was in use.
Problem: Some system functions that could return different values on
master and slave were not marked unsafe. In particular:
GET_LOCK
IS_FREE_LOCK
IS_USED_LOCK
MASTER_POS_WAIT
RELEASE_LOCK
SLEEP
SYSDATE
VERSION
Fix: Mark these functions unsafe.
file
Issuing 'FLUSH LOGS' does not close and reopen indexfile.
Instead a SEEK_SET is performed.
This patch makes index file to be closed and reopened whenever a
rotation happens (FLUSH LOGS is issued or binary log exceeds
maximum configured size).
Let
- T be a transactional table and N non-transactional table.
- B be begin, C commit and R rollback.
- M be a mixed statement, i.e. a statement that updates both T and N.
- M* be a mixed statement that fails while updating either T or N.
This patch restore the behavior presented in 5.1.37 for rows either produced in
the RBR or MIXED modes, when a M* statement that happened early in a transaction
had their changes written to the binary log outside the boundaries of the
transaction and wrapped in a BEGIN/ROLLBACK. This was done to keep the slave
consistent with with the master as the rollback would keep the changes on N and
undo them on T. In particular, we do what follows:
. B M* T C would log - B M* R B T C.
Note that, we are not preserving history from the master as we are introducing a
rollback that never happened. However, this seems to be more acceptable than
making the slave diverge. We do not fix the following case:
. B T M* C would log B T M* C.
The slave will diverge as the changes on T tables that originated from the M
statement are rolled back on the master but not on the slave. Unfortunately, we
cannot simply rollback the transaction as this would undo any uncommitted
changes on T tables.
SBR is not considered in this patch because a failing statement is written to
the binary along with the error code and a slave executes and then rolls back
the statement when it has an associated error code, thus undoing the effects
on T. In RBR and MBR, a full-fledged fix will be pushed after the WL 2687.
The 'BEGIN/COMMIT/ROLLBACK' log event could be filtered out if the
database is not selected by --database option of mysqlbinlog command.
This can result in problem if there are some statements in the
transaction are not filtered out.
To fix the problem, mysqlbinlog will output 'BEGIN/ROLLBACK/COMMIT'
in regardless of the database filtering rules.
binlog-db-db / binlog-ignore-db
InnoDB will return an error if statement based replication is used
along with transaction isolation level READ-COMMITTED (or weaker),
even if the statement in question is filtered out according to the
binlog-do-db rules set. In this case, an error should not be printed.
This patch addresses this issue by extending the existing check in
external_lock to take into account the filter rules before deciding to
print an error. Furthermore, it also changes decide_logging_format to
take into consideration whether the statement is filtered out from
binlog before decision is made.
This test case uses mysqlbinlog to dump the content of master-bin.000001,
but the content of master-bin.000001 is not that this test needs.
MTR runs a lot of test cases on one server, so when this test starts, the current binlog file
might not be master-bin.000001, or there are other events are written by tests before.
'RESET MASTER' command must be called at the begin, it ensures that binlog of this test
is wrote to master-bin.000001 correctly.
Three other tests have the same problem, They were fixed together.
mysqlbinlog-cp932
binlog_incident
binlog_tmp_table
If using statement based replication (SBR), repeatedly calling
statements which are unsafe for SBR will cause a warning message
to be written to the error for each statement. This might lead
to filling up the error log and there is no way to disable this
behavior.
The solution is to only log these message (about statements unsafe
for statement based replication) if the log_warnings option is set.
For example:
SET GLOBAL LOG_WARNINGS = 0;
INSERT INTO t1 VALUES(UUID());
SET GLOBAL LOG_WARNINGS = 1;
INSERT INTO t1 VALUES(UUID());
In this case the message will be printed only once:
[Warning] Statement may not be safe to log in statement format.
Statement: INSERT INTO t1 VALUES(UUID())
format." warnings
Despite the fact that a statement would be filtered out from binlog, a
warning would still be thrown if it was issued with the LIMIT.
This patch addresses this issue by checking the filtering rules before
printing out the warning.
mysqlbinlog --database parameter was being ignored when processing
row events. As such no event filtering would take place.
This patch addresses this by deploying a call to shall_skip_database
when table_map_events are handled (as these contain also the name of
the database). All other rows events referencing the table id for the
filtered map event, will also be skipped.
"freeing items"
The calculation of the table map log event in the event constructor
was one byte shorter than what would be actually written. This would
lead to a mismatch between the number of bytes written and the event
end_log_pos, causing bad event alignment in the binlog (corrupted
binlog) or in the transaction cache while fixing positions
(MYSQL_BIN_LOG::write_cache). This could lead to impossible to read
binlog or even infinite loops in MYSQL_BIN_LOG::write_cache.
This patch addresses this issue by correcting the expected event
length in the Table_map_log_event constructor, when the field metadata
size exceeds 255.
In the output from mysqlbinlog, incident log events were
represented as just a comment. Since the incident log event
represents an incident that could cause the contents of the
database to change without being logged to the binary log,
it means that if the SQL is applied to a server, it could
potentially lead to that the databases are out of sync.
In order to handle that, this patch adds the statement "RELOAD
DATABASE" to the SQL output for the incident log event. This will
require a DBA to edit the file and handle the case as apropriate
before applying the output to a server.
Mysql server crashes because unsafe statements warning is wrongly elevated to error,
which is set the error status of Diagnostics_area of the thread in THD::binlog_query().
Yet the caller believes that binary logging shouldn't touch the status, so it will
set the status also later by my_ok(), my_error() or my_message() seperately
according to the execution result of the statement or transaction.
But the status of Diagnostics_area of the thread is allowed to set only once.
Fixed to clear the error wrongly set by binary logging, but keep the warning message.
The reason of the bug is in that the test makes a trick with relay log files and
did not reset fully at the end.
If mtr does not restart the test the new SQL thread tried to work with the old time
session data.
Fixed with deploying RESET slave at the clean-up.
When binlog_format is STATEMENT and the statement is unsafe before,
the unsafe warning/error message was issued without checking
whether the SQL_LOG_BIN was turned on or not.
Fixed with adding a sql_log_bin_toplevel flag in THD to check
whether SQL_LOG_BIN is ON in current session whatever the current is in sp or not.
Set wrong sql_mode when creating a procedure.
So that the sql_mode can't be writen into binary log correctly.
Restore the current session sql_mode right before generating the binlog event
when creating a procedure.
TRUNCATE TABLE fails to replicate when stmt-based binlogging is not supported.
Correcting some tests that was failing in pushbuild as well as fixing result
file for some tests that are not executed in the default MTR run.
The problem is that a unfiltered user query was being passed as
the format string parameter of sql_print_warning which later
performs printf-like formatting, leading to crashes if the user
query contains formatting instructions (ie: %s). Also, it was
using THD::query as the source of the user query, but this
variable is not meaningful in some situations -- in a delayed
insert, it points to the table name.
The solution is to pass the user query as a parameter for the
format string and use the function parameter query_arg as the
source of the user query.
TRUNCATE TABLE fails to replicate when stmt-based binlogging is not supported.
There were two separate problems with the code, both of which are fixed with
this patch:
1. An error was printed by InnoDB for TRUNCATE TABLE in statement mode when
the in isolation levels READ COMMITTED and READ UNCOMMITTED since InnoDB
does permit statement-based replication for DML statements. However,
the TRUNCATE TABLE is not transactional, but is a DDL, and should therefore
be allowed to be replicated as a statement.
2. The statement was not logged in mixed mode because of the error above, but
the error was not reported to the client.
This patch fixes the problem by treating TRUNCATE TABLE a DDL, that is, it is
always logged as a statement and not reporting an error from InnoDB for TRUNCATE
TABLE.
The test case proposed by the bugfix fails in bugteam trees after merging new
mtr from main. The failure is due to the fact that the binlog file location has
changed and is no more under $MYSQLTEST_VARDIR/log.
This patch fixes the test failure by setting the correct path to the binlog
file.
When using CREATE TEMPORARY TABLE LIKE to create a temporary table,
or using TRUNCATE to delete all rows of a temporary table, they
did not set the tmp_table_used flag, and cause the omission of
"SET @@session.pseudo_thread_id" when dumping binlog with mysqlbinlog,
and cause error when replay the statements.
This patch fixed the problem by setting tmp_table_used in these two
cases. (Done by He Zhenxing 2009-01-12)
conflicts:
Text conflict in client/mysqltest.cc
Text conflict in mysql-test/include/wait_until_connected_again.inc
Text conflict in mysql-test/lib/mtr_report.pm
Text conflict in mysql-test/mysql-test-run.pl
Text conflict in mysql-test/r/events_bugs.result
Text conflict in mysql-test/r/log_state.result
Text conflict in mysql-test/r/myisam_data_pointer_size_func.result
Text conflict in mysql-test/r/mysqlcheck.result
Text conflict in mysql-test/r/query_cache.result
Text conflict in mysql-test/r/status.result
Text conflict in mysql-test/suite/binlog/r/binlog_index.result
Text conflict in mysql-test/suite/binlog/r/binlog_innodb.result
Text conflict in mysql-test/suite/rpl/r/rpl_packet.result
Text conflict in mysql-test/suite/rpl/t/rpl_packet.test
Text conflict in mysql-test/t/disabled.def
Text conflict in mysql-test/t/events_bugs.test
Text conflict in mysql-test/t/log_state.test
Text conflict in mysql-test/t/myisam_data_pointer_size_func.test
Text conflict in mysql-test/t/mysqlcheck.test
Text conflict in mysql-test/t/query_cache.test
Text conflict in mysql-test/t/rpl_init_slave_func.test
Text conflict in mysql-test/t/status.test
The binlog_innodb test was sensitive to what tests ran before it. Now run
FLUSH STATUS before performing operations that need to be checked.
sys_var_thd_ulong::update() was improperly casting an option value from
ulonglong to ulong before comparing it to the max allowed value. On systems
where ulong and ulonglong are of different size, this caused values greater
than ULONG_MAX to wrap around (not be truncated to ULONG_MAX, which appears to
have been the intention of the original coder), and caused some checks to work
incorrectly. This wasn't generally visible to the user, because later checks
would prevent the wrapped-around value from being used. But it caused warning
messages to differ between 32- and 64-bit platforms. Fix is to just remove the
cast. Also added a DBUG_ASSERT to ensure that the value really is capped
properly before finally stuffing it into the ulong.
