polardbxengine/mysql-test/suite/rpl/t/rpl_trx_boundary_parser_war...

339 lines
13 KiB
Plaintext

# ==== Purpose ====
#
# This test will generate all expected transaction boundary parser warnings.
#
# It will disable GTID auto positioning and will make the IO thread to
# retrieve an unexpected event by stopping the IO thread, changing the
# master.info file manually and restarting the slave.
#
# ==== Related Bugs and Worklogs ====
#
# BUG#17943188: SHOW SLAVE STATUS/RETRIEVED_GTID_SET MAY HAVE PARTIAL TRX OR
# MISS COMPLETE TRX
#
# This test should run only on debug build
--source include/have_debug.inc
--source include/no_valgrind_without_big.inc
# This test uses debug sync to stop the IO thread in the middle of a transaction
--source include/have_debug_sync.inc
# Error message suppression
call mtr.add_suppression("Statement is unsafe because it is being used inside a XA transaction");
--source include/force_myisam_default.inc
--source include/have_myisam.inc
--source include/have_binlog_format_statement.inc
--source include/master-slave.inc
--source include/rpl_connection_slave.inc
# Error messages suppression on slave
call mtr.add_suppression("An unexpected event sequence was detected by the IO thread");
call mtr.add_suppression("GTID_LOG_EVENT .* is not expected in an event stream");
call mtr.add_suppression("QUERY.* is not expected in an event stream");
CALL mtr.add_suppression("Unsafe statement written to the binary log using statement format since*");
# Disable GTID auto positioning
--source include/stop_slave.inc
CHANGE MASTER TO MASTER_AUTO_POSITION= 0;
#--source include/start_slave.inc
--source include/rpl_connection_master.inc
--let $master_uuid= `SELECT @@GLOBAL.SERVER_UUID`
# Create a DDL with a USER_VAR event
SET @var= 10;
CREATE EVENT ev1 ON SCHEDULE EVERY @var HOUR DO INSERT INTO t1 VALUES (0);
# Create a transactional and a non-transactional table with data
CREATE TABLE t1 (c1 INT) ENGINE= InnoDB;
INSERT INTO t1 VALUES (1);
CREATE TABLE t2 (c1 INT) ENGINE= MyISAM;
INSERT INTO t2 VALUES (1);
#XA transaction
--eval XA START 'xa_trx'
INSERT INTO t1 VALUES(2);
--eval XA END 'xa_trx'
--eval XA PREPARE 'xa_trx'
--eval XA ROLLBACK 'xa_trx'
# Display all binlog events generated by the master
--let $keep_gtid_events= 1
--replace_result $master_uuid MASTER_UUID
# Make the non-GTID binlog event stream just like GTID one
--let $mask_anonymous_gtid_events= 1
--source include/show_binlog_events.inc
###
### Set some parameter that will be used in the event count loop
###
--let $expected_amount_of_events= 26
--let $event_to_remove_debug_point= $expected_amount_of_events
--dec $event_to_remove_debug_point
# We always start counting by the second event, skipping slave's FD
--let $event_counter= 2
--let $master_2nd_event_pos= query_get_value(SHOW BINLOG EVENTS IN 'master-bin.000001', Pos, 2)
--let $master_pos= $master_2nd_event_pos
###
### Prepare to count the events queued the the IO thread
###
--source include/rpl_connection_slave.inc
# Get the master.info file path (the $MYSQLD_SLAVE_DATADIR)
--let $MYSQLD_SLAVE_DATADIR= `select @@datadir`
--let $debug_point= pause_on_queuing_event
--source include/add_debug_point.inc
# Start the IO thread to start receiving events from master
START SLAVE IO_THREAD;
# Disabling query log during queue event counting
--disable_query_log
###
### Counting events and generating master.info.backup files
###
while ($event_counter <= $expected_amount_of_events)
{
# We need to wait for an event to be queued until the expected amount
if ($event_counter < $expected_amount_of_events)
{
SET DEBUG_SYNC='now WAIT_FOR reached_queuing_event';
}
# For the last expected event we can just sync IO thread as there is
# no more events to retrieved after it.
if ($event_counter == $expected_amount_of_events)
{
--source include/rpl_connection_master.inc
--source include/sync_slave_io_with_master.inc
}
# For all retrieved events after the PREVIOUS_GTIDs
if ($event_counter > 2)
{
--echo # This is the event #$event_counter of current slave relay log file
--let $master_pos= query_get_value(SHOW RELAYLOG EVENTS IN 'slave-relay-bin.000002' FROM $master_pos, Pos, 2)
--let $binlog_start= $master_pos
--let $binlog_file= slave-relay-bin.000002
--source include/show_relaylog_events.inc
}
# We can remove the debug point after reaching the event before
# the last expected event
if ($event_counter == $event_to_remove_debug_point)
{
--source include/remove_debug_point.inc
}
# Generate a master.info.backup file pointing to the event to be queued
--copy_file $MYSQLD_SLAVE_DATADIR/master.info $MYSQLD_SLAVE_DATADIR/master.backup.$event_counter
# Let the event be queued and the IO thread to retrieve the next one
if ($event_counter < $expected_amount_of_events)
{
SET DEBUG_SYNC= 'now SIGNAL continue_queuing_event';
}
--inc $event_counter
}
--enable_query_log
###
### Setup common GREP environment variables to display mysql error log entries
### with the expected errors.
###
# File to GREP
--let $assert_file=$MYSQLTEST_VARDIR/log/mysqld.2.err
# Show entries only after the last occurrence of the following pattern
--let $assert_only_after=.* \[Note\] \[[^]]*\] \[[^]]*\] Shutting down slave threads
# Each test will log only one warning line
--let $assert_count= 1
--echo
--echo #
--echo # Case 1: GTID_LOG_EVENT is not expected in an event stream after a GTID_LOG_EVENT.
--echo #
--let $stop_after= 8
--let $restart_at= 8
--source extra/rpl_tests/rpl_trx_boundary_parser_warning.inc
# Assert that there is the expected warning log line but just after the last restart
--let $assert_select=.* \[Warning\] \[[^]]*\] \[[^]]*\] GTID_LOG_EVENT .* is not expected.*
--let $assert_text= Case 1 found the expected warning line in the error log.
--source include/assert_grep.inc
--echo
--echo #
--echo # Case 2: GTID_LOG_EVENT is not expected in an event stream in the middle of a DDL.
--echo #
--let $stop_after= 6
--let $restart_at= 8
--source extra/rpl_tests/rpl_trx_boundary_parser_warning.inc
# Assert that there is the expected warning log line but just after the last restart
--let $assert_select=.* \[Warning\] \[[^]]*\] \[[^]]*\] GTID_LOG_EVENT .* is not expected.*
--let $assert_text= Case 2 found the expected warning line in the error log.
--source include/assert_grep.inc
--echo
--echo #
--echo # Case 3: GTID_LOG_EVENT is not expected in an event stream in the middle of a DML.
--echo #
--let $stop_after= 11
--let $restart_at= 10
--source extra/rpl_tests/rpl_trx_boundary_parser_warning.inc
# Assert that there is the expected warning log line but just after the last restart
--let $assert_select=.* \[Warning\] \[[^]]*\] \[[^]]*\] GTID_LOG_EVENT .* is not expected.*
--let $assert_text= Case 3 found the expected warning line in the error log.
--source include/assert_grep.inc
--echo
--echo #
--echo # Case 4: QUERY(BEGIN) is not expected in an event stream in the middle of a DDL.
--echo #
--let $stop_after= 6
--let $restart_at= 11
--source extra/rpl_tests/rpl_trx_boundary_parser_warning.inc
# Assert that there is the expected warning log line but just after the last restart
--let $assert_select=.* \[Warning\] \[[^]]*\] \[[^]]*\] QUERY\(BEGIN\) is not expected.*
--let $assert_text= Case 4 found the expected warning line in the error log.
--source include/assert_grep.inc
--echo
--echo #
--echo # Case 5: QUERY(BEGIN) is not expected in an event stream in the middle of a DML.
--echo #
--let $stop_after= 11
--let $restart_at= 11
--source extra/rpl_tests/rpl_trx_boundary_parser_warning.inc
# Assert that there is the expected warning log line but just after the last restart
--let $assert_select=.* \[Warning\] \[[^]]*\] \[[^]]*\] QUERY\(BEGIN\) is not expected.*
--let $assert_text= Case 5 found the expected warning line in the error log.
--source include/assert_grep.inc
--echo
--echo #
--echo # Case 6.a: QUERY(COMMIT or ROLLBACK) or XID_LOG_EVENT is not expected in an event stream outside a transaction.
--echo #
--let $stop_after= 9
--let $restart_at= 13
--source extra/rpl_tests/rpl_trx_boundary_parser_warning.inc
# Assert that there is the expected warning log line but just after the last restart
--let $assert_select=.* \[Warning\] \[[^]]*\] \[[^]]*\] QUERY\(COMMIT or ROLLBACK\) or XID_LOG_EVENT is not expected.*
--let $assert_text= Case 6.a found the expected warning line in the error log.
--source include/assert_grep.inc
--echo
--echo #
--echo # Case 6.b: QUERY(COMMIT or ROLLBACK) or XID_LOG_EVENT is not expected in an event stream outside a transaction.
--echo #
--let $stop_after= 9
--let $restart_at= 19
--source extra/rpl_tests/rpl_trx_boundary_parser_warning.inc
# Assert that there is the expected warning log line but just after the last restart
--let $assert_select=.* \[Warning\] \[[^]]*\] \[[^]]*\] QUERY\(COMMIT or ROLLBACK\) or XID_LOG_EVENT is not expected.*
--let $assert_text= Case 6.b found the expected warning line in the error log.
--source include/assert_grep.inc
--echo
--echo #
--echo # Case 7.a: QUERY(COMMIT or ROLLBACK) or XID_LOG_EVENT is not expected in an event stream after a GTID_LOG_EVENT.
--echo #
--let $stop_after= 8
--let $restart_at= 13
--source extra/rpl_tests/rpl_trx_boundary_parser_warning.inc
# Assert that there is the expected warning log line but just after the last restart
--let $assert_select=.* \[Warning\] \[[^]]*\] \[[^]]*\] QUERY\(COMMIT or ROLLBACK\) or XID_LOG_EVENT is not expected.*
--let $assert_text= Case 7.a found the expected warning line in the error log.
--source include/assert_grep.inc
--echo
--echo #
--echo # Case 7.b: QUERY(COMMIT or ROLLBACK) or XID_LOG_EVENT is not expected in an event stream after a GTID_LOG_EVENT.
--echo #
--let $stop_after= 8
--let $restart_at= 19
--source extra/rpl_tests/rpl_trx_boundary_parser_warning.inc
# Assert that there is the expected warning log line but just after the last restart
--let $assert_select=.* \[Warning\] \[[^]]*\] \[[^]]*\] QUERY\(COMMIT or ROLLBACK\) or XID_LOG_EVENT is not expected.*
--let $assert_text= Case 7.b found the expected warning line in the error log.
--source include/assert_grep.inc
--echo
--echo #
--echo # Case 8.a: QUERY(COMMIT or ROLLBACK) or XID_LOG_EVENT is not expected in an event stream in the middle of a DDL.
--echo #
--let $stop_after= 6
--let $restart_at= 13
--source extra/rpl_tests/rpl_trx_boundary_parser_warning.inc
# Assert that there is the expected warning log line but just after the last restart
--let $assert_select=.* \[Warning\] \[[^]]*\] \[[^]]*\] QUERY\(COMMIT or ROLLBACK\) or XID_LOG_EVENT is not expected.*
--let $assert_text= Case 8.a found the expected warning line in the error log.
--source include/assert_grep.inc
--echo
--echo #
--echo # Case 8.b: QUERY(COMMIT or ROLLBACK) or XID_LOG_EVENT is not expected in an event stream in the middle of a DDL.
--echo #
--let $stop_after= 6
--let $restart_at= 19
--source extra/rpl_tests/rpl_trx_boundary_parser_warning.inc
# Assert that there is the expected warning log line but just after the last restart
--let $assert_select=.* \[Warning\] \[[^]]*\] \[[^]]*\] QUERY\(COMMIT or ROLLBACK\) or XID_LOG_EVENT is not expected.*
--let $assert_text= Case 8.b found the expected warning line in the error log.
--source include/assert_grep.inc
--echo
--echo #
--echo # Case 9.a: QUERY(XA ROLLBACK) is not expected in an event stream in the middle of a DDL.
--echo #
--let $stop_after= 6
--let $restart_at= 26
--source extra/rpl_tests/rpl_trx_boundary_parser_warning.inc
# Assert that there is the expected warning log line but just after the last restart
--let $assert_select=.* \[Warning\] \[[^]]*\] \[[^]]*\] QUERY\(XA ROLLBACK\) is not expected.*
--let $assert_text= Case 9.a found the expected warning line in the error log.
--source include/assert_grep.inc
--echo
--echo #
--echo # Case 9.b: QUERY(XA ROLLBACK) is not expected in an event stream outside a transaction.
--echo #
--let $stop_after= 9
--let $restart_at= 26
--source extra/rpl_tests/rpl_trx_boundary_parser_warning.inc
# Assert that there is the expected warning log line but just after the last restart
--let $assert_select=.* \[Warning\] \[[^]]*\] \[[^]]*\] QUERY\(XA ROLLBACK\) is not expected.*
--let $assert_text= Case 9.b found the expected warning line in the error log.
--source include/assert_grep.inc
--echo
--echo #
--echo # Prepare the slave to correctly replicate again after the test case
--echo #
# Restart the slave
--let $rpl_server_number= 2
--let $rpl_force_stop=0
--source include/rpl_stop_server.inc
--source include/rpl_start_server.inc
# Reset the slave and enable GTID auto positioning if needed
--source include/rpl_connection_slave.inc
--source include/stop_slave.inc
--disable_warnings
DROP TABLE IF EXISTS t1, t2;
--enable_warnings
RESET MASTER;
RESET SLAVE;
if ($use_gtids)
{
--disable_query_log
CHANGE MASTER TO MASTER_AUTO_POSITION= 1;
--enable_query_log
}
--source include/start_slave.inc
###
### Cleanup
###
# Remove the master.info.backup files
--let $event_counter= 2
while ($event_counter <= $expected_amount_of_events)
{
--remove_file $MYSQLD_SLAVE_DATADIR/master.backup.$event_counter
--inc $event_counter
}
# Drop the created tables
--source include/rpl_connection_master.inc
DROP TABLE t1, t2;
DROP EVENT ev1;
--source include/rpl_end.inc