diff options
| -rw-r--r-- | mysql-test/suite/binlog/include/binlog_write_error.inc | 2 | ||||
| -rw-r--r-- | mysql-test/suite/binlog/r/binlog_bug23533.result | 1 | ||||
| -rw-r--r-- | mysql-test/suite/binlog/r/binlog_write_error.result | 1 | ||||
| -rw-r--r-- | mysql-test/suite/binlog/t/binlog_bug23533.test | 2 | ||||
| -rw-r--r-- | mysql-test/suite/binlog_encryption/binlog_write_error.result | 1 | ||||
| -rw-r--r-- | mysql-test/suite/binlog_encryption/rpl_mixed_binlog_max_cache_size.result | 2 | ||||
| -rw-r--r-- | mysql-test/suite/rpl/include/rpl_binlog_max_cache_size.test | 2 | ||||
| -rw-r--r-- | mysql-test/suite/rpl/r/rpl_mdev-11092.result | 211 | ||||
| -rw-r--r-- | mysql-test/suite/rpl/r/rpl_mixed_binlog_max_cache_size.result | 2 | ||||
| -rw-r--r-- | mysql-test/suite/rpl/r/rpl_stm_binlog_max_cache_size.result | 2 | ||||
| -rw-r--r-- | mysql-test/suite/rpl/t/rpl_mdev-11092.test | 498 | ||||
| -rw-r--r-- | sql/handler.cc | 8 | ||||
| -rw-r--r-- | sql/log.cc | 71 |
13 files changed, 778 insertions, 25 deletions
diff --git a/mysql-test/suite/binlog/include/binlog_write_error.inc b/mysql-test/suite/binlog/include/binlog_write_error.inc index fa3ba087a7e..be5e9e0cfea 100644 --- a/mysql-test/suite/binlog/include/binlog_write_error.inc +++ b/mysql-test/suite/binlog/include/binlog_write_error.inc @@ -38,6 +38,8 @@ DROP TRIGGER IF EXISTS tr2; DROP VIEW IF EXISTS v1, v2; enable_warnings; +call mtr.add_suppression("Write to binary log failed: Error writing file*"); + --echo # --echo # Test injecting binlog write error when executing queries --echo # diff --git a/mysql-test/suite/binlog/r/binlog_bug23533.result b/mysql-test/suite/binlog/r/binlog_bug23533.result index cc9799506c3..aa357b58f2c 100644 --- a/mysql-test/suite/binlog/r/binlog_bug23533.result +++ b/mysql-test/suite/binlog/r/binlog_bug23533.result @@ -1,3 +1,4 @@ +call mtr.add_suppression("Write to binary log failed: Multi-statement transaction required more than .max_binlog_cache_size.*"); SET AUTOCOMMIT=0; CREATE TABLE t1 (a INT NOT NULL AUTO_INCREMENT, b TEXT, PRIMARY KEY(a)) ENGINE=InnoDB; SELECT COUNT(*) FROM t1; diff --git a/mysql-test/suite/binlog/r/binlog_write_error.result b/mysql-test/suite/binlog/r/binlog_write_error.result index 6e8a212035a..7e8e373c797 100644 --- a/mysql-test/suite/binlog/r/binlog_write_error.result +++ b/mysql-test/suite/binlog/r/binlog_write_error.result @@ -9,6 +9,7 @@ DROP PROCEDURE IF EXISTS p2; DROP TRIGGER IF EXISTS tr1; DROP TRIGGER IF EXISTS tr2; DROP VIEW IF EXISTS v1, v2; +call mtr.add_suppression("Write to binary log failed: Error writing file*"); # # Test injecting binlog write error when executing queries # diff --git a/mysql-test/suite/binlog/t/binlog_bug23533.test b/mysql-test/suite/binlog/t/binlog_bug23533.test index ca610e399e4..a77497115e5 100644 --- a/mysql-test/suite/binlog/t/binlog_bug23533.test +++ b/mysql-test/suite/binlog/t/binlog_bug23533.test @@ -6,7 +6,7 @@ --source include/have_innodb.inc --source include/have_log_bin.inc --source include/have_binlog_format_row.inc - +call mtr.add_suppression("Write to binary log failed: Multi-statement transaction required more than .max_binlog_cache_size.*"); SET AUTOCOMMIT=0; # Create 1st table diff --git a/mysql-test/suite/binlog_encryption/binlog_write_error.result b/mysql-test/suite/binlog_encryption/binlog_write_error.result index 6e8a212035a..7e8e373c797 100644 --- a/mysql-test/suite/binlog_encryption/binlog_write_error.result +++ b/mysql-test/suite/binlog_encryption/binlog_write_error.result @@ -9,6 +9,7 @@ DROP PROCEDURE IF EXISTS p2; DROP TRIGGER IF EXISTS tr1; DROP TRIGGER IF EXISTS tr2; DROP VIEW IF EXISTS v1, v2; +call mtr.add_suppression("Write to binary log failed: Error writing file*"); # # Test injecting binlog write error when executing queries # diff --git a/mysql-test/suite/binlog_encryption/rpl_mixed_binlog_max_cache_size.result b/mysql-test/suite/binlog_encryption/rpl_mixed_binlog_max_cache_size.result index 388c8e67b68..944ad9331ad 100644 --- a/mysql-test/suite/binlog_encryption/rpl_mixed_binlog_max_cache_size.result +++ b/mysql-test/suite/binlog_encryption/rpl_mixed_binlog_max_cache_size.result @@ -1,6 +1,8 @@ include/master-slave.inc [connection master] call mtr.add_suppression("Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT"); +call mtr.add_suppression("Write to binary log failed: Multi-row statements required more than .max_binlog_stmt_cache_size"); +call mtr.add_suppression("Write to binary log failed: Multi-statement transaction required more than .max_binlog_cache_size"); SET GLOBAL max_binlog_cache_size = 4096; SET GLOBAL binlog_cache_size = 4096; SET GLOBAL max_binlog_stmt_cache_size = 4096; diff --git a/mysql-test/suite/rpl/include/rpl_binlog_max_cache_size.test b/mysql-test/suite/rpl/include/rpl_binlog_max_cache_size.test index 4c93ad86209..d750554b4ec 100644 --- a/mysql-test/suite/rpl/include/rpl_binlog_max_cache_size.test +++ b/mysql-test/suite/rpl/include/rpl_binlog_max_cache_size.test @@ -22,6 +22,8 @@ # ######################################################################################## call mtr.add_suppression("Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT"); +call mtr.add_suppression("Write to binary log failed: Multi-row statements required more than .max_binlog_stmt_cache_size"); +call mtr.add_suppression("Write to binary log failed: Multi-statement transaction required more than .max_binlog_cache_size"); let $old_max_binlog_cache_size= query_get_value(SHOW VARIABLES LIKE "max_binlog_cache_size", Value, 1); let $old_binlog_cache_size= query_get_value(SHOW VARIABLES LIKE "binlog_cache_size", Value, 1); diff --git a/mysql-test/suite/rpl/r/rpl_mdev-11092.result b/mysql-test/suite/rpl/r/rpl_mdev-11092.result index 8bc8fe4a20b..a685e204e7a 100644 --- a/mysql-test/suite/rpl/r/rpl_mdev-11092.result +++ b/mysql-test/suite/rpl/r/rpl_mdev-11092.result @@ -1,7 +1,12 @@ include/master-slave.inc [connection master] call mtr.add_suppression("Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT"); -call mtr.add_suppression("Slave SQL: The incident LOST_EVENTS occurred on the master. .*"); +call mtr.add_suppression("Slave SQL: The incident LOST_EVENTS occured on the master. .*"); +call mtr.add_suppression("Write to binary log failed: Multi-row statements required more than .max_binlog_stmt_cache_size.* "); +call mtr.add_suppression("Write to binary log failed: Multi-statement transaction required more than .max_binlog_cache_size.* "); +call mtr.add_suppression("Incident event write to the binary log file failed"); +call mtr.add_suppression("handlerton rollback failed"); +"*********** Annotate Event write failure **************" SET GLOBAL max_binlog_cache_size = 4096; SET GLOBAL binlog_cache_size = 4096; SET GLOBAL max_binlog_stmt_cache_size = 4096; @@ -10,12 +15,212 @@ disconnect master; connect master,127.0.0.1,root,,test,$MASTER_MYPORT,; CREATE TABLE t1(a INT PRIMARY KEY, data VARCHAR(30000)) ENGINE=MYISAM; connection master; -ERROR HY000: Writing one row to the row-based binary log failed +"#######################################################################" +"# Test Case1: Annotate event write failure for MyISAM #" +"#######################################################################" +ERROR HY000: Multi-row statements required more than 'max_binlog_stmt_cache_size' bytes of storage; increase this mysqld variable and try again +# Validating update was not binlogged.. +# ..success +# Validating that the inserted data was saved on the master.. +# ..success +connection slave; include/wait_for_slave_sql_error_and_skip.inc [errno=1590] +# Validating that the insert was not replicated to the slave.. +# ..success +"#######################################################################" +"# Test Case2: Annotate event write failure for INNODB #" +"#######################################################################" connection master; +CREATE TABLE t2(a INT PRIMARY KEY, data VARCHAR(30000)) ENGINE=INNODB; +ERROR HY000: Multi-statement transaction required more than 'max_binlog_cache_size' bytes of storage; increase this mysqld variable and try again +# Validating binlog GTID position progressed from first insert.. +# ..success +# Validating that only the first insert into t2 saved.. +# ..success +include/save_master_gtid.inc +connection slave; +include/sync_with_master_gtid.inc +# Validating the first insert into t2 replicated to slave.. +include/diff_tables.inc [master:test.t2,slave:test.t2] +# ..success +"#######################################################################" +"# Test Case3: Annotate event write failure for mixed engine UPDATE #" +"#######################################################################" +connection master; +ERROR HY000: Multi-row statements required more than 'max_binlog_stmt_cache_size' bytes of storage; increase this mysqld variable and try again +# Validating update was not binlogged.. +# ..success +# Validating non-transactional part of update saved.. +# ..success +# Validating transactional part of update was rolled back.. +# ..success +include/save_master_gtid.inc +connection slave; +include/wait_for_slave_sql_error_and_skip.inc [errno=1590] +# Validating the rolled-back multi-engine update did not replicate to slave at all.. +# ..success +connection master; +"****** Clean up *******" SET GLOBAL max_binlog_cache_size= ORIGINAL_VALUE; SET GLOBAL binlog_cache_size= ORIGINAL_VALUE; SET GLOBAL max_binlog_stmt_cache_size= ORIGINAL_VALUE; SET GLOBAL binlog_stmt_cache_size= ORIGINAL_VALUE; -DROP TABLE t1; +DROP TABLE t1,t2; +"*********** TABLE MAP Event write failure **************" +CREATE TABLE tm (f INT) ENGINE=MYISAM; +CREATE TABLE ti (f INT) ENGINE=INNODB; +INSERT INTO tm VALUES (10); +INSERT INTO ti VALUES (20); +connection slave; +"#######################################################################" +"# Test Case4: Table_map event write failure for trans engine UPDATE #" +"#######################################################################" +# Transaction should be rolled back without writing incident event +connection master; +SET debug_dbug="+d,table_map_write_error"; +UPDATE ti, tm set ti.f=30; +ERROR HY000: Multi-statement transaction required more than 'max_binlog_cache_size' bytes of storage; increase this mysqld variable and try again +# Validating update was not binlogged.. +# ..success +# Validating update was rolled back from storage engines.. +# ..success +include/save_master_gtid.inc +connection slave; +include/sync_with_master_gtid.inc +"#######################################################################" +"# Test Case5: Table_map event write failure for mixed engine UPDATE #" +"#######################################################################" +connection master; +# In case of mixed engines if non trans table is updated write INCIDENT event +UPDATE ti,tm SET tm.f=88, ti.f=120; +ERROR HY000: Multi-statement transaction required more than 'max_binlog_cache_size' bytes of storage; increase this mysqld variable and try again +# Validating update was not binlogged.. +# ..success +# Validating that only the non-transactional update saved on master.. +# ..success +connection slave; +include/wait_for_slave_sql_error_and_skip.inc [errno=1590] +# Validating that neither of the updates replicated to slave.. +# ..success +"#######################################################################" +"# Test Case6: Committing a transaction consisting of two updates: +"# S1) Update transactional table +"# S2) Update transactional table +"# with a table_map event write failure on the second event should +"# roll-back only the second update without incident +"#######################################################################" +connection master; +SET debug_dbug=""; +BEGIN; +UPDATE ti, tm set ti.f=40; +SET debug_dbug="+d,table_map_write_error"; +UPDATE ti, tm set ti.f=50; +ERROR HY000: Multi-statement transaction required more than 'max_binlog_cache_size' bytes of storage; increase this mysqld variable and try again +COMMIT; +# Validating binlog GTID position progressed from first update.. +# ..success +# Validating the first update saved.. +# ..and that the second update did not save.. +# ..success +# Validating that only the first update replicated to slave without incident +connection master; +include/save_master_gtid.inc +connection slave; +include/sync_with_master_gtid.inc +include/diff_tables.inc [master:test.ti,slave:test.ti] +"#######################################################################" +"# Test Case7: Rolling back a transaction consisting of two updates: +"# S1) Update transactional table +"# S2) Update transactional table +"# with a table_map event write failure on the second event should +"# roll-back both updates without incident +"#######################################################################" +connection master; +SET debug_dbug=""; +BEGIN; +UPDATE ti, tm set ti.f=60; +SET debug_dbug="+d,table_map_write_error"; +UPDATE ti, tm set ti.f=70; +ERROR HY000: Multi-statement transaction required more than 'max_binlog_cache_size' bytes of storage; increase this mysqld variable and try again +ROLLBACK; +# Validating update was not binlogged.. +# ..success +# Validating that neither update saved on master.. +# ..success +# Validating the transaction did not replicate to the slave +connection master; +include/save_master_gtid.inc +connection slave; +include/sync_with_master_gtid.inc +include/diff_tables.inc [master:test.ti,slave:test.ti] +"#######################################################################" +"# Test Case8: Committing a transaction consisting of two updates: +"# S1) Update transactional table +"# S2) Update mixed trans/non-trans tables +"# with a table_map event write failure on the second event should +"# roll-back only the second update with incident +"#######################################################################" +connection master; +BEGIN; +SET debug_dbug=""; +UPDATE ti, tm set ti.f=80; +SET debug_dbug="+d,table_map_write_error"; +UPDATE ti, tm set ti.f=90,tm.f=99; +ERROR HY000: Multi-statement transaction required more than 'max_binlog_cache_size' bytes of storage; increase this mysqld variable and try again +COMMIT; +# Validating binlog GTID position progressed from first update.. +# ..success +# Validating the first update saved.. +# ..and the transactional part of the second update did not save.. +# ..whereas the non-trans part of the second update did save.. +# ..success +# Validating that the incident propagated to the slave +connection slave; +include/wait_for_slave_sql_error_and_skip.inc [errno=1590] +# Validating that the first update replicated to the slave.. +# ..and neither part of the second update replicated.. +# ..success +"#######################################################################" +"# Test Case9: Rolling back a transaction consisting of two updates: +"# S1) Update transactional table +"# S2) Update mixed trans/non-trans tables +"# with a table_map event write failure on the second event should +"# roll-back both transactional updates, preserve the non-transactional +"# update on the master (only), and write an incident event +"#######################################################################" +connection master; +SET debug_dbug=""; +BEGIN; +UPDATE ti, tm set ti.f=100; +SET debug_dbug="+d,table_map_write_error"; +UPDATE ti, tm set ti.f=110,tm.f=111; +ERROR HY000: Multi-statement transaction required more than 'max_binlog_cache_size' bytes of storage; increase this mysqld variable and try again +ROLLBACK; +# Validating update was not binlogged.. +# ..success +# Validating trans updates rollback, but the non-trans update stays.. +# ..success +# Validating that the incident propagated to the slave +connection slave; +include/wait_for_slave_sql_error_and_skip.inc [errno=1590] +# Validating that none of the updates replicated to the slave +include/diff_tables.inc [master:test.ti,slave:test.ti] +# ..success +"#######################################################################" +"# Test Case10: If an incident event fails to write, a specific error +"# should be logged +"# +"# Note: This test case is the same as test case 5, with the caveat of +"# the incident event failing to write. +"#######################################################################" +connection master; +SET debug_dbug="d,table_map_write_error,incident_event_write_error"; +UPDATE ti, tm set ti.f=120, tm.f=122; +ERROR HY000: Multi-statement transaction required more than 'max_binlog_cache_size' bytes of storage; increase this mysqld variable and try again +# Validate error message indicating incident event failed to write +FOUND 1 /Incident event write to the binary log file failed/ in mysqld.1.err +connection master; +"******** Clean Up **********" +SET GLOBAL debug_dbug = ''; +DROP TABLE tm,ti; include/rpl_end.inc diff --git a/mysql-test/suite/rpl/r/rpl_mixed_binlog_max_cache_size.result b/mysql-test/suite/rpl/r/rpl_mixed_binlog_max_cache_size.result index 388c8e67b68..944ad9331ad 100644 --- a/mysql-test/suite/rpl/r/rpl_mixed_binlog_max_cache_size.result +++ b/mysql-test/suite/rpl/r/rpl_mixed_binlog_max_cache_size.result @@ -1,6 +1,8 @@ include/master-slave.inc [connection master] call mtr.add_suppression("Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT"); +call mtr.add_suppression("Write to binary log failed: Multi-row statements required more than .max_binlog_stmt_cache_size"); +call mtr.add_suppression("Write to binary log failed: Multi-statement transaction required more than .max_binlog_cache_size"); SET GLOBAL max_binlog_cache_size = 4096; SET GLOBAL binlog_cache_size = 4096; SET GLOBAL max_binlog_stmt_cache_size = 4096; diff --git a/mysql-test/suite/rpl/r/rpl_stm_binlog_max_cache_size.result b/mysql-test/suite/rpl/r/rpl_stm_binlog_max_cache_size.result index 388c8e67b68..944ad9331ad 100644 --- a/mysql-test/suite/rpl/r/rpl_stm_binlog_max_cache_size.result +++ b/mysql-test/suite/rpl/r/rpl_stm_binlog_max_cache_size.result @@ -1,6 +1,8 @@ include/master-slave.inc [connection master] call mtr.add_suppression("Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT"); +call mtr.add_suppression("Write to binary log failed: Multi-row statements required more than .max_binlog_stmt_cache_size"); +call mtr.add_suppression("Write to binary log failed: Multi-statement transaction required more than .max_binlog_cache_size"); SET GLOBAL max_binlog_cache_size = 4096; SET GLOBAL binlog_cache_size = 4096; SET GLOBAL max_binlog_stmt_cache_size = 4096; diff --git a/mysql-test/suite/rpl/t/rpl_mdev-11092.test b/mysql-test/suite/rpl/t/rpl_mdev-11092.test index 782d24803c7..0c020386b98 100644 --- a/mysql-test/suite/rpl/t/rpl_mdev-11092.test +++ b/mysql-test/suite/rpl/t/rpl_mdev-11092.test @@ -1,3 +1,4 @@ +--source include/have_debug.inc --source include/have_innodb.inc --source include/not_embedded.inc --source include/not_windows.inc @@ -6,13 +7,19 @@ ######################################################################################## call mtr.add_suppression("Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT"); -call mtr.add_suppression("Slave SQL: The incident LOST_EVENTS occurred on the master. .*"); +call mtr.add_suppression("Slave SQL: The incident LOST_EVENTS occured on the master. .*"); +call mtr.add_suppression("Write to binary log failed: Multi-row statements required more than .max_binlog_stmt_cache_size.* "); +call mtr.add_suppression("Write to binary log failed: Multi-statement transaction required more than .max_binlog_cache_size.* "); +call mtr.add_suppression("Incident event write to the binary log file failed"); +call mtr.add_suppression("handlerton rollback failed"); let $old_max_binlog_cache_size= query_get_value(SHOW VARIABLES LIKE "max_binlog_cache_size", Value, 1); let $old_binlog_cache_size= query_get_value(SHOW VARIABLES LIKE "binlog_cache_size", Value, 1); let $old_max_binlog_stmt_cache_size= query_get_value(SHOW VARIABLES LIKE "max_binlog_stmt_cache_size", Value, 1); let $old_binlog_stmt_cache_size= query_get_value(SHOW VARIABLES LIKE "binlog_stmt_cache_size", Value, 1); +--echo "*********** Annotate Event write failure **************" + SET GLOBAL max_binlog_cache_size = 4096; SET GLOBAL binlog_cache_size = 4096; SET GLOBAL max_binlog_stmt_cache_size = 4096; @@ -26,19 +33,162 @@ let $data = `select concat('"', repeat('a',2000), '"')`; connection master; +# Insert a huge row into MyISAM table. The row will be inserted in engine and a +# request to write to binary log will be initiated. Since row annotations are +# enabled the size of the annotate event itself will exceed the +# "max_binlog_stmt_cache_size". This will result in ER_STMT_CACHE_FULL error +# and an incident event will be written to the binary log as row update in +# engine cannot be undone. + +--echo "#######################################################################" +--echo "# Test Case1: Annotate event write failure for MyISAM #" +--echo "#######################################################################" + --disable_query_log ---error ER_BINLOG_ROW_LOGGING_FAILED +--let $old_gtid_binlog_pos= query_get_value(SHOW VARIABLES LIKE 'gtid_binlog_pos', Value, 1) +--error ER_STMT_CACHE_FULL eval INSERT INTO t1 (a, data) VALUES (2, CONCAT($data, $data, $data, $data, $data, $data)); --enable_query_log +--let $new_gtid_binlog_pos= query_get_value(SHOW VARIABLES LIKE 'gtid_binlog_pos', Value, 1) +--echo # Validating update was not binlogged.. +if(`SELECT strcmp("$old_gtid_binlog_pos","$new_gtid_binlog_pos") != 0`) +{ + --die Binlog GTID position should have been unchanged after failed update +} +--echo # ..success + +--echo # Validating that the inserted data was saved on the master.. +if(`SELECT COUNT(*)!=1 FROM t1`) +{ + --die The insertion should have saved on a non-transactional table +} +--echo # ..success + +--connection slave # Incident event # 1590=ER_SLAVE_INCIDENT --let $slave_sql_errno= 1590 --source include/wait_for_slave_sql_error_and_skip.inc -connection master; +--echo # Validating that the insert was not replicated to the slave.. +if(`SELECT COUNT(*) FROM t1`) +{ + --die The insertion should not have replicated to the slave +} +--echo # ..success + +# MDEV-21087 +# Insert two huge rows in to transaction cache. Have data such that first row +# fits inside the binary log cache. While writing the annotate event for the +# second row the binary log cache size will exceed "max_binlog_cache_size". +# Hence this statement cannot be written to binary log. As DMLs in Innodb can +# be safely rolled back only an error will be reported. Slave will continue to +# work. + +--echo "#######################################################################" +--echo "# Test Case2: Annotate event write failure for INNODB #" +--echo "#######################################################################" + +--connection master +CREATE TABLE t2(a INT PRIMARY KEY, data VARCHAR(30000)) ENGINE=INNODB; +--disable_query_log +--let $old_gtid_binlog_pos= query_get_value(SHOW VARIABLES LIKE 'gtid_binlog_pos', Value, 1) +BEGIN; +eval INSERT INTO t2 (a, data) VALUES (1, CONCAT($data, $data)); +--error ER_TRANS_CACHE_FULL +eval INSERT INTO t2 (a, data) VALUES (2, CONCAT($data, $data)); +COMMIT; +--enable_query_log + +--let $new_gtid_binlog_pos= query_get_value(SHOW VARIABLES LIKE 'gtid_binlog_pos', Value, 1) +--echo # Validating binlog GTID position progressed from first insert.. +if(`SELECT strcmp("$old_gtid_binlog_pos","$new_gtid_binlog_pos") = 0`) +{ + --die Binlog GTID position should have updated +} +--echo # ..success + +--echo # Validating that only the first insert into t2 saved.. +if(`SELECT COUNT(*)!=1 FROM t2`) +{ + --die Only one row should exist in t2 from the first insert, the second should have rolled back +} +--echo # ..success +--source include/save_master_gtid.inc + +--connection slave +--source include/sync_with_master_gtid.inc +--echo # Validating the first insert into t2 replicated to slave.. +--let $diff_tables= master:test.t2,slave:test.t2 +--source include/diff_tables.inc +--echo # ..success + +# Testing mixed engine UPDATE statement scenario. In the following multi +# update query 'ha_update_row' will be invoked for t1 (myisam) table. This +# intern invokes binlog_write_table_map() function call. While writing a huge +# annotate event binary log cache size will exceed max_binlog_cache_size. +# Writing to binary log fails. Since non transactional changes cannot be +# rolled back incident event will be written to binary log. + +--echo "#######################################################################" +--echo "# Test Case3: Annotate event write failure for mixed engine UPDATE #" +--echo "#######################################################################" + +--connection master +let $new_data = `select concat('"', repeat('b',2000), '"')`; +--let $old_gtid_binlog_pos= query_get_value(SHOW VARIABLES LIKE 'gtid_binlog_pos', Value, 1) +--disable_query_log +--error ER_STMT_CACHE_FULL +eval UPDATE t1,t2 SET t1.data="Hello", t2.data=CONCAT($new_data,$new_data,$new_data,$new_data,$new_data); +--enable_query_log + +--let $new_gtid_binlog_pos= query_get_value(SHOW VARIABLES LIKE 'gtid_binlog_pos', Value, 1) +--echo # Validating update was not binlogged.. +if(`SELECT strcmp("$old_gtid_binlog_pos","$new_gtid_binlog_pos") != 0`) +{ + --die Binlog GTID position should have been unchanged after failed update +} +--echo # ..success + +--echo # Validating non-transactional part of update saved.. +if(`SELECT COUNT(*)!=1 from t1 where data="Hello"`) +{ + --die Non-transactional part of update should have saved +} +--echo # ..success + +--echo # Validating transactional part of update was rolled back.. +if(`SELECT COUNT(*) from t2 where data LIKE "b%"`) +{ + --die Transactional part of update should have been rolled back +} +--echo # ..success +--source include/save_master_gtid.inc + +--connection slave + +# Incident event +# 1590=ER_SLAVE_INCIDENT +--let $slave_sql_errno= 1590 +--source include/wait_for_slave_sql_error_and_skip.inc + +--echo # Validating the rolled-back multi-engine update did not replicate to slave at all.. +if(`SELECT COUNT(*) from t1 where data="Hello"`) +{ + --die Non-transactional part of update should not have replicated +} +if(`SELECT COUNT(*) from t2 where data LIKE "b%"`) +{ + --die Transactional part of update should not have replicated +} +--echo # ..success + +--connection master + +--echo "****** Clean up *******" --replace_result $old_max_binlog_cache_size ORIGINAL_VALUE --eval SET GLOBAL max_binlog_cache_size= $old_max_binlog_cache_size --replace_result $old_binlog_cache_size ORIGINAL_VALUE @@ -48,6 +198,346 @@ connection master; --replace_result $old_binlog_stmt_cache_size ORIGINAL_VALUE --eval SET GLOBAL binlog_stmt_cache_size= $old_binlog_stmt_cache_size -DROP TABLE t1; +DROP TABLE t1,t2; + +--echo "*********** TABLE MAP Event write failure **************" + +--let $debug_save= `SELECT @@GLOBAL.debug_dbug` +CREATE TABLE tm (f INT) ENGINE=MYISAM; +CREATE TABLE ti (f INT) ENGINE=INNODB; +INSERT INTO tm VALUES (10); +INSERT INTO ti VALUES (20); +--sync_slave_with_master + +--echo "#######################################################################" +--echo "# Test Case4: Table_map event write failure for trans engine UPDATE #" +--echo "#######################################################################" +--echo # Transaction should be rolled back without writing incident event +--connection master +--let $old_gtid_binlog_pos= query_get_value(SHOW VARIABLES LIKE 'gtid_binlog_pos', Value, 1) +SET debug_dbug="+d,table_map_write_error"; +--error ER_TRANS_CACHE_FULL +UPDATE ti, tm set ti.f=30; + +--let $new_gtid_binlog_pos= query_get_value(SHOW VARIABLES LIKE 'gtid_binlog_pos', Value, 1) +--echo # Validating update was not binlogged.. +if(`SELECT strcmp("$old_gtid_binlog_pos","$new_gtid_binlog_pos") != 0`) +{ + --die Binlog GTID position should have been unchanged after failed update +} +--echo # ..success + +--echo # Validating update was rolled back from storage engines.. +if(`SELECT COUNT(*) FROM ti WHERE f=130`) +{ + --die Update for InnoDB table should not have saved +} +--echo # ..success + +--source include/save_master_gtid.inc + +--connection slave +--source include/sync_with_master_gtid.inc + +--echo "#######################################################################" +--echo "# Test Case5: Table_map event write failure for mixed engine UPDATE #" +--echo "#######################################################################" +--connection master +--let $old_gtid_binlog_pos= query_get_value(SHOW VARIABLES LIKE 'gtid_binlog_pos', Value, 1) +--echo # In case of mixed engines if non trans table is updated write INCIDENT event +--error ER_TRANS_CACHE_FULL +UPDATE ti,tm SET tm.f=88, ti.f=120; + +--let $new_gtid_binlog_pos= query_get_value(SHOW VARIABLES LIKE 'gtid_binlog_pos', Value, 1) +--echo # Validating update was not binlogged.. +if(`SELECT strcmp("$old_gtid_binlog_pos","$new_gtid_binlog_pos") != 0`) +{ + --die Binlog GTID position should have been unchanged after failed update +} +--echo # ..success + +--echo # Validating that only the non-transactional update saved on master.. +if(`SELECT COUNT(*)!=1 FROM tm WHERE f=88`) +{ + --die Update for MyISAM table should have saved +} +if(`SELECT COUNT(*) FROM ti WHERE f=120`) +{ + --die Update for InnoDB table should not have saved +} +--echo # ..success + + +--connection slave +# Incident event +# 1590=ER_SLAVE_INCIDENT +--let $slave_sql_errno= 1590 +--source include/wait_for_slave_sql_error_and_skip.inc + +--echo # Validating that neither of the updates replicated to slave.. +if(`SELECT COUNT(*) FROM tm WHERE f=88`) +{ + --die Update for MyISAM table should not have replicated to slave +} +if(`SELECT COUNT(*) FROM ti WHERE f=120`) +{ + --die Update for InnoDB table should not have replicated to slave +} +--echo # ..success + +--echo "#######################################################################" +--echo "# Test Case6: Committing a transaction consisting of two updates: +--echo "# S1) Update transactional table +--echo "# S2) Update transactional table +--echo "# with a table_map event write failure on the second event should +--echo "# roll-back only the second update without incident +--echo "#######################################################################" +--connection master +--let $old_gtid_binlog_pos= query_get_value(SHOW VARIABLES LIKE 'gtid_binlog_pos', Value, 1) + +SET debug_dbug=""; +BEGIN; +# successful update +UPDATE ti, tm set ti.f=40; +SET debug_dbug="+d,table_map_write_error"; +--error ER_TRANS_CACHE_FULL +UPDATE ti, tm set ti.f=50; +COMMIT; + +--let $new_gtid_binlog_pos= query_get_value(SHOW VARIABLES LIKE 'gtid_binlog_pos', Value, 1) +--echo # Validating binlog GTID position progressed from first update.. +if(`SELECT strcmp("$old_gtid_binlog_pos","$new_gtid_binlog_pos") = 0`) +{ + --die Binlog GTID position should have updated +} +--echo # ..success + +--echo # Validating the first update saved.. +if(`SELECT COUNT(*)!=1 FROM ti WHERE f=40`) +{ + --die The first update should have saved because it was transactional +} +--echo # ..and that the second update did not save.. +if(`SELECT COUNT(*) FROM ti WHERE f=50`) +{ + --die The second update should have rolled back because it failed +} +--echo # ..success + +--echo # Validating that only the first update replicated to slave without incident +--connection master +--source include/save_master_gtid.inc +--connection slave +--source include/sync_with_master_gtid.inc +--let $diff_tables= master:test.ti,slave:test.ti +--source include/diff_tables.inc + + +--echo "#######################################################################" +--echo "# Test Case7: Rolling back a transaction consisting of two updates: +--echo "# S1) Update transactional table +--echo "# S2) Update transactional table +--echo "# with a table_map event write failure on the second event should +--echo "# roll-back both updates without incident +--echo "#######################################################################" +--connection master +--let $old_gtid_binlog_pos= query_get_value(SHOW VARIABLES LIKE 'gtid_binlog_pos', Value, 1) + +SET debug_dbug=""; +BEGIN; +# successful update +UPDATE ti, tm set ti.f=60; +SET debug_dbug="+d,table_map_write_error"; +--error ER_TRANS_CACHE_FULL +UPDATE ti, tm set ti.f=70; +ROLLBACK; + +--let $new_gtid_binlog_pos= query_get_value(SHOW VARIABLES LIKE 'gtid_binlog_pos', Value, 1) +--echo # Validating update was not binlogged.. +if(`SELECT strcmp("$old_gtid_binlog_pos","$new_gtid_binlog_pos") != 0`) +{ + --die Binlog GTID position should have been unchanged after failed update +} +--echo # ..success + +--echo # Validating that neither update saved on master.. +if(`SELECT COUNT(*) FROM ti WHERE f=60`) +{ + --die The first update should not have saved +} +if(`SELECT COUNT(*) FROM ti WHERE f=70`) +{ + --die The second update should not have saved +} +--echo # ..success + +--echo # Validating the transaction did not replicate to the slave +--connection master +--source include/save_master_gtid.inc + +--connection slave +--source include/sync_with_master_gtid.inc +--let $diff_tables= master:test.ti,slave:test.ti +--source include/diff_tables.inc + + +--echo "#######################################################################" +--echo "# Test Case8: Committing a transaction consisting of two updates: +--echo "# S1) Update transactional table +--echo "# S2) Update mixed trans/non-trans tables +--echo "# with a table_map event write failure on the second event should +--echo "# roll-back only the second update with incident +--echo "#######################################################################" +--connection master +--let $old_gtid_binlog_pos= query_get_value(SHOW VARIABLES LIKE 'gtid_binlog_pos', Value, 1) + +BEGIN; +# successful update +SET debug_dbug=""; +UPDATE ti, tm set ti.f=80; +SET debug_dbug="+d,table_map_write_error"; +--error ER_TRANS_CACHE_FULL +UPDATE ti, tm set ti.f=90,tm.f=99; +COMMIT; + +--let $new_gtid_binlog_pos= query_get_value(SHOW VARIABLES LIKE 'gtid_binlog_pos', Value, 1) +--echo # Validating binlog GTID position progressed from first update.. +if(`SELECT strcmp("$old_gtid_binlog_pos","$new_gtid_binlog_pos") = 0`) +{ + --die Binlog GTID position should have updated +} +--echo # ..success + +--echo # Validating the first update saved.. +if(`SELECT COUNT(*)!=1 FROM ti WHERE f=80`) +{ + --die The first update should have saved because it was transactional +} +--echo # ..and the transactional part of the second update did not save.. +if(`SELECT COUNT(*) FROM ti WHERE f=90`) +{ + --die The transactional part of the second update should have rolled back because it failed +} +--echo # ..whereas the non-trans part of the second update did save.. +if(`SELECT COUNT(*)!=1 FROM tm WHERE f=99`) +{ + --die The non-trans part from the second update should have saved +} +--echo # ..success + +--echo # Validating that the incident propagated to the slave +--connection slave +# Incident event +# 1590=ER_SLAVE_INCIDENT +--let $slave_sql_errno= 1590 +--source include/wait_for_slave_sql_error_and_skip.inc + +--echo # Validating that the first update replicated to the slave.. +if(`SELECT COUNT(*)!=1 FROM ti WHERE f=80`) +{ + --die The first update should have replicated because it was transactional +} +--echo # ..and neither part of the second update replicated.. +if(`SELECT COUNT(*) FROM ti WHERE f=90`) +{ + --die The trans part from the second update should not have replicated because it was rolled back +} +if(`SELECT COUNT(*) FROM tm WHERE f=99`) +{ + --die The non-trans part from the second update should not have replicated because it was not binlogged +} +--echo # ..success + + +--echo "#######################################################################" +--echo "# Test Case9: Rolling back a transaction consisting of two updates: +--echo "# S1) Update transactional table +--echo "# S2) Update mixed trans/non-trans tables +--echo "# with a table_map event write failure on the second event should +--echo "# roll-back both transactional updates, preserve the non-transactional +--echo "# update on the master (only), and write an incident event +--echo "#######################################################################" +--connection master +--let $old_gtid_binlog_pos= query_get_value(SHOW VARIABLES LIKE 'gtid_binlog_pos', Value, 1) + +SET debug_dbug=""; +BEGIN; +# successful update +UPDATE ti, tm set ti.f=100; +SET debug_dbug="+d,table_map_write_error"; +--error ER_TRANS_CACHE_FULL +UPDATE ti, tm set ti.f=110,tm.f=111; +ROLLBACK; + +--let $new_gtid_binlog_pos= query_get_value(SHOW VARIABLES LIKE 'gtid_binlog_pos', Value, 1) +--echo # Validating update was not binlogged.. +if(`SELECT strcmp("$old_gtid_binlog_pos","$new_gtid_binlog_pos") != 0`) +{ + --die Binlog GTID position should have been unchanged after failed update +} +--echo # ..success + +--echo # Validating trans updates rollback, but the non-trans update stays.. +if(`SELECT COUNT(*) FROM ti WHERE f=100`) +{ + --die The first update should not have saved +} +if(`SELECT COUNT(*) FROM ti WHERE f=110`) +{ + --die The transactional part of the second update should not have saved +} +if(`SELECT COUNT(*)!=1 FROM tm WHERE f=111`) +{ + --die The non-trans part of the second update should have saved +} +--echo # ..success + +--echo # Validating that the incident propagated to the slave +--connection slave +# Incident event +# 1590=ER_SLAVE_INCIDENT +--let $slave_sql_errno= 1590 +--source include/wait_for_slave_sql_error_and_skip.inc + +--echo # Validating that none of the updates replicated to the slave +--let $diff_tables= master:test.ti,slave:test.ti +--source include/diff_tables.inc +if(`SELECT COUNT(*) FROM tm WHERE f=111`) +{ + --die The non-trans part from the second update should not have replicated because it was not binlogged +} +--echo # ..success + + +--echo "#######################################################################" +--echo "# Test Case10: If an incident event fails to write, a specific error +--echo "# should be logged +--echo "# +--echo "# Note: This test case is the same as test case 5, with the caveat of +--echo "# the incident event failing to write. +--echo "#######################################################################" + +--connection master +SET debug_dbug="d,table_map_write_error,incident_event_write_error"; +--error ER_TRANS_CACHE_FULL +UPDATE ti, tm set ti.f=120, tm.f=122; + +--echo # Validate error message indicating incident event failed to write +let $log_error_= `SELECT @@GLOBAL.log_error`; +if(!$log_error_) +{ + # MySQL Server on windows is started with --console and thus + # does not know the location of its .err log, use default location + let $log_error_ = $MYSQLTEST_VARDIR/log/mysqld.1.err; +} +--let SEARCH_PATTERN= Incident event write to the binary log file failed +--let SEARCH_FILE= $log_error_ +--source include/search_pattern_in_file.inc + + +--connection master +--echo "******** Clean Up **********" +--eval SET GLOBAL debug_dbug = '$debug_save' +DROP TABLE tm,ti; --source include/rpl_end.inc diff --git a/sql/handler.cc b/sql/handler.cc index 2048ce137da..66a932cc70e 100644 --- a/sql/handler.cc +++ b/sql/handler.cc @@ -6270,7 +6270,7 @@ static int write_locked_table_maps(THD *thd) continue; TABLE **const end_ptr= lock->table + lock->table_count; - for (TABLE **table_ptr= lock->table ; + for (TABLE **table_ptr= lock->table ; table_ptr != end_ptr ; ++table_ptr) { @@ -6294,8 +6294,10 @@ static int write_locked_table_maps(THD *thd) */ bool const has_trans= thd->lex->sql_command == SQLCOM_CREATE_TABLE || table->file->has_transactions(); - int const error= thd->binlog_write_table_map(table, has_trans, - &with_annotate); + + int const error= + thd->binlog_write_table_map(table, has_trans, &with_annotate); + /* If an error occurs, it is the responsibility of the caller to roll back the transaction. diff --git a/sql/log.cc b/sql/log.cc index f6f3879e66d..7ca9b38dc6e 100644 --- a/sql/log.cc +++ b/sql/log.cc @@ -2081,7 +2081,8 @@ static int binlog_rollback(handlerton *hton, THD *thd, bool all) error= binlog_commit_flush_stmt_cache(thd, all, cache_mngr); } - if (cache_mngr->trx_cache.empty()) + + if (!cache_mngr->trx_cache.has_incident() && cache_mngr->trx_cache.empty()) { /* we're here because cache_log was flushed in MYSQL_BIN_LOG::log_xid() @@ -5713,17 +5714,23 @@ binlog_start_consistent_snapshot(handlerton *hton, THD *thd) } /** - This function writes a table map to the binary log. + This function writes a table map to the binary log. Note that in order to keep the signature uniform with related methods, we use a redundant parameter to indicate whether a transactional table was changed or not. If with_annotate != NULL and *with_annotate = TRUE write also Annotate_rows before the table map. - + + If an error occurs while writing events and rollback is not possible, e.g. + due to the statement modifying a non-transactional table, an incident event + is logged. + @param table a pointer to the table. @param is_transactional @c true indicates a transactional table, otherwise @c false a non-transactional. + @param with_annotate @c true to write an annotate event before writing + the table_map event, @c false otherwise. @return nonzero if an error pops up when writing the table map event. */ @@ -5739,7 +5746,7 @@ int THD::binlog_write_table_map(TABLE *table, bool is_transactional, /* Ensure that all events in a GTID group are in the same cache */ if (variables.option_bits & OPTION_GTID_BEGIN) is_transactional= 1; - + /* Pre-conditions */ DBUG_ASSERT(is_current_stmt_binlog_format_row()); DBUG_ASSERT(WSREP_EMULATE_BINLOG(this) || mysql_bin_log.is_open()); @@ -5764,17 +5771,35 @@ int THD::binlog_write_table_map(TABLE *table, bool is_transactional, /* Annotate event should be written not more than once */ *with_annotate= 0; if (unlikely((error= writer.write(&anno)))) - { - if (my_errno == EFBIG) - cache_data->set_incident(); - DBUG_RETURN(error); - } + goto write_err; } - if (unlikely((error= writer.write(&the_event)))) - DBUG_RETURN(error); + DBUG_EXECUTE_IF("table_map_write_error", + { + if (is_transactional) + { + my_errno= EFBIG; + error= 1; + goto write_err; + } + }); + if ((error= writer.write(&the_event))) + goto write_err; - binlog_table_maps++; - DBUG_RETURN(0); + binlog_table_maps++; + DBUG_RETURN(0); + +write_err: + mysql_bin_log.set_write_error(this, is_transactional); + /* + For non-transactional engine or multi statement transaction with mixed + engines, data is written to table but writing to binary log failed. In + these scenarios rollback is not possible. Hence report an incident. + */ + if (mysql_bin_log.check_write_error(this) && cache_data && + lex->stmt_accessed_table(LEX::STMT_WRITES_NON_TRANS_TABLE) && + table->current_lock == F_WRLCK) + cache_data->set_incident(); + DBUG_RETURN(error); } /** @@ -7202,7 +7227,9 @@ bool MYSQL_BIN_LOG::write_incident(THD *thd) if (likely(is_open())) { prev_binlog_id= current_binlog_id; - if (likely(!(error= write_incident_already_locked(thd))) && + if (likely( + !(error= DBUG_EVALUATE_IF("incident_event_write_error", 1, + write_incident_already_locked(thd)))) && likely(!(error= flush_and_sync(0)))) { update_binlog_end_pos(); @@ -7248,6 +7275,22 @@ bool MYSQL_BIN_LOG::write_incident(THD *thd) mysql_mutex_unlock(&LOCK_log); } + /* + Upon writing incident event, check for thd->error() and print the + relevant error message in the error log. + */ + if (thd->is_error()) + { + sql_print_error("Write to binary log failed: " + "%s. An incident event is written to binary log " + "and slave will be stopped.\n", + thd->get_stmt_da()->message()); + } + if (error) + { + sql_print_error("Incident event write to the binary log file failed."); + } + DBUG_RETURN(error); } |