- commits - lists.mariadb.org

[Commits] bd4d159f18a: MDEV-19925: Column ... cannot be converted from type 'varchar(20)' to type 'varchar(20)'
by sujatha 18 Jul '19

18 Jul '19

revision-id: bd4d159f18a27751a29569c92c731395884e4732 (mariadb-10.2.25-76-gbd4d159f18a) parent(s): 4e02e502f6f9622a84942fd3329241e790acab66 author: Sujatha committer: Sujatha timestamp: 2019-07-18 13:02:45 +0530 message: MDEV-19925: Column ... cannot be converted from type 'varchar(20)' to type 'varchar(20)' Cherry picking: Bug#25135304: RBR: WRONG FIELD LENGTH IN ERROR MESSAGE commit 47bd3f7cf3c8518f62b1580ec65af2ba7ac13b95 Description: ============ In row based replication, when replicating from a table with a field with character set set to UTF8mb3 to the same table with the same field set to character set UTF8mb4 I get a confusing error message: For VARCHAR: VARCHAR(1) 'utf8mb3' to VARCHAR(1) 'utf8mb4' "Column 0 of table 'test.t1' cannot be converted from type 'varchar(3)' to type 'varchar(1)'" Similar issue with CHAR type as well. Issue with respect to BLOB types: For BLOB: LONGBLOB to TINYBLOB - Error message displays incorrect blob type. "Column 0 of table 'test.t1' cannot be converted from type 'tinyblob' to type 'tinyblob'" Analysis: ========= In Row based replication charset information is not sent as part of metadata from master to slave. For VARCHAR field its character length is converted into equivalent octets/bytes and stored internally. At the time of displaying the data to user it is converted back to original character length. For example: VARCHAR(2)- utf8mb3 is stored as:2*3 = VARCHAR(6) At the time of displaying it to user VARCHAR(6)- charset utf8mb3:6/3= VARCHAR(2). At present the internally converted octect length is sent from master to slave with out providing the charset information. On slave side if the type conversion fails 'show_sql_type' function is used to get the type specific information from metadata. Since there is no charset information is available the filed type is displayed as VARCHAR(6). This results in confused error message. For CHAR fields CHAR(1)- utf8mb3 - CHAR(3) CHAR(1)- utf8mb4 - CHAR(4) 'show_sql_type' function which retrieves type information from metadata uses (bytes/local charset length) to get actual character length. If slave's chaset is 'utf8mb4' then CHAR(3/4)-->CHAR(0) CHAR(4/4)-->CHAR(1). This results in confused error message. Analysis for BLOB type issue: BLOB's length is represented in two forms. 1. Actual length i.e (length < 256) type= MYSQL_TYPE_TINY_BLOB; (length < 65536) type= MYSQL_TYPE_BLOB; ... 2. packlength - The number of bytes used to represent the length of the blob 1- tinyblob 2- blob ... In row based replication only the packlength is written in the binary log. On the slave side this packlength is interpreted as actual length of the blob. Hence the length is always < 256 and the type is displayed as tiny blob. Fix: === For CHAR and VARCHAR fields display their length in bytes for both source and target fields. For target field display the charset information if it is relevant. For blob type changed the code to use the packlength and display appropriate blob type in error message. --- .../suite/rpl/r/rpl_extra_col_master_innodb.result | 4 +- .../suite/rpl/r/rpl_extra_col_master_myisam.result | 4 +- .../suite/rpl/r/rpl_extra_col_slave_innodb.result | 12 +- .../suite/rpl/r/rpl_extra_col_slave_myisam.result | 12 +- .../suite/rpl/r/rpl_row_basic_2myisam.result | 4 +- .../suite/rpl/r/rpl_row_basic_3innodb.result | 4 +- mysql-test/suite/rpl/r/rpl_row_colSize.result | 10 +- .../suite/rpl/r/rpl_type_conv_utf8_utf8mb4.result | 62 +++++++++ .../suite/rpl/t/rpl_type_conv_utf8_utf8mb4.test | 144 +++++++++++++++++++++ sql/rpl_utility.cc | 45 +++++-- .../rpl/r/rpl_extra_col_master_tokudb.result | 4 +- .../rpl/r/rpl_extra_col_slave_tokudb.result | 12 +- .../mysql-test/rpl/r/rpl_row_basic_3tokudb.result | 4 +- 13 files changed, 274 insertions(+), 47 deletions(-) diff --git a/mysql-test/suite/rpl/r/rpl_extra_col_master_innodb.result b/mysql-test/suite/rpl/r/rpl_extra_col_master_innodb.result index 3aa7c07a845..497507dd89f 100644 --- a/mysql-test/suite/rpl/r/rpl_extra_col_master_innodb.result +++ b/mysql-test/suite/rpl/r/rpl_extra_col_master_innodb.result @@ -468,7 +468,7 @@ INSERT INTO t10 () VALUES(1,@b1,DEFAULT,'Kyle',DEFAULT), connection slave; include/wait_for_slave_sql_error_and_skip.inc [errno=1677] -Last_SQL_Error = 'Column 2 of table 'test.t10' cannot be converted from type 'double' to type 'char(5)'' +Last_SQL_Error = 'Column 2 of table 'test.t10' cannot be converted from type 'double' to type 'char(5(bytes) latin1)'' *** Drop t10 *** connection master; @@ -510,7 +510,7 @@ INSERT INTO t11 () VALUES(1,@b1,'Testing is fun','Kyle',DEFAULT), connection slave; include/wait_for_slave_sql_error_and_skip.inc [errno=1677] -Last_SQL_Error = 'Column 2 of table 'test.t11' cannot be converted from type 'tinyblob' to type 'varchar(254)'' +Last_SQL_Error = 'Column 2 of table 'test.t11' cannot be converted from type 'blob' to type 'varchar(254(bytes) latin1)'' *** Drop t11 *** connection master; diff --git a/mysql-test/suite/rpl/r/rpl_extra_col_master_myisam.result b/mysql-test/suite/rpl/r/rpl_extra_col_master_myisam.result index 0918364b28e..3907a549e05 100644 --- a/mysql-test/suite/rpl/r/rpl_extra_col_master_myisam.result +++ b/mysql-test/suite/rpl/r/rpl_extra_col_master_myisam.result @@ -468,7 +468,7 @@ INSERT INTO t10 () VALUES(1,@b1,DEFAULT,'Kyle',DEFAULT), connection slave; include/wait_for_slave_sql_error_and_skip.inc [errno=1677] -Last_SQL_Error = 'Column 2 of table 'test.t10' cannot be converted from type 'double' to type 'char(5)'' +Last_SQL_Error = 'Column 2 of table 'test.t10' cannot be converted from type 'double' to type 'char(5(bytes) latin1)'' *** Drop t10 *** connection master; @@ -510,7 +510,7 @@ INSERT INTO t11 () VALUES(1,@b1,'Testing is fun','Kyle',DEFAULT), connection slave; include/wait_for_slave_sql_error_and_skip.inc [errno=1677] -Last_SQL_Error = 'Column 2 of table 'test.t11' cannot be converted from type 'tinyblob' to type 'varchar(254)'' +Last_SQL_Error = 'Column 2 of table 'test.t11' cannot be converted from type 'blob' to type 'varchar(254(bytes) latin1)'' *** Drop t11 *** connection master; diff --git a/mysql-test/suite/rpl/r/rpl_extra_col_slave_innodb.result b/mysql-test/suite/rpl/r/rpl_extra_col_slave_innodb.result index 456c1c24f8f..1a128f9692c 100644 --- a/mysql-test/suite/rpl/r/rpl_extra_col_slave_innodb.result +++ b/mysql-test/suite/rpl/r/rpl_extra_col_slave_innodb.result @@ -64,7 +64,7 @@ a b c connection slave; START SLAVE; include/wait_for_slave_sql_error.inc [errno=1677] -Last_SQL_Error = 'Column 2 of table 'test.t2' cannot be converted from type 'char(10)' to type 'char(5)'' +Last_SQL_Error = 'Column 2 of table 'test.t2' cannot be converted from type 'char(10(bytes))' to type 'char(5(bytes) latin1)'' STOP SLAVE; RESET SLAVE; SELECT * FROM t2 ORDER BY a; @@ -102,7 +102,7 @@ INSERT INTO t3 () VALUES(@b1,2,'Kyle, TEX'),(@b1,1,'JOE AUSTIN'),(@b1,4,'QA TEST ******************************************** connection slave; include/wait_for_slave_sql_error_and_skip.inc [errno=1677] -Last_SQL_Error = 'Column 0 of table 'test.t3' cannot be converted from type 'tinyblob' to type 'int(11)'' +Last_SQL_Error = 'Column 0 of table 'test.t3' cannot be converted from type 'blob' to type 'int(11)'' *** Drop t3 *** connection master; DROP TABLE t3; @@ -160,7 +160,7 @@ INSERT INTO t5 () VALUES(1,'Kyle',200.23,1,'b1b1',23.00098), ******************************************** connection slave; include/wait_for_slave_sql_error_and_skip.inc [errno=1677] -Last_SQL_Error = 'Column 1 of table 'test.t5' cannot be converted from type 'varchar(6)' to type 'char(5)'' +Last_SQL_Error = 'Column 1 of table 'test.t5' cannot be converted from type 'varchar(6(bytes))' to type 'char(5(bytes) latin1)'' *** Drop t5 *** connection master; DROP TABLE t5; @@ -188,7 +188,7 @@ INSERT INTO t6 () VALUES(1,'Kyle',200.23,1), ******************************************** connection slave; include/wait_for_slave_sql_error.inc [errno=1677] -Last_SQL_Error = 'Column 1 of table 'test.t6' cannot be converted from type 'varchar(6)' to type 'char(5)'' +Last_SQL_Error = 'Column 1 of table 'test.t6' cannot be converted from type 'varchar(6(bytes))' to type 'char(5(bytes) latin1)'' *** Drop t6 *** include/rpl_reset.inc connection master; @@ -310,7 +310,7 @@ INSERT INTO t10 () VALUES(1,@b1,'Kyle'),(2,@b1,'JOE'),(3,@b1,'QA'); ******************************************** connection slave; include/wait_for_slave_sql_error_and_skip.inc [errno=1677] -Last_SQL_Error = 'Column 2 of table 'test.t10' cannot be converted from type 'char(5)' to type 'double'' +Last_SQL_Error = 'Column 2 of table 'test.t10' cannot be converted from type 'char(5(bytes))' to type 'double'' *** Drop t10 *** connection master; DROP TABLE t10; @@ -338,7 +338,7 @@ INSERT INTO t11 () VALUES(1,@b1,'Kyle'),(2,@b1,'JOE'),(3,@b1,'QA'); ******************************************** connection slave; include/wait_for_slave_sql_error_and_skip.inc [errno=1677] -Last_SQL_Error = 'Column 2 of table 'test.t11' cannot be converted from type 'varchar(254)' to type 'int(11)'' +Last_SQL_Error = 'Column 2 of table 'test.t11' cannot be converted from type 'varchar(254(bytes))' to type 'int(11)'' *** Drop t11 *** connection master; DROP TABLE t11; diff --git a/mysql-test/suite/rpl/r/rpl_extra_col_slave_myisam.result b/mysql-test/suite/rpl/r/rpl_extra_col_slave_myisam.result index 7178a2a78b8..2a14092fafc 100644 --- a/mysql-test/suite/rpl/r/rpl_extra_col_slave_myisam.result +++ b/mysql-test/suite/rpl/r/rpl_extra_col_slave_myisam.result @@ -64,7 +64,7 @@ a b c connection slave; START SLAVE; include/wait_for_slave_sql_error.inc [errno=1677] -Last_SQL_Error = 'Column 2 of table 'test.t2' cannot be converted from type 'char(10)' to type 'char(5)'' +Last_SQL_Error = 'Column 2 of table 'test.t2' cannot be converted from type 'char(10(bytes))' to type 'char(5(bytes) latin1)'' STOP SLAVE; RESET SLAVE; SELECT * FROM t2 ORDER BY a; @@ -102,7 +102,7 @@ INSERT INTO t3 () VALUES(@b1,2,'Kyle, TEX'),(@b1,1,'JOE AUSTIN'),(@b1,4,'QA TEST ******************************************** connection slave; include/wait_for_slave_sql_error_and_skip.inc [errno=1677] -Last_SQL_Error = 'Column 0 of table 'test.t3' cannot be converted from type 'tinyblob' to type 'int(11)'' +Last_SQL_Error = 'Column 0 of table 'test.t3' cannot be converted from type 'blob' to type 'int(11)'' *** Drop t3 *** connection master; DROP TABLE t3; @@ -160,7 +160,7 @@ INSERT INTO t5 () VALUES(1,'Kyle',200.23,1,'b1b1',23.00098), ******************************************** connection slave; include/wait_for_slave_sql_error_and_skip.inc [errno=1677] -Last_SQL_Error = 'Column 1 of table 'test.t5' cannot be converted from type 'varchar(6)' to type 'char(5)'' +Last_SQL_Error = 'Column 1 of table 'test.t5' cannot be converted from type 'varchar(6(bytes))' to type 'char(5(bytes) latin1)'' *** Drop t5 *** connection master; DROP TABLE t5; @@ -188,7 +188,7 @@ INSERT INTO t6 () VALUES(1,'Kyle',200.23,1), ******************************************** connection slave; include/wait_for_slave_sql_error.inc [errno=1677] -Last_SQL_Error = 'Column 1 of table 'test.t6' cannot be converted from type 'varchar(6)' to type 'char(5)'' +Last_SQL_Error = 'Column 1 of table 'test.t6' cannot be converted from type 'varchar(6(bytes))' to type 'char(5(bytes) latin1)'' *** Drop t6 *** include/rpl_reset.inc connection master; @@ -310,7 +310,7 @@ INSERT INTO t10 () VALUES(1,@b1,'Kyle'),(2,@b1,'JOE'),(3,@b1,'QA'); ******************************************** connection slave; include/wait_for_slave_sql_error_and_skip.inc [errno=1677] -Last_SQL_Error = 'Column 2 of table 'test.t10' cannot be converted from type 'char(5)' to type 'double'' +Last_SQL_Error = 'Column 2 of table 'test.t10' cannot be converted from type 'char(5(bytes))' to type 'double'' *** Drop t10 *** connection master; DROP TABLE t10; @@ -338,7 +338,7 @@ INSERT INTO t11 () VALUES(1,@b1,'Kyle'),(2,@b1,'JOE'),(3,@b1,'QA'); ******************************************** connection slave; include/wait_for_slave_sql_error_and_skip.inc [errno=1677] -Last_SQL_Error = 'Column 2 of table 'test.t11' cannot be converted from type 'varchar(254)' to type 'int(11)'' +Last_SQL_Error = 'Column 2 of table 'test.t11' cannot be converted from type 'varchar(254(bytes))' to type 'int(11)'' *** Drop t11 *** connection master; DROP TABLE t11; diff --git a/mysql-test/suite/rpl/r/rpl_row_basic_2myisam.result b/mysql-test/suite/rpl/r/rpl_row_basic_2myisam.result index 1d4b31a4a87..6c669a994a2 100644 --- a/mysql-test/suite/rpl/r/rpl_row_basic_2myisam.result +++ b/mysql-test/suite/rpl/r/rpl_row_basic_2myisam.result @@ -560,7 +560,7 @@ INSERT INTO t5 VALUES (1, "", 1); INSERT INTO t5 VALUES (2, repeat(_utf8'a', 255), 2); connection slave; include/wait_for_slave_sql_error.inc [errno=1677] -Last_SQL_Error = 'Column 1 of table 'test.t5' cannot be converted from type 'char(255)' to type 'char(16)'' +Last_SQL_Error = 'Column 1 of table 'test.t5' cannot be converted from type 'char(765(bytes))' to type 'char(48(bytes) utf8)'' include/rpl_reset.inc [expecting slave to stop] connection master; @@ -568,7 +568,7 @@ INSERT INTO t6 VALUES (1, "", 1); INSERT INTO t6 VALUES (2, repeat(_utf8'a', 255), 2); connection slave; include/wait_for_slave_sql_error.inc [errno=1677] -Last_SQL_Error = 'Column 1 of table 'test.t6' cannot be converted from type 'char(255)' to type 'char(128)'' +Last_SQL_Error = 'Column 1 of table 'test.t6' cannot be converted from type 'char(765(bytes))' to type 'char(384(bytes) utf8)'' include/rpl_reset.inc [expecting slave to replicate correctly] connection master; diff --git a/mysql-test/suite/rpl/r/rpl_row_basic_3innodb.result b/mysql-test/suite/rpl/r/rpl_row_basic_3innodb.result index 1e3ddd4f289..fce02e63962 100644 --- a/mysql-test/suite/rpl/r/rpl_row_basic_3innodb.result +++ b/mysql-test/suite/rpl/r/rpl_row_basic_3innodb.result @@ -565,7 +565,7 @@ INSERT INTO t5 VALUES (1, "", 1); INSERT INTO t5 VALUES (2, repeat(_utf8'a', 255), 2); connection slave; include/wait_for_slave_sql_error.inc [errno=1677] -Last_SQL_Error = 'Column 1 of table 'test.t5' cannot be converted from type 'char(255)' to type 'char(16)'' +Last_SQL_Error = 'Column 1 of table 'test.t5' cannot be converted from type 'char(765(bytes))' to type 'char(48(bytes) utf8)'' include/rpl_reset.inc [expecting slave to stop] connection master; @@ -573,7 +573,7 @@ INSERT INTO t6 VALUES (1, "", 1); INSERT INTO t6 VALUES (2, repeat(_utf8'a', 255), 2); connection slave; include/wait_for_slave_sql_error.inc [errno=1677] -Last_SQL_Error = 'Column 1 of table 'test.t6' cannot be converted from type 'char(255)' to type 'char(128)'' +Last_SQL_Error = 'Column 1 of table 'test.t6' cannot be converted from type 'char(765(bytes))' to type 'char(384(bytes) utf8)'' include/rpl_reset.inc [expecting slave to replicate correctly] connection master; diff --git a/mysql-test/suite/rpl/r/rpl_row_colSize.result b/mysql-test/suite/rpl/r/rpl_row_colSize.result index dd324ef7807..578c321964a 100644 --- a/mysql-test/suite/rpl/r/rpl_row_colSize.result +++ b/mysql-test/suite/rpl/r/rpl_row_colSize.result @@ -185,7 +185,7 @@ INSERT INTO t1 VALUES ('This is a test.'); connection slave; START SLAVE; include/wait_for_slave_sql_error.inc [errno=1677] -Last_SQL_Error = 'Column 0 of table 'test.t1' cannot be converted from type 'char(20)' to type 'char(10)'' +Last_SQL_Error = 'Column 0 of table 'test.t1' cannot be converted from type 'char(20(bytes))' to type 'char(10(bytes) latin1)'' SELECT COUNT(*) FROM t1; COUNT(*) 0 @@ -264,7 +264,7 @@ INSERT INTO t1 VALUES ('This is a test.'); connection slave; START SLAVE; include/wait_for_slave_sql_error.inc [errno=1677] -Last_SQL_Error = 'Column 0 of table 'test.t1' cannot be converted from type 'varchar(2000)' to type 'varchar(100)'' +Last_SQL_Error = 'Column 0 of table 'test.t1' cannot be converted from type 'varchar(2000(bytes))' to type 'varchar(100(bytes) latin1)'' SELECT COUNT(*) FROM t1; COUNT(*) 0 @@ -287,7 +287,7 @@ INSERT INTO t1 VALUES ('This is a test.'); connection slave; START SLAVE; include/wait_for_slave_sql_error.inc [errno=1677] -Last_SQL_Error = 'Column 0 of table 'test.t1' cannot be converted from type 'varchar(200)' to type 'varchar(10)'' +Last_SQL_Error = 'Column 0 of table 'test.t1' cannot be converted from type 'varchar(200(bytes))' to type 'varchar(10(bytes) latin1)'' SELECT COUNT(*) FROM t1; COUNT(*) 0 @@ -310,7 +310,7 @@ INSERT INTO t1 VALUES ('This is a test.'); connection slave; START SLAVE; include/wait_for_slave_sql_error.inc [errno=1677] -Last_SQL_Error = 'Column 0 of table 'test.t1' cannot be converted from type 'varchar(2000)' to type 'varchar(1000)'' +Last_SQL_Error = 'Column 0 of table 'test.t1' cannot be converted from type 'varchar(2000(bytes))' to type 'varchar(1000(bytes) latin1)'' SELECT COUNT(*) FROM t1; COUNT(*) 0 @@ -334,7 +334,7 @@ INSERT INTO t1 VALUES ('This is a test.'); connection slave; START SLAVE; include/wait_for_slave_sql_error.inc [errno=1677] -Last_SQL_Error = 'Column 0 of table 'test.t1' cannot be converted from type 'tinyblob' to type 'tinyblob'' +Last_SQL_Error = 'Column 0 of table 'test.t1' cannot be converted from type 'longblob' to type 'tinyblob'' SELECT COUNT(*) FROM t1; COUNT(*) 0 diff --git a/mysql-test/suite/rpl/r/rpl_type_conv_utf8_utf8mb4.result b/mysql-test/suite/rpl/r/rpl_type_conv_utf8_utf8mb4.result new file mode 100644 index 00000000000..870a90d408b --- /dev/null +++ b/mysql-test/suite/rpl/r/rpl_type_conv_utf8_utf8mb4.result @@ -0,0 +1,62 @@ +include/master-slave.inc +[connection master] +#################################################################### +# Test Case1: Improved error message with charset information +#################################################################### +connection master; +SET SQL_LOG_BIN=0; +CREATE TABLE t1 (c1 VARCHAR(1) CHARACTER SET 'utf8mb3'); +SET SQL_LOG_BIN=1; +connection slave; +CREATE TABLE t1 (c1 VARCHAR(1) CHARACTER SET 'utf8mb4'); +connection master; +INSERT INTO t1 VALUES ('a'); +connection slave; +include/wait_for_slave_sql_error.inc [errno=1677] +FOUND 1 /\'varchar$3\(bytes$\)\' to type \'varchar$4\(bytes$ utf8mb4\)\'/ in mysqld.2.err +connection master; +DROP TABLE t1; +connection slave; +DROP TABLE t1; +include/rpl_reset.inc +#################################################################### +# Test Case2: Improved error message with charset information for CHAR +# type +#################################################################### +connection master; +SET SQL_LOG_BIN=0; +CREATE TABLE t1 (c1 CHAR(1) CHARACTER SET 'utf8mb3'); +SET SQL_LOG_BIN=1; +connection slave; +CREATE TABLE t1 (c1 CHAR(1) CHARACTER SET 'utf8mb4'); +connection master; +INSERT INTO t1 VALUES ('a'); +connection slave; +include/wait_for_slave_sql_error.inc [errno=1677] +FOUND 1 /\'char$3\(bytes$\)\' to type \'char$4\(bytes$ utf8mb4\)\'/ in mysqld.2.err +connection master; +DROP TABLE t1; +connection slave; +DROP TABLE t1; +include/rpl_reset.inc +#################################################################### +# Test Case3: For BLOB type fileds, when type conversion failed on +# slave, the errormessage had incorrect type names. +#################################################################### +connection master; +SET SQL_LOG_BIN=0; +CREATE TABLE t1 (c1 LONGBLOB); +SET SQL_LOG_BIN=1; +connection slave; +CREATE TABLE t1 (c1 TINYBLOB); +connection master; +INSERT INTO t1 VALUES ('a'); +connection slave; +include/wait_for_slave_sql_error.inc [errno=1677] +FOUND 1 /\'longblob\' to type \'tinyblob\'/ in mysqld.2.err +connection master; +DROP TABLE t1; +connection slave; +DROP TABLE t1; +include/rpl_reset.inc +include/rpl_end.inc diff --git a/mysql-test/suite/rpl/t/rpl_type_conv_utf8_utf8mb4.test b/mysql-test/suite/rpl/t/rpl_type_conv_utf8_utf8mb4.test new file mode 100644 index 00000000000..ee56ffdcd06 --- /dev/null +++ b/mysql-test/suite/rpl/t/rpl_type_conv_utf8_utf8mb4.test @@ -0,0 +1,144 @@ +# ==== Purpose ==== +# +# Test verifies that when slave side type conversion fails in row based +# replication, more informative error message is displayed. It also verifies +# that in the case of blob fields appropriate type name is displayed in error +# message. +# +# ==== Implementation ==== +# +# Steps: +# Test case1: +# 1. Create a table on master with VARCHAR filed and charset +# 'utf8mb3'. +# 2. Create a table on slave with VARCHAR field and charset +# 'utf8mb4'. +# 3. Insert a tuple on master. +# 4. Verify that slave provides more informative error message with +# respect to difference in charsets. +# Test case2: Repeat same steps as above for CHAR field +# Test case3: +# 1. Create a table on master with LONGBLOB field. +# 2. Create a table on slave with TINYBLOB field. +# 3. Insert a tuple on master. +# 4. Verify that error message displayed on slave clearly states type +# conversion failure from 'longblob' to 'tinyblob'. +# 5. Also verify that error message doesn't show additional details +# of charset when not required. +# +# ==== References ==== +# +# MDEV-19925: Column ... cannot be converted from type 'varchar(20)' to type +# 'varchar(20)' +# + +--source include/have_binlog_format_row.inc +# Inorder to grep a specific error pattern in error log a fresh error log +# needs to be generated. +--source include/force_restart.inc +--source include/master-slave.inc + +--echo #################################################################### +--echo # Test Case1: Improved error message with charset information +--echo #################################################################### +--connection master +SET SQL_LOG_BIN=0; +CREATE TABLE t1 (c1 VARCHAR(1) CHARACTER SET 'utf8mb3'); +SET SQL_LOG_BIN=1; + +--connection slave +CREATE TABLE t1 (c1 VARCHAR(1) CHARACTER SET 'utf8mb4'); + +--connection master +INSERT INTO t1 VALUES ('a'); + +--connection slave +--let $slave_sql_errno= 1677 +--source include/wait_for_slave_sql_error.inc + +# Check error log for correct messages. +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.2.err; +} + +# Error msg before: Column 0 of table 'test.t1' cannot be converted from type 'varchar(3)' to type 'varchar(1)' +# Error msg after : Column 0 of table 'test.t1' cannot be converted from type 'varchar(3(bytes))' to type 'varchar(4(bytes) utf8mb4)' +--let SEARCH_FILE=$log_error_ +--let SEARCH_PATTERN=\'varchar$3\(bytes$\)\' to type \'varchar$4\(bytes$ utf8mb4\)\' +--source include/search_pattern_in_file.inc + +--connection master +DROP TABLE t1; +--connection slave +DROP TABLE t1; +--let $rpl_only_running_threads= 1 +--source include/rpl_reset.inc + +--echo #################################################################### +--echo # Test Case2: Improved error message with charset information for CHAR +--echo # type +--echo #################################################################### +--connection master +SET SQL_LOG_BIN=0; +CREATE TABLE t1 (c1 CHAR(1) CHARACTER SET 'utf8mb3'); +SET SQL_LOG_BIN=1; + +--connection slave +CREATE TABLE t1 (c1 CHAR(1) CHARACTER SET 'utf8mb4'); + +--connection master +INSERT INTO t1 VALUES ('a'); + +--connection slave +--let $slave_sql_errno= 1677 +--source include/wait_for_slave_sql_error.inc + +# Error msg before: Column 0 of table 'test.t1' cannot be converted from type 'char(0)' to type 'char(1)' +# Error msg after : Column 0 of table 'test.t1' cannot be converted from type 'char(3(bytes))' to type 'char(4(bytes) utf8mb4)' +--let SEARCH_FILE=$log_error_ +--let SEARCH_PATTERN=\'char$3\(bytes$\)\' to type \'char$4\(bytes$ utf8mb4\)\' +--source include/search_pattern_in_file.inc + +--connection master +DROP TABLE t1; +--connection slave +DROP TABLE t1; +--let $rpl_only_running_threads= 1 +--source include/rpl_reset.inc + +--echo #################################################################### +--echo # Test Case3: For BLOB type fileds, when type conversion failed on +--echo # slave, the errormessage had incorrect type names. +--echo #################################################################### +--connection master +SET SQL_LOG_BIN=0; +CREATE TABLE t1 (c1 LONGBLOB); +SET SQL_LOG_BIN=1; + +--connection slave +CREATE TABLE t1 (c1 TINYBLOB); + +--connection master +INSERT INTO t1 VALUES ('a'); + +--connection slave +--let $slave_sql_errno= 1677 +--source include/wait_for_slave_sql_error.inc + +# Error msg before: Column 0 of table 'test.t1' cannot be converted from type 'tinyblob' to type 'tinyblob' +# Error msg after : Column 0 of table 'test.t1' cannot be converted from type 'longblob' to type 'tinyblob' +--let SEARCH_FILE=$log_error_ +--let SEARCH_PATTERN=\'longblob\' to type \'tinyblob\' +--source include/search_pattern_in_file.inc + +--connection master +DROP TABLE t1; +--connection slave +DROP TABLE t1; +--let $rpl_only_running_threads= 1 +--source include/rpl_reset.inc +--source include/rpl_end.inc diff --git a/sql/rpl_utility.cc b/sql/rpl_utility.cc index 4277e68a8b5..da814ae28b1 100644 --- a/sql/rpl_utility.cc +++ b/sql/rpl_utility.cc @@ -410,7 +410,7 @@ void show_sql_type(enum_field_types type, uint16 metadata, String *str, CHARSET_ CHARSET_INFO *cs= str->charset(); uint32 length= cs->cset->snprintf(cs, (char*) str->ptr(), str->alloced_length(), - "varchar(%u)", metadata); + "varchar(%u(bytes))", metadata); str->length(length); } break; @@ -460,22 +460,22 @@ void show_sql_type(enum_field_types type, uint16 metadata, String *str, CHARSET_ it is necessary to check the pack length to figure out what kind of blob it really is. */ - switch (get_blob_type_from_length(metadata)) + switch (metadata) { - case MYSQL_TYPE_TINY_BLOB: + case 1: str->set_ascii(STRING_WITH_LEN("tinyblob")); break; - case MYSQL_TYPE_MEDIUM_BLOB: - str->set_ascii(STRING_WITH_LEN("mediumblob")); + case 2: + str->set_ascii(STRING_WITH_LEN("blob")); break; - case MYSQL_TYPE_LONG_BLOB: - str->set_ascii(STRING_WITH_LEN("longblob")); + case 3: + str->set_ascii(STRING_WITH_LEN("mediumblob")); break; - case MYSQL_TYPE_BLOB: - str->set_ascii(STRING_WITH_LEN("blob")); + case 4: + str->set_ascii(STRING_WITH_LEN("longblob")); break; default: @@ -493,7 +493,7 @@ void show_sql_type(enum_field_types type, uint16 metadata, String *str, CHARSET_ uint bytes= (((metadata >> 4) & 0x300) ^ 0x300) + (metadata & 0x00ff); uint32 length= cs->cset->snprintf(cs, (char*) str->ptr(), str->alloced_length(), - "char(%d)", bytes / field_cs->mbmaxlen); + "char(%d(bytes))", bytes); str->length(length); } break; @@ -893,12 +893,33 @@ table_def::compatible_with(THD *thd, rpl_group_info *rgi, const char *tbl_name= table->s->table_name.str; char source_buf[MAX_FIELD_WIDTH]; char target_buf[MAX_FIELD_WIDTH]; + String field_sql_type; String source_type(source_buf, sizeof(source_buf), &my_charset_latin1); String target_type(target_buf, sizeof(target_buf), &my_charset_latin1); THD *thd= table->in_use; - show_sql_type(type(col), field_metadata(col), &source_type, field->charset()); - field->sql_type(target_type); + show_sql_type(type(col), field_metadata(col), &source_type, + field->charset()); + if (field->has_charset() && + (field->real_type() != MYSQL_TYPE_ENUM && + field->real_type() != MYSQL_TYPE_SET) && + (field->type() == MYSQL_TYPE_VARCHAR || + field->type() == MYSQL_TYPE_STRING)) + { + field_sql_type.append((field->type() == MYSQL_TYPE_VARCHAR) ? + "varchar" : "char"); + const CHARSET_INFO *cs= field->charset(); + size_t length= cs->cset->snprintf(cs, (char*) target_type.ptr(), + target_type.alloced_length(), + "%s(%u(bytes) %s)", + field_sql_type.c_ptr_safe(), + field->field_length, + field->charset()->csname); + target_type.length(length); + } + else + field->sql_type(target_type); + rli->report(ERROR_LEVEL, ER_SLAVE_CONVERSION_FAILED, rgi->gtid_info(), ER_THD(thd, ER_SLAVE_CONVERSION_FAILED), col, db_name, tbl_name, diff --git a/storage/tokudb/mysql-test/rpl/r/rpl_extra_col_master_tokudb.result b/storage/tokudb/mysql-test/rpl/r/rpl_extra_col_master_tokudb.result index cca18c7c1ab..f8867e8a98b 100644 --- a/storage/tokudb/mysql-test/rpl/r/rpl_extra_col_master_tokudb.result +++ b/storage/tokudb/mysql-test/rpl/r/rpl_extra_col_master_tokudb.result @@ -468,7 +468,7 @@ INSERT INTO t10 () VALUES(1,@b1,DEFAULT,'Kyle',DEFAULT), connection slave; include/wait_for_slave_sql_error_and_skip.inc [errno=1677] -Last_SQL_Error = 'Column 2 of table 'test.t10' cannot be converted from type 'double' to type 'char(5)'' +Last_SQL_Error = 'Column 2 of table 'test.t10' cannot be converted from type 'double' to type 'char(5(bytes) latin1)'' *** Drop t10 *** connection master; @@ -510,7 +510,7 @@ INSERT INTO t11 () VALUES(1,@b1,'Testing is fun','Kyle',DEFAULT), connection slave; include/wait_for_slave_sql_error_and_skip.inc [errno=1677] -Last_SQL_Error = 'Column 2 of table 'test.t11' cannot be converted from type 'tinyblob' to type 'varchar(254)'' +Last_SQL_Error = 'Column 2 of table 'test.t11' cannot be converted from type 'blob' to type 'varchar(254(bytes) latin1)'' *** Drop t11 *** connection master; diff --git a/storage/tokudb/mysql-test/rpl/r/rpl_extra_col_slave_tokudb.result b/storage/tokudb/mysql-test/rpl/r/rpl_extra_col_slave_tokudb.result index 8906cf31d74..7cbe0d6092c 100644 --- a/storage/tokudb/mysql-test/rpl/r/rpl_extra_col_slave_tokudb.result +++ b/storage/tokudb/mysql-test/rpl/r/rpl_extra_col_slave_tokudb.result @@ -64,7 +64,7 @@ a b c connection slave; START SLAVE; include/wait_for_slave_sql_error.inc [errno=1677] -Last_SQL_Error = 'Column 2 of table 'test.t2' cannot be converted from type 'char(10)' to type 'char(5)'' +Last_SQL_Error = 'Column 2 of table 'test.t2' cannot be converted from type 'char(10(bytes))' to type 'char(5(bytes) latin1)'' STOP SLAVE; RESET SLAVE; SELECT * FROM t2 ORDER BY a; @@ -102,7 +102,7 @@ INSERT INTO t3 () VALUES(@b1,2,'Kyle, TEX'),(@b1,1,'JOE AUSTIN'),(@b1,4,'QA TEST ******************************************** connection slave; include/wait_for_slave_sql_error_and_skip.inc [errno=1677] -Last_SQL_Error = 'Column 0 of table 'test.t3' cannot be converted from type 'tinyblob' to type 'int(11)'' +Last_SQL_Error = 'Column 0 of table 'test.t3' cannot be converted from type 'blob' to type 'int(11)'' *** Drop t3 *** connection master; DROP TABLE t3; @@ -160,7 +160,7 @@ INSERT INTO t5 () VALUES(1,'Kyle',200.23,1,'b1b1',23.00098), ******************************************** connection slave; include/wait_for_slave_sql_error_and_skip.inc [errno=1677] -Last_SQL_Error = 'Column 1 of table 'test.t5' cannot be converted from type 'varchar(6)' to type 'char(5)'' +Last_SQL_Error = 'Column 1 of table 'test.t5' cannot be converted from type 'varchar(6(bytes))' to type 'char(5(bytes) latin1)'' *** Drop t5 *** connection master; DROP TABLE t5; @@ -188,7 +188,7 @@ INSERT INTO t6 () VALUES(1,'Kyle',200.23,1), ******************************************** connection slave; include/wait_for_slave_sql_error.inc [errno=1677] -Last_SQL_Error = 'Column 1 of table 'test.t6' cannot be converted from type 'varchar(6)' to type 'char(5)'' +Last_SQL_Error = 'Column 1 of table 'test.t6' cannot be converted from type 'varchar(6(bytes))' to type 'char(5(bytes) latin1)'' *** Drop t6 *** include/rpl_reset.inc connection master; @@ -310,7 +310,7 @@ INSERT INTO t10 () VALUES(1,@b1,'Kyle'),(2,@b1,'JOE'),(3,@b1,'QA'); ******************************************** connection slave; include/wait_for_slave_sql_error_and_skip.inc [errno=1677] -Last_SQL_Error = 'Column 2 of table 'test.t10' cannot be converted from type 'char(5)' to type 'double'' +Last_SQL_Error = 'Column 2 of table 'test.t10' cannot be converted from type 'char(5(bytes))' to type 'double'' *** Drop t10 *** connection master; DROP TABLE t10; @@ -338,7 +338,7 @@ INSERT INTO t11 () VALUES(1,@b1,'Kyle'),(2,@b1,'JOE'),(3,@b1,'QA'); ******************************************** connection slave; include/wait_for_slave_sql_error_and_skip.inc [errno=1677] -Last_SQL_Error = 'Column 2 of table 'test.t11' cannot be converted from type 'varchar(254)' to type 'int(11)'' +Last_SQL_Error = 'Column 2 of table 'test.t11' cannot be converted from type 'varchar(254(bytes))' to type 'int(11)'' *** Drop t11 *** connection master; DROP TABLE t11; diff --git a/storage/tokudb/mysql-test/rpl/r/rpl_row_basic_3tokudb.result b/storage/tokudb/mysql-test/rpl/r/rpl_row_basic_3tokudb.result index 32a42143180..7d7a7e18a76 100644 --- a/storage/tokudb/mysql-test/rpl/r/rpl_row_basic_3tokudb.result +++ b/storage/tokudb/mysql-test/rpl/r/rpl_row_basic_3tokudb.result @@ -565,7 +565,7 @@ INSERT INTO t5 VALUES (1, "", 1); INSERT INTO t5 VALUES (2, repeat(_utf8'a', 255), 2); connection slave; include/wait_for_slave_sql_error.inc [errno=1677] -Last_SQL_Error = 'Column 1 of table 'test.t5' cannot be converted from type 'char(255)' to type 'char(16)'' +Last_SQL_Error = 'Column 1 of table 'test.t5' cannot be converted from type 'char(765(bytes))' to type 'char(48(bytes) utf8)'' include/rpl_reset.inc [expecting slave to stop] connection master; @@ -573,7 +573,7 @@ INSERT INTO t6 VALUES (1, "", 1); INSERT INTO t6 VALUES (2, repeat(_utf8'a', 255), 2); connection slave; include/wait_for_slave_sql_error.inc [errno=1677] -Last_SQL_Error = 'Column 1 of table 'test.t6' cannot be converted from type 'char(255)' to type 'char(128)'' +Last_SQL_Error = 'Column 1 of table 'test.t6' cannot be converted from type 'char(765(bytes))' to type 'char(384(bytes) utf8)'' include/rpl_reset.inc [expecting slave to replicate correctly] connection master;

1 0

[Commits] d7c461e0123: MDEV-7409 On RBR, extend the PROCESSLIST info to include at least the name of the recently used table
by sachin.setiya＠mariadb.com 17 Jul '19

17 Jul '19

revision-id: d7c461e012322a032ade3aff50e36e39e3835a23 (mariadb-10.4.5-24-gd7c461e0123) parent(s): e35676f5557d68c7b51ba47aa73dcdf72eafa436 author: Sachin committer: Sachin timestamp: 2019-07-17 18:56:52 +0530 message: MDEV-7409 On RBR, extend the PROCESSLIST info to include at least the name of the recently used table When RBR is used, add the db name to db Field and table name to Status Field of the "SHOW FULL PROCESSLIST" command for SQL thread. --- mysql-test/suite/rpl/r/rpl_rbr_monitor.result | 56 +++++++++++++++++++ mysql-test/suite/rpl/t/rpl_rbr_monitor.test | 77 +++++++++++++++++++++++++++ sql/log_event.cc | 71 +++++++++++++++++------- 3 files changed, 184 insertions(+), 20 deletions(-) diff --git a/mysql-test/suite/rpl/r/rpl_rbr_monitor.result b/mysql-test/suite/rpl/r/rpl_rbr_monitor.result new file mode 100644 index 00000000000..ab8574f055f --- /dev/null +++ b/mysql-test/suite/rpl/r/rpl_rbr_monitor.result @@ -0,0 +1,56 @@ +include/master-slave.inc +[connection master] +connection master; +create table t1(a int primary key) engine=innodb; +connection slave; +connection slave1; +begin; +insert into t1(a) values(1); +connection master; +select * from t1; +a +connection master; +insert into t1(a) values(1); +#monitoring write rows +connection slave; +SELECT db , state FROM INFORMATION_SCHEMA.PROCESSLIST +WHERE DB = 'test' AND STATE LIKE "Write_rows_log_event::write_row(%) on table %"; +db state +test Write_rows_log_event::write_row(-1) on table `t1` +#monitoring update rows +connection slave1; +rollback; +begin; +select a from t1 for update; +a +1 +connection master; +update t1 set a = a + 1 ; +connection slave; +SELECT db, state FROM INFORMATION_SCHEMA.PROCESSLIST +WHERE DB = 'test' AND STATE LIKE "Update_rows_log_event::find_row(%) on table %"; +db state +test Update_rows_log_event::find_row(-1) on table `t1` +#monitoring delete rows +connection slave1; +rollback; +begin; +select * from t1 for update; +a +2 +connection master; +delete from t1; +connection slave; +select * from t1; +a +2 +SELECT db , state FROM INFORMATION_SCHEMA.PROCESSLIST +WHERE DB = 'test' AND STATE LIKE "Delete_rows_log_event::find_row(%) on table %"; +db state +test Delete_rows_log_event::find_row(-1) on table `t1` +connection slave1; +rollback; +connection master; +drop table t1; +connection slave; +include/rpl_end.inc diff --git a/mysql-test/suite/rpl/t/rpl_rbr_monitor.test b/mysql-test/suite/rpl/t/rpl_rbr_monitor.test new file mode 100644 index 00000000000..cbc38c511fc --- /dev/null +++ b/mysql-test/suite/rpl/t/rpl_rbr_monitor.test @@ -0,0 +1,77 @@ +--source include/have_innodb.inc +--source include/have_binlog_format_row.inc +--source include/master-slave.inc +--enable_connect_log + +--connection master +create table t1(a int primary key) engine=innodb; + +--sync_slave_with_master +--connection slave1 +begin; +insert into t1(a) values(1); +--connection master +select * from t1; + +--connection master +insert into t1(a) values(1); +--save_master_pos + +--echo #monitoring write rows +--connection slave + + +let $wait_condition= SELECT COUNT(*) = 1 FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Write_rows_log_event::write_row(%) on table %"; +--source include/wait_condition.inc +SELECT db , state FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Write_rows_log_event::write_row(%) on table %"; + + +--echo #monitoring update rows +--connection slave1 +rollback; +--sync_with_master +begin; +select a from t1 for update; + +--connection master +update t1 set a = a + 1 ; +--save_master_pos + +--connection slave +let $wait_condition= SELECT COUNT(*) = 1 FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Update_rows_log_event::find_row(%) on table %"; +--source include/wait_condition.inc +SELECT db, state FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Update_rows_log_event::find_row(%) on table %"; + +--echo #monitoring delete rows +--connection slave1 +rollback; +--sync_with_master +begin; +select * from t1 for update; + +--connection master +delete from t1; +--save_master_pos + +--connection slave +select * from t1; +let $wait_condition= SELECT COUNT(*) = 1 FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Delete_rows_log_event::find_row(%) on table %"; +--source include/wait_condition.inc +SELECT db , state FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Delete_rows_log_event::find_row(%) on table %"; + +#CleanUp +--connection slave1 +rollback; +--sync_with_master + +--connection master +drop table t1; +--sync_slave_with_master + +--source include/rpl_end.inc diff --git a/sql/log_event.cc b/sql/log_event.cc index f25ebd56792..32af08c88f9 100644 --- a/sql/log_event.cc +++ b/sql/log_event.cc @@ -13693,19 +13693,27 @@ Write_rows_log_event::do_exec_row(rpl_group_info *rgi) { DBUG_ASSERT(m_table != NULL); const char *tmp= thd->get_proc_info(); - const char *message= "Write_rows_log_event::write_row()"; + LEX_CSTRING *tmp_db= &thd->db; + char *message, msg[128]; + const char *table_name= m_table->s->table_name.str; + char quote_char= get_quote_char_for_identifier(thd, STRING_WITH_LEN(table_name)); + my_snprintf(msg, sizeof(msg),"Write_rows_log_event::write_row() on table %c%s%c", + quote_char, table_name, quote_char); + thd->set_db(&m_table->s->db); + message= msg; int error; #ifdef WSREP_PROC_INFO my_snprintf(thd->wsrep_info, sizeof(thd->wsrep_info) - 1, - "Write_rows_log_event::write_row(%lld)", - (long long) wsrep_thd_trx_seqno(thd)); + "Write_rows_log_event::write_row(%lld) on table %c%s%c", + (long long) wsrep_thd_trx_seqno(thd), quote_char, table_name, quote_char); message= thd->wsrep_info; #endif /* WSREP_PROC_INFO */ thd_proc_info(thd, message); error= write_row(rgi, slave_exec_mode == SLAVE_EXEC_MODE_IDEMPOTENT); thd_proc_info(thd, tmp); + thd->set_db(tmp_db); if (unlikely(error) && unlikely(!thd->is_error())) { @@ -14368,15 +14376,22 @@ int Delete_rows_log_event::do_exec_row(rpl_group_info *rgi) { int error; const char *tmp= thd->get_proc_info(); - const char *message= "Delete_rows_log_event::find_row()"; + LEX_CSTRING *tmp_db= &thd->db; + char *message, msg[128]; + const char *table_name= m_table->s->table_name.str; + char quote_char= get_quote_char_for_identifier(thd, STRING_WITH_LEN(table_name)); + my_snprintf(msg, sizeof(msg),"Delete_rows_log_event::find_row() on table %c%s%c", + quote_char, table_name, quote_char); + thd->set_db(&m_table->s->db); + message= msg; const bool invoke_triggers= slave_run_triggers_for_rbr && !master_had_triggers && m_table->triggers; DBUG_ASSERT(m_table != NULL); #ifdef WSREP_PROC_INFO my_snprintf(thd->wsrep_info, sizeof(thd->wsrep_info) - 1, - "Delete_rows_log_event::find_row(%lld)", - (long long) wsrep_thd_trx_seqno(thd)); + "Delete_rows_log_event::find_row(%lld) on table %c%s%c", + (long long) wsrep_thd_trx_seqno(thd), quote_char, table_name, quote_char); message= thd->wsrep_info; #endif /* WSREP_PROC_INFO */ @@ -14386,11 +14401,13 @@ int Delete_rows_log_event::do_exec_row(rpl_group_info *rgi) /* Delete the record found, located in record[0] */ - message= "Delete_rows_log_event::ha_delete_row()"; + my_snprintf(msg, sizeof(msg),"Delete_rows_log_event::ha_delete_row() on table %c%s%c", + quote_char, table_name, quote_char); + message= msg; #ifdef WSREP_PROC_INFO snprintf(thd->wsrep_info, sizeof(thd->wsrep_info) - 1, - "Delete_rows_log_event::ha_delete_row(%lld)", - (long long) wsrep_thd_trx_seqno(thd)); + "Delete_rows_log_event::ha_delete_row(%lld) on table %c%s%c", + (long long) wsrep_thd_trx_seqno(thd), quote_char, table_name, quote_char); message= thd->wsrep_info; #endif thd_proc_info(thd, message); @@ -14422,6 +14439,7 @@ int Delete_rows_log_event::do_exec_row(rpl_group_info *rgi) m_table->file->ha_index_or_rnd_end(); } thd_proc_info(thd, tmp); + thd->set_db(tmp_db); return error; } @@ -14590,17 +14608,25 @@ Update_rows_log_event::do_exec_row(rpl_group_info *rgi) const bool invoke_triggers= slave_run_triggers_for_rbr && !master_had_triggers && m_table->triggers; const char *tmp= thd->get_proc_info(); - const char *message= "Update_rows_log_event::find_row()"; + LEX_CSTRING *tmp_db= &thd->db; + char *message, msg[128]; + const char *table_name= m_table->s->table_name.str; + char quote_char= get_quote_char_for_identifier(thd, STRING_WITH_LEN(table_name)); DBUG_ASSERT(m_table != NULL); + my_snprintf(msg, sizeof(msg),"Update_rows_log_event::find_row() on table %c%s%c", + quote_char, table_name, quote_char); + thd->set_db(&m_table->s->db); + message= msg; #ifdef WSREP_PROC_INFO my_snprintf(thd->wsrep_info, sizeof(thd->wsrep_info) - 1, - "Update_rows_log_event::find_row(%lld)", - (long long) wsrep_thd_trx_seqno(thd)); + "Update_rows_log_event::find_row(%lld) on table %c%s%c", + (long long) wsrep_thd_trx_seqno(thd), quote_char, table_name, quote_char); message= thd->wsrep_info; #endif /* WSREP_PROC_INFO */ thd_proc_info(thd, message); + int error= find_row(rgi); if (unlikely(error)) { @@ -14611,6 +14637,7 @@ Update_rows_log_event::do_exec_row(rpl_group_info *rgi) if ((m_curr_row= m_curr_row_end)) unpack_current_row(rgi, &m_cols_ai); thd_proc_info(thd, tmp); + thd->set_db(tmp_db); return error; } @@ -14628,11 +14655,13 @@ Update_rows_log_event::do_exec_row(rpl_group_info *rgi) store_record(m_table,record[1]); m_curr_row= m_curr_row_end; - message= "Update_rows_log_event::unpack_current_row()"; + my_snprintf(msg, sizeof(msg),"Update_rows_log_event::unpack_current_row() on table %c%s%c", + quote_char, table_name, quote_char); + message= msg; #ifdef WSREP_PROC_INFO my_snprintf(thd->wsrep_info, sizeof(thd->wsrep_info) - 1, - "Update_rows_log_event::unpack_current_row(%lld)", - (long long) wsrep_thd_trx_seqno(thd)); + "Update_rows_log_event::unpack_current_row(%lld) on table %c%s%c", + (long long) wsrep_thd_trx_seqno(thd), quote_char, table_name, quote_char); message= thd->wsrep_info; #endif /* WSREP_PROC_INFO */ @@ -14655,11 +14684,13 @@ Update_rows_log_event::do_exec_row(rpl_group_info *rgi) DBUG_DUMP("new values", m_table->record[0], m_table->s->reclength); #endif - message= "Update_rows_log_event::ha_update_row()"; + my_snprintf(msg, sizeof(msg),"Update_rows_log_event::ha_update_row() on table %c%s%c", + quote_char, table_name, quote_char); + message= msg; #ifdef WSREP_PROC_INFO my_snprintf(thd->wsrep_info, sizeof(thd->wsrep_info) - 1, - "Update_rows_log_event::ha_update_row(%lld)", - (long long) wsrep_thd_trx_seqno(thd)); + "Update_rows_log_event::ha_update_row(%lld) on table %c%s%c", + (long long) wsrep_thd_trx_seqno(thd), quote_char, table_name, quote_char); message= thd->wsrep_info; #endif /* WSREP_PROC_INFO */ @@ -14693,9 +14724,9 @@ Update_rows_log_event::do_exec_row(rpl_group_info *rgi) unlikely(process_triggers(TRG_EVENT_UPDATE, TRG_ACTION_AFTER, TRUE))) error= HA_ERR_GENERIC; // in case if error is not set yet - thd_proc_info(thd, tmp); - err: + thd_proc_info(thd, tmp); + thd->set_db(tmp_db); m_table->file->ha_index_or_rnd_end(); return error; }

1 0

[Commits] e7f5737dee1: MDEV-7409 On RBR, extend the PROCESSLIST info to include at least the name of the recently used table
by sachin.setiya＠mariadb.com 17 Jul '19

17 Jul '19

revision-id: e7f5737dee1216523fdca37e9683cc3e1cc0dccb (mariadb-10.4.5-24-ge7f5737dee1) parent(s): e35676f5557d68c7b51ba47aa73dcdf72eafa436 author: Sachin committer: Sachin timestamp: 2019-07-17 18:53:09 +0530 message: MDEV-7409 On RBR, extend the PROCESSLIST info to include at least the name of the recently used table When RBR is used, add the db name to db Field and table name to Status Field of the "SHOW FULL PROCESSLIST" command for SQL thread. --- mysql-test/suite/rpl/r/rpl_rbr_monitor.result | 56 +++++++++++++++++++ mysql-test/suite/rpl/t/rpl_rbr_monitor.test | 77 +++++++++++++++++++++++++++ sql/log_event.cc | 71 +++++++++++++++++------- 3 files changed, 184 insertions(+), 20 deletions(-) diff --git a/mysql-test/suite/rpl/r/rpl_rbr_monitor.result b/mysql-test/suite/rpl/r/rpl_rbr_monitor.result new file mode 100644 index 00000000000..ab8574f055f --- /dev/null +++ b/mysql-test/suite/rpl/r/rpl_rbr_monitor.result @@ -0,0 +1,56 @@ +include/master-slave.inc +[connection master] +connection master; +create table t1(a int primary key) engine=innodb; +connection slave; +connection slave1; +begin; +insert into t1(a) values(1); +connection master; +select * from t1; +a +connection master; +insert into t1(a) values(1); +#monitoring write rows +connection slave; +SELECT db , state FROM INFORMATION_SCHEMA.PROCESSLIST +WHERE DB = 'test' AND STATE LIKE "Write_rows_log_event::write_row(%) on table %"; +db state +test Write_rows_log_event::write_row(-1) on table `t1` +#monitoring update rows +connection slave1; +rollback; +begin; +select a from t1 for update; +a +1 +connection master; +update t1 set a = a + 1 ; +connection slave; +SELECT db, state FROM INFORMATION_SCHEMA.PROCESSLIST +WHERE DB = 'test' AND STATE LIKE "Update_rows_log_event::find_row(%) on table %"; +db state +test Update_rows_log_event::find_row(-1) on table `t1` +#monitoring delete rows +connection slave1; +rollback; +begin; +select * from t1 for update; +a +2 +connection master; +delete from t1; +connection slave; +select * from t1; +a +2 +SELECT db , state FROM INFORMATION_SCHEMA.PROCESSLIST +WHERE DB = 'test' AND STATE LIKE "Delete_rows_log_event::find_row(%) on table %"; +db state +test Delete_rows_log_event::find_row(-1) on table `t1` +connection slave1; +rollback; +connection master; +drop table t1; +connection slave; +include/rpl_end.inc diff --git a/mysql-test/suite/rpl/t/rpl_rbr_monitor.test b/mysql-test/suite/rpl/t/rpl_rbr_monitor.test new file mode 100644 index 00000000000..cbc38c511fc --- /dev/null +++ b/mysql-test/suite/rpl/t/rpl_rbr_monitor.test @@ -0,0 +1,77 @@ +--source include/have_innodb.inc +--source include/have_binlog_format_row.inc +--source include/master-slave.inc +--enable_connect_log + +--connection master +create table t1(a int primary key) engine=innodb; + +--sync_slave_with_master +--connection slave1 +begin; +insert into t1(a) values(1); +--connection master +select * from t1; + +--connection master +insert into t1(a) values(1); +--save_master_pos + +--echo #monitoring write rows +--connection slave + + +let $wait_condition= SELECT COUNT(*) = 1 FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Write_rows_log_event::write_row(%) on table %"; +--source include/wait_condition.inc +SELECT db , state FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Write_rows_log_event::write_row(%) on table %"; + + +--echo #monitoring update rows +--connection slave1 +rollback; +--sync_with_master +begin; +select a from t1 for update; + +--connection master +update t1 set a = a + 1 ; +--save_master_pos + +--connection slave +let $wait_condition= SELECT COUNT(*) = 1 FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Update_rows_log_event::find_row(%) on table %"; +--source include/wait_condition.inc +SELECT db, state FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Update_rows_log_event::find_row(%) on table %"; + +--echo #monitoring delete rows +--connection slave1 +rollback; +--sync_with_master +begin; +select * from t1 for update; + +--connection master +delete from t1; +--save_master_pos + +--connection slave +select * from t1; +let $wait_condition= SELECT COUNT(*) = 1 FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Delete_rows_log_event::find_row(%) on table %"; +--source include/wait_condition.inc +SELECT db , state FROM INFORMATION_SCHEMA.PROCESSLIST + WHERE DB = 'test' AND STATE LIKE "Delete_rows_log_event::find_row(%) on table %"; + +#CleanUp +--connection slave1 +rollback; +--sync_with_master + +--connection master +drop table t1; +--sync_slave_with_master + +--source include/rpl_end.inc diff --git a/sql/log_event.cc b/sql/log_event.cc index f25ebd56792..3a7f37eae94 100644 --- a/sql/log_event.cc +++ b/sql/log_event.cc @@ -13693,19 +13693,27 @@ Write_rows_log_event::do_exec_row(rpl_group_info *rgi) { DBUG_ASSERT(m_table != NULL); const char *tmp= thd->get_proc_info(); - const char *message= "Write_rows_log_event::write_row()"; + LEX_CSTRING *tmp_db= &thd->db; + char *message, msg[128]; + const char *table_name= m_table->s->table_name.str; + char quote_char= get_quote_char_for_identifier(thd, STRING_WITH_LEN(table_name)); + my_snprintf(msg, sizeof(msg),"Write_rows_log_event::write_row() on table %c%s%c", + quote_char, table_name, quote_char); + thd->set_db(&m_table->s->db); + message= msg; int error; #ifdef WSREP_PROC_INFO my_snprintf(thd->wsrep_info, sizeof(thd->wsrep_info) - 1, - "Write_rows_log_event::write_row(%lld)", - (long long) wsrep_thd_trx_seqno(thd)); + "Write_rows_log_event::write_row(%lld) on table %c%s%c", + (long long) wsrep_thd_trx_seqno(thd), quote_char, table_name, quote_char); message= thd->wsrep_info; #endif /* WSREP_PROC_INFO */ thd_proc_info(thd, message); error= write_row(rgi, slave_exec_mode == SLAVE_EXEC_MODE_IDEMPOTENT); thd_proc_info(thd, tmp); + thd->set_db(tmp_db); if (unlikely(error) && unlikely(!thd->is_error())) { @@ -14368,15 +14376,22 @@ int Delete_rows_log_event::do_exec_row(rpl_group_info *rgi) { int error; const char *tmp= thd->get_proc_info(); - const char *message= "Delete_rows_log_event::find_row()"; + LEX_CSTRING *tmp_db= &thd->db; + char *message, msg[128]; + const char *table_name= m_table->s->table_name.str; + char quote_char= get_quote_char_for_identifier(thd, STRING_WITH_LEN(table_name)); + my_snprintf(msg, sizeof(msg),"Delete_rows_log_event::find_row() on table %c%s%c", + quote_char, table_name, quote_char); + thd->set_db(&m_table->s->db); + message= msg; const bool invoke_triggers= slave_run_triggers_for_rbr && !master_had_triggers && m_table->triggers; DBUG_ASSERT(m_table != NULL); #ifdef WSREP_PROC_INFO my_snprintf(thd->wsrep_info, sizeof(thd->wsrep_info) - 1, - "Delete_rows_log_event::find_row(%lld)", - (long long) wsrep_thd_trx_seqno(thd)); + "Delete_rows_log_event::find_row(%lld) on table %c%s%c", + (long long) wsrep_thd_trx_seqno(thd), quote_char, table_name, quote_char); message= thd->wsrep_info; #endif /* WSREP_PROC_INFO */ @@ -14386,11 +14401,13 @@ int Delete_rows_log_event::do_exec_row(rpl_group_info *rgi) /* Delete the record found, located in record[0] */ - message= "Delete_rows_log_event::ha_delete_row()"; + my_snprintf(msg, sizeof(msg),"Delete_rows_log_event::ha_delete_row() on table %c%s%c", + quote_char, table_name, quote_char); + message= msg; #ifdef WSREP_PROC_INFO snprintf(thd->wsrep_info, sizeof(thd->wsrep_info) - 1, - "Delete_rows_log_event::ha_delete_row(%lld)", - (long long) wsrep_thd_trx_seqno(thd)); + "Delete_rows_log_event::ha_delete_row(%lld) on table %c%s%c", + (long long) wsrep_thd_trx_seqno(thd), quote_char, table_name, quote_char); message= thd->wsrep_info; #endif thd_proc_info(thd, message); @@ -14422,6 +14439,7 @@ int Delete_rows_log_event::do_exec_row(rpl_group_info *rgi) m_table->file->ha_index_or_rnd_end(); } thd_proc_info(thd, tmp); + thd->set_db(tmp_db); return error; } @@ -14590,17 +14608,25 @@ Update_rows_log_event::do_exec_row(rpl_group_info *rgi) const bool invoke_triggers= slave_run_triggers_for_rbr && !master_had_triggers && m_table->triggers; const char *tmp= thd->get_proc_info(); - const char *message= "Update_rows_log_event::find_row()"; + LEX_CSTRING *tmp_db= &thd->db; + char *message, msg[128]; + const char *table_name= m_table->s->table_name.str; + char quote_char= get_quote_char_for_identifier(thd, STRING_WITH_LEN(table_name)); DBUG_ASSERT(m_table != NULL); + my_snprintf(msg, sizeof(msg),"Update_rows_log_event::find_row() on table %c%s%c", + quote_char, table_name, quote_char); + thd->set_db(&m_table->s->db); + message= msg; #ifdef WSREP_PROC_INFO my_snprintf(thd->wsrep_info, sizeof(thd->wsrep_info) - 1, - "Update_rows_log_event::find_row(%lld)", - (long long) wsrep_thd_trx_seqno(thd)); + "Update_rows_log_event::find_row(%lld) on table %c%s%c", + (long long) wsrep_thd_trx_seqno(thd), quote_char, table_name, quote_char); message= thd->wsrep_info; #endif /* WSREP_PROC_INFO */ thd_proc_info(thd, message); + int error= find_row(rgi); if (unlikely(error)) { @@ -14611,6 +14637,7 @@ Update_rows_log_event::do_exec_row(rpl_group_info *rgi) if ((m_curr_row= m_curr_row_end)) unpack_current_row(rgi, &m_cols_ai); thd_proc_info(thd, tmp); + thd->db= *tmp_db; return error; } @@ -14628,11 +14655,13 @@ Update_rows_log_event::do_exec_row(rpl_group_info *rgi) store_record(m_table,record[1]); m_curr_row= m_curr_row_end; - message= "Update_rows_log_event::unpack_current_row()"; + my_snprintf(msg, sizeof(msg),"Update_rows_log_event::unpack_current_row() on table %c%s%c", + quote_char, table_name, quote_char); + message= msg; #ifdef WSREP_PROC_INFO my_snprintf(thd->wsrep_info, sizeof(thd->wsrep_info) - 1, - "Update_rows_log_event::unpack_current_row(%lld)", - (long long) wsrep_thd_trx_seqno(thd)); + "Update_rows_log_event::unpack_current_row(%lld) on table %c%s%c", + (long long) wsrep_thd_trx_seqno(thd), quote_char, table_name, quote_char); message= thd->wsrep_info; #endif /* WSREP_PROC_INFO */ @@ -14655,11 +14684,13 @@ Update_rows_log_event::do_exec_row(rpl_group_info *rgi) DBUG_DUMP("new values", m_table->record[0], m_table->s->reclength); #endif - message= "Update_rows_log_event::ha_update_row()"; + my_snprintf(msg, sizeof(msg),"Update_rows_log_event::ha_update_row() on table %c%s%c", + quote_char, table_name, quote_char); + message= msg; #ifdef WSREP_PROC_INFO my_snprintf(thd->wsrep_info, sizeof(thd->wsrep_info) - 1, - "Update_rows_log_event::ha_update_row(%lld)", - (long long) wsrep_thd_trx_seqno(thd)); + "Update_rows_log_event::ha_update_row(%lld) on table %c%s%c", + (long long) wsrep_thd_trx_seqno(thd), quote_char, table_name, quote_char); message= thd->wsrep_info; #endif /* WSREP_PROC_INFO */ @@ -14693,9 +14724,9 @@ Update_rows_log_event::do_exec_row(rpl_group_info *rgi) unlikely(process_triggers(TRG_EVENT_UPDATE, TRG_ACTION_AFTER, TRUE))) error= HA_ERR_GENERIC; // in case if error is not set yet - thd_proc_info(thd, tmp); - err: + thd_proc_info(thd, tmp); + thd->set_db(tmp_db); m_table->file->ha_index_or_rnd_end(); return error; }

1 0

[Commits] 5619f0a24fc: MDEV-17614 INSERT on dup key update is replication unsafe
by sachin.setiya＠mariadb.com 17 Jul '19

17 Jul '19

revision-id: 5619f0a24fc89f0b78d23a179fcf9203c1e9da8a (mariadb-10.1.39-91-g5619f0a24fc) parent(s): bdc961acc7ae9d5a3661ac425e936cd03dc5ccbb author: Sachin committer: Sachin timestamp: 2019-07-17 15:56:29 +0530 message: MDEV-17614 INSERT on dup key update is replication unsafe Make INSERT...ON DUPLICATE KEY UPDATE unsafe while using stmt or mixed format When there is more then one unique key. Although there is two exception. 1. Auto Increment key is not counted because Innodb will get gap lock for failed Insert and concurrent insert will get a next increment value. But if user supplies auto inc value it can be unsafe. 2. Count only unique keys for which insertion is performed. So this patch also addresses the bug id #72921 --- .../suite/rpl/r/rpl_known_bugs_detection.result | 20 ---- mysql-test/suite/rpl/r/rpl_mdev_17614.result | 98 +++++++++++++++++ .../suite/rpl/t/rpl_known_bugs_detection.test | 39 ------- mysql-test/suite/rpl/t/rpl_mdev_17614.test | 121 +++++++++++++++++++++ sql/sql_class.cc | 42 +++++++ sql/sql_class.h | 40 ++++--- sql/sql_insert.cc | 1 + 7 files changed, 288 insertions(+), 73 deletions(-) diff --git a/mysql-test/suite/rpl/r/rpl_known_bugs_detection.result b/mysql-test/suite/rpl/r/rpl_known_bugs_detection.result index ea738b710fd..adef091ea3e 100644 --- a/mysql-test/suite/rpl/r/rpl_known_bugs_detection.result +++ b/mysql-test/suite/rpl/r/rpl_known_bugs_detection.result @@ -1,26 +1,6 @@ call mtr.add_suppression("Unsafe statement written to the binary log using statement format"); include/master-slave.inc [connection master] -call mtr.add_suppression("Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT."); -CREATE TABLE t1 (a INT NOT NULL PRIMARY KEY AUTO_INCREMENT, b INT, -UNIQUE(b)); -INSERT INTO t1(b) VALUES(1),(1),(2) ON DUPLICATE KEY UPDATE t1.b=10; -SELECT * FROM t1; -a b -1 10 -2 2 -call mtr.add_suppression("Slave SQL.*suffer.*http:..bugs.mysql.com.bug.php.id=24432"); -include/wait_for_slave_sql_error.inc [errno=1105] -Last_SQL_Error = 'Error 'master may suffer from http://bugs.mysql.com/bug.php?id=24432 so slave stops; check error log on slave for more info' on query. Default database: 'test'. Query: 'INSERT INTO t1(b) VALUES(1),(1),(2) ON DUPLICATE KEY UPDATE t1.b=10'' -SELECT * FROM t1; -a b -stop slave; -include/wait_for_slave_to_stop.inc -reset slave; -reset master; -drop table t1; -start slave; -include/wait_for_slave_to_start.inc CREATE TABLE t1 ( id bigint(20) unsigned NOT NULL auto_increment, field_1 int(10) unsigned NOT NULL, diff --git a/mysql-test/suite/rpl/r/rpl_mdev_17614.result b/mysql-test/suite/rpl/r/rpl_mdev_17614.result new file mode 100644 index 00000000000..28de23e28c9 --- /dev/null +++ b/mysql-test/suite/rpl/r/rpl_mdev_17614.result @@ -0,0 +1,98 @@ +include/master-slave.inc +[connection master] +call mtr.add_suppression("Unsafe statement written to the binary log using statement format"); +CREATE TABLE t1 (a INT NOT NULL PRIMARY KEY , b INT, +UNIQUE(b), c int) engine=innodb; +INSERT INTO t1 VALUES (1, 1, 1); +BEGIN; +INSERT INTO t1 VALUES (2, 1, 2) ON DUPLICATE KEY UPDATE b=VALUES(b), c=VALUES(c); +Warnings: +Note 1592 Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. INSERT... ON DUPLICATE KEY UPDATE on a table with more than one UNIQUE KEY is unsafe +INSERT INTO t1 VALUES(2, 2, 3) ON DUPLICATE KEY UPDATE b=VALUES(b), c=VALUES(c); +Warnings: +Note 1592 Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. INSERT... ON DUPLICATE KEY UPDATE on a table with more than one UNIQUE KEY is unsafe +COMMIT; +SELECT * FROM t1; +a b c +1 1 2 +2 2 3 +include/wait_for_slave_sql_error.inc [errno=1062] +Last_SQL_Error = 'Error 'Duplicate entry '1' for key 'b'' on query. Default database: 'test'. Query: 'INSERT INTO t1 VALUES (2, 1, 2) ON DUPLICATE KEY UPDATE b=VALUES(b), c=VALUES(c)'' +#Different value from server +SELECT * FROM t1; +a b c +1 1 1 +2 2 3 +stop slave; +include/wait_for_slave_to_stop.inc +reset slave; +reset master; +drop table t1; +start slave; +include/wait_for_slave_to_start.inc +CREATE TABLE t1 (a INT NOT NULL PRIMARY KEY auto_increment, b INT, +UNIQUE(b), c int) engine=innodb; +INSERT INTO t1 VALUES (default, 1, 1); +BEGIN; +INSERT INTO t1 VALUES (default, 1, 2) ON DUPLICATE KEY UPDATE b=VALUES(b), c=VALUES(c); +INSERT INTO t1 VALUES(default, 2, 3) ON DUPLICATE KEY UPDATE b=VALUES(b), c=VALUES(c); +COMMIT; +SELECT * FROM t1; +a b c +1 1 2 +3 2 3 +#same data as master +SELECT * FROM t1; +a b c +1 1 2 +3 2 3 +drop table t1; +CREATE TABLE t1 (a INT NOT NULL PRIMARY KEY, b INT, +UNIQUE(b), c int, d int ) engine=innodb; +INSERT INTO t1 VALUES (1, 1, 1, 1); +BEGIN; +INSERT INTO t1 VALUES (2, NULL, 2, 2) ON DUPLICATE KEY UPDATE b=VALUES(b), c=VALUES(c); +Warnings: +Note 1592 Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. INSERT... ON DUPLICATE KEY UPDATE on a table with more than one UNIQUE KEY is unsafe +INSERT INTO t1 VALUES(3, NULL, 2, 3) ON DUPLICATE KEY UPDATE b=VALUES(b), c=VALUES(c); +Warnings: +Note 1592 Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT. INSERT... ON DUPLICATE KEY UPDATE on a table with more than one UNIQUE KEY is unsafe +COMMIT; +SELECT * FROM t1; +a b c d +1 1 1 1 +2 NULL 2 2 +3 NULL 2 3 +#same data as master +SELECT * FROM t1; +a b c d +1 1 1 1 +2 NULL 2 2 +3 NULL 2 3 +drop table t1; +CREATE TABLE t1 (a INT NOT NULL PRIMARY KEY auto_increment, b INT, +UNIQUE(b), c int) engine=innodb; +INSERT INTO t1 VALUES (1, 1, 1); +BEGIN; +INSERT INTO t1 VALUES (2, 1, 2) ON DUPLICATE KEY UPDATE b=VALUES(b), c=VALUES(c); +INSERT INTO t1 VALUES(2, 2, 3) ON DUPLICATE KEY UPDATE b=VALUES(b), c=VALUES(c); +COMMIT; +SELECT * FROM t1; +a b c +1 1 2 +2 2 3 +include/wait_for_slave_sql_error.inc [errno=1062] +Last_SQL_Error = 'Error 'Duplicate entry '1' for key 'b'' on query. Default database: 'test'. Query: 'INSERT INTO t1 VALUES (2, 1, 2) ON DUPLICATE KEY UPDATE b=VALUES(b), c=VALUES(c)'' +#Different value from server +SELECT * FROM t1; +a b c +1 1 1 +2 2 3 +stop slave; +include/wait_for_slave_to_stop.inc +reset slave; +reset master; +drop table t1; +start slave; +include/wait_for_slave_to_start.inc +include/rpl_end.inc diff --git a/mysql-test/suite/rpl/t/rpl_known_bugs_detection.test b/mysql-test/suite/rpl/t/rpl_known_bugs_detection.test index ab263ece407..5ea056d5f14 100644 --- a/mysql-test/suite/rpl/t/rpl_known_bugs_detection.test +++ b/mysql-test/suite/rpl/t/rpl_known_bugs_detection.test @@ -14,45 +14,6 @@ source include/have_binlog_checksum_off.inc; source include/master-slave.inc; -call mtr.add_suppression("Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT."); - -# -# This is to test that slave properly detects if -# master may suffer from: -# BUG#24432 "INSERT... ON DUPLICATE KEY UPDATE skips auto_increment values" -# (i.e. on master, INSERT ON DUPLICATE KEY UPDATE is used and manipulates -# an auto_increment column, and is binlogged statement-based). -# - -# testcase with INSERT VALUES -CREATE TABLE t1 (a INT NOT NULL PRIMARY KEY AUTO_INCREMENT, b INT, -UNIQUE(b)); -sync_slave_with_master; -connection master; -INSERT INTO t1(b) VALUES(1),(1),(2) ON DUPLICATE KEY UPDATE t1.b=10; -SELECT * FROM t1; -connection slave; - -# show the error message -#1105 = ER_UNKNOWN_ERROR ---let $slave_sql_errno= 1105 ---let $show_slave_sql_error= 1 -call mtr.add_suppression("Slave SQL.*suffer.*http:..bugs.mysql.com.bug.php.id=24432"); ---source include/wait_for_slave_sql_error.inc -# show that it was not replicated -SELECT * FROM t1; - -# restart replication for the next testcase -stop slave; ---source include/wait_for_slave_to_stop.inc -reset slave; -connection master; -reset master; -drop table t1; -connection slave; -start slave; ---source include/wait_for_slave_to_start.inc - # testcase with INSERT SELECT connection master; CREATE TABLE t1 ( diff --git a/mysql-test/suite/rpl/t/rpl_mdev_17614.test b/mysql-test/suite/rpl/t/rpl_mdev_17614.test new file mode 100644 index 00000000000..9b86c8c15b5 --- /dev/null +++ b/mysql-test/suite/rpl/t/rpl_mdev_17614.test @@ -0,0 +1,121 @@ +source include/have_debug.inc; +source include/have_innodb.inc; +-- source include/have_binlog_format_statement.inc +source include/master-slave.inc; +# MDEV-17614 +# INSERT on dup key update is replication unsafe +# There can be three case +# 1. 2 unique key, Replication is unsafe. +# 2. 2 unique key , with one auto increment key, Safe to replicate because Innodb will acquire gap lock +# 3. n no of unique keys (n>1) but insert is only in 1 unique key +# 4. 2 unique key , with one auto increment key(but user gives auto inc value), unsafe to replicate + +# Case 1 +call mtr.add_suppression("Unsafe statement written to the binary log using statement format"); +CREATE TABLE t1 (a INT NOT NULL PRIMARY KEY , b INT, +UNIQUE(b), c int) engine=innodb; +sync_slave_with_master; +connection master; +INSERT INTO t1 VALUES (1, 1, 1); +BEGIN; +INSERT INTO t1 VALUES (2, 1, 2) ON DUPLICATE KEY UPDATE b=VALUES(b), c=VALUES(c); + --connection master1 + INSERT INTO t1 VALUES(2, 2, 3) ON DUPLICATE KEY UPDATE b=VALUES(b), c=VALUES(c); +--connection master +COMMIT; +SELECT * FROM t1; +--connection slave +# show the error message +--let $slave_sql_errno= 1062 +--let $show_slave_sql_error= 1 +--source include/wait_for_slave_sql_error.inc +--echo #Different value from server +SELECT * FROM t1; + +# restart replication for the next testcase +stop slave; +--source include/wait_for_slave_to_stop.inc +reset slave; +connection master; +reset master; +drop table t1; +connection slave; +start slave; +--source include/wait_for_slave_to_start.inc +# Case 2 +--connection master +CREATE TABLE t1 (a INT NOT NULL PRIMARY KEY auto_increment, b INT, +UNIQUE(b), c int) engine=innodb; +sync_slave_with_master; +connection master; +INSERT INTO t1 VALUES (default, 1, 1); +BEGIN; +INSERT INTO t1 VALUES (default, 1, 2) ON DUPLICATE KEY UPDATE b=VALUES(b), c=VALUES(c); + --connection master1 + INSERT INTO t1 VALUES(default, 2, 3) ON DUPLICATE KEY UPDATE b=VALUES(b), c=VALUES(c); +--connection master +COMMIT; +SELECT * FROM t1; +--sync_slave_with_master +--echo #same data as master +SELECT * FROM t1; + +connection master; +drop table t1; +--sync_slave_with_master + +# Case 3 +--connection master +CREATE TABLE t1 (a INT NOT NULL PRIMARY KEY, b INT, +UNIQUE(b), c int, d int ) engine=innodb; +sync_slave_with_master; +connection master; +INSERT INTO t1 VALUES (1, 1, 1, 1); +BEGIN; +INSERT INTO t1 VALUES (2, NULL, 2, 2) ON DUPLICATE KEY UPDATE b=VALUES(b), c=VALUES(c); + --connection master1 + INSERT INTO t1 VALUES(3, NULL, 2, 3) ON DUPLICATE KEY UPDATE b=VALUES(b), c=VALUES(c); +--connection master +COMMIT; +SELECT * FROM t1; +--sync_slave_with_master +--echo #same data as master +SELECT * FROM t1; +connection master; +drop table t1; +--sync_slave_with_master + +# Case 4 +--connection master +CREATE TABLE t1 (a INT NOT NULL PRIMARY KEY auto_increment, b INT, +UNIQUE(b), c int) engine=innodb; +sync_slave_with_master; +connection master; +INSERT INTO t1 VALUES (1, 1, 1); +BEGIN; +INSERT INTO t1 VALUES (2, 1, 2) ON DUPLICATE KEY UPDATE b=VALUES(b), c=VALUES(c); + --connection master1 + INSERT INTO t1 VALUES(2, 2, 3) ON DUPLICATE KEY UPDATE b=VALUES(b), c=VALUES(c); +--connection master +COMMIT; +SELECT * FROM t1; +--connection slave +# show the error message +--let $slave_sql_errno= 1062 +--let $show_slave_sql_error= 1 +--source include/wait_for_slave_sql_error.inc +--echo #Different value from server +SELECT * FROM t1; + +# restart replication for the next testcase +stop slave; +--source include/wait_for_slave_to_stop.inc +reset slave; +connection master; +reset master; +drop table t1; +connection slave; +start slave; +--source include/wait_for_slave_to_start.inc + +--source include/rpl_end.inc diff --git a/sql/sql_class.cc b/sql/sql_class.cc index 6bcff6d1fca..b9c499e9db7 100644 --- a/sql/sql_class.cc +++ b/sql/sql_class.cc @@ -6144,6 +6144,48 @@ int THD::decide_logging_format(TABLE_LIST *tables) DBUG_RETURN(0); } +int THD::decide_logging_format_2(TABLE *table) +{ + /* + INSERT...ON DUPLICATE KEY UPDATE on a table with more than one unique keys + can be unsafe. + */ + if(wsrep_binlog_format() <= BINLOG_FORMAT_STMT && + !is_current_stmt_binlog_format_row() && + !lex->is_stmt_unsafe() && + lex->sql_command == SQLCOM_INSERT && + lex->duplicates == DUP_UPDATE) + { + uint unique_keys= 0; + uint keys= table->s->keys, i= 0; + Field *field; + for (KEY* keyinfo= table->s->key_info; + i < keys && unique_keys <= 1; i++, keyinfo++) + if (keyinfo->flags & HA_NOSAME && + !(keyinfo->key_part->field->flags & AUTO_INCREMENT_FLAG && + //User given auto inc can be unsafe + !keyinfo->key_part->field->val_int())) + { + for (uint j= 0; j < keyinfo->user_defined_key_parts; j++) + { + field= keyinfo->key_part[j].field; + if(!bitmap_is_set(table->write_set,field->field_index)) + goto exit; + } + unique_keys++; +exit:; + } + + if (unique_keys > 1) + { + lex->set_stmt_unsafe(LEX::BINLOG_STMT_UNSAFE_INSERT_TWO_KEYS); + binlog_unsafe_warning_flags|= lex->get_stmt_unsafe_flags(); + set_current_stmt_binlog_format_row_if_mixed(); + return 1; + } + } + return 0; +} /* Implementation of interface to write rows to the binary log through the diff --git a/sql/sql_class.h b/sql/sql_class.h index e3bc572ed0c..260cf8039ea 100644 --- a/sql/sql_class.h +++ b/sql/sql_class.h @@ -2208,6 +2208,20 @@ class THD :public Statement, /* container for handler's private per-connection data */ Ha_data ha_data[MAX_HA]; + /** + Bit field for the state of binlog warnings. + + The first Lex::BINLOG_STMT_UNSAFE_COUNT bits list all types of + unsafeness that the current statement has. + + This must be a member of THD and not of LEX, because warnings are + detected and issued in different places (@c + decide_logging_format() and @c binlog_query(), respectively). + Between these calls, the THD->lex object may change; e.g., if a + stored routine is invoked. Only THD persists between the calls. + */ + uint32 binlog_unsafe_warning_flags; + #ifndef MYSQL_CLIENT binlog_cache_mngr * binlog_setup_trx_data(); @@ -2317,20 +2331,6 @@ class THD :public Statement, */ enum_binlog_format current_stmt_binlog_format; - /** - Bit field for the state of binlog warnings. - - The first Lex::BINLOG_STMT_UNSAFE_COUNT bits list all types of - unsafeness that the current statement has. - - This must be a member of THD and not of LEX, because warnings are - detected and issued in different places (@c - decide_logging_format() and @c binlog_query(), respectively). - Between these calls, the THD->lex object may change; e.g., if a - stored routine is invoked. Only THD persists between the calls. - */ - uint32 binlog_unsafe_warning_flags; - /* Number of outstanding table maps, i.e., table maps in the transaction cache. @@ -3939,6 +3939,18 @@ class THD :public Statement, } void leave_locked_tables_mode(); int decide_logging_format(TABLE_LIST *tables); + /* + In Some cases when decide_logging_format is called it does not have all + information to decide the logging format. So that cases we call decide_logging_format_2 + at later stages in execution. + One example would be binlog format for IODKU but column with unique key is not inserted. + We dont have inserted columns info when we call decide_logging_format so on later stage we call + decide_logging_format_2 + + @returns 0 if no format is changed + 1 if there is change in binlog format + */ + int decide_logging_format_2(TABLE *table); enum need_invoker { INVOKER_NONE=0, INVOKER_USER, INVOKER_ROLE}; void binlog_invoker(bool role) { m_binlog_invoker= role ? INVOKER_ROLE : INVOKER_USER; } diff --git a/sql/sql_insert.cc b/sql/sql_insert.cc index da76f10596d..30df68d8c6e 100644 --- a/sql/sql_insert.cc +++ b/sql/sql_insert.cc @@ -1025,6 +1025,7 @@ bool mysql_insert(THD *thd,TABLE_LIST *table_list, error= 1; break; } + thd->decide_logging_format_2(table); #ifndef EMBEDDED_LIBRARY if (lock_type == TL_WRITE_DELAYED) {

1 0

[Commits] fb619954867: MDEV-15010: Wrong Seconds_Behind_Master when only starting the SQL_Thread
by sujatha 16 Jul '19

16 Jul '19

revision-id: fb619954867232b3a733213a2703b2a425dff8e9 (mariadb-5.5.64-19-gfb619954867) parent(s): 7a7d9904e12335ee8b1eea9671138b3c469a3829 author: Sujatha committer: Sujatha timestamp: 2019-06-19 14:48:18 +0530 message: MDEV-15010: Wrong Seconds_Behind_Master when only starting the SQL_Thread Problem: ======= When I run replication normally, I get a value in "Seconds_Behind_Master" from "SHOW SLAVE STATUS". However, when I run only the SQL Thread (on local relay logs that have been downloaded previously), I have "NULL" in "Seconds_Behind_Master". I would expect to have a numeric value. Fix: === Implemented following changes. case 1: "Seconds_Behind_Master" shows 0, when SQL thread is in sync with IO thread and IO thread is running. case 2: "Seconds_Behind_Master" reports NULL, when SQL thread is in sync with IO thread and IO thread is stopped. case 3: "Seconds_Behind_Master" reports NULL, when SQL thread is stopped while IO thread is up and running. case 4: "Seconds_Behind_Master" reports a valid numerical value when IO thread is stopped and SQL thread is consuming existing relay log. --- .../suite/rpl/r/rpl_seconds_behind_master.result | 40 ++++++++++ .../suite/rpl/t/rpl_seconds_behind_master.test | 92 ++++++++++++++++++++++ sql/slave.cc | 82 ++++++++++++------- 3 files changed, 187 insertions(+), 27 deletions(-) diff --git a/mysql-test/suite/rpl/r/rpl_seconds_behind_master.result b/mysql-test/suite/rpl/r/rpl_seconds_behind_master.result new file mode 100644 index 00000000000..1c0ce7c1b19 --- /dev/null +++ b/mysql-test/suite/rpl/r/rpl_seconds_behind_master.result @@ -0,0 +1,40 @@ +include/master-slave.inc +[connection master] +CREATE TABLE t1 (a INT PRIMARY KEY, b INT); +****************************************************************** +* Case1: SQL thread is in sync with IO thread and IO thread is UP +* Seconds_Behind_Master should be '0'. +****************************************************************** +include/assert.inc [Seconds_Behind_Master should be 0] +****************************************************************** +* Case2: SQL thread is in sync with IO thread and IO thread is +* stopped. +* Seconds_Behind_Master should be 'NULL'. +****************************************************************** +include/stop_slave_io.inc +include/assert.inc [Seconds_Behind_Master should be NULL] +****************************************************************** +* Case3: SQL thread is stopped while IO thread is up and running. +* Seconds_Behind_Master should be 'NULL'. +****************************************************************** +START SLAVE IO_THREAD; +include/wait_for_slave_io_to_start.inc +include/stop_slave_sql.inc +include/assert.inc [Seconds_Behind_Master should be NULL] +****************************************************************** +* Case4: IO thread is stopped. SQL thread is consuming existing relay +* log. Hence the Seconds_Behind_Master should have a numeric +* value > 0 +****************************************************************** +INSERT INTO t1 VALUES (1,sleep(2)); +INSERT INTO t1 VALUES (2,sleep(2)); +include/sync_slave_io_with_master.inc +include/stop_slave_io.inc +START SLAVE SQL_THREAD; +include/wait_for_slave_sql_to_start.inc +include/assert.inc [Seconds_Behind_Master should be > 0] +START SLAVE IO_THREAD; +include/wait_for_slave_io_to_start.inc +******* CLEANUP ********* +DROP TABLE t1; +include/rpl_end.inc diff --git a/mysql-test/suite/rpl/t/rpl_seconds_behind_master.test b/mysql-test/suite/rpl/t/rpl_seconds_behind_master.test new file mode 100644 index 00000000000..6f9ed2939e1 --- /dev/null +++ b/mysql-test/suite/rpl/t/rpl_seconds_behind_master.test @@ -0,0 +1,92 @@ +# ==== Purpose ==== +# +# Test verifies that Seconds_Behind_Master(SBM) values are as expected in various +# scenario listed below. +# +# case 1: SBM=0 if SQL thread is in sync with IO thread and IO thread is UP +# case 2: SBM=NULL if SQL thread is in sync with IO thread and IO thread is +# stopped. +# case 3: SBM=NULL if SQL thread is stopped while IO thread is up and running. +# case 4: SBM > 0 and SBM != NULL if IO thread is stopped. SQL thread is +# consuming existing relay log. +# +# ==== Implementation ==== +# +# Steps: +# 1 - Create a table and sync it with slave and verify SBM value. +# 2 - Now stop IO thread and verify SBM +# 3 - Start IO thread, Stop SQL thread and verify SBM +# 4 - Execute slow INSERT statements with SLEEP(2) on master. Ensure that +# the IO thread has read these INSERT statements and then bring it down. +# 5 - Start the SQL thread and verify that while it is trying to consume +# these slow INSERT statements in relay log the SBM value is > 0. +# +# ==== References ==== +# +# MDEV-15010: Wrong Seconds_Behind_Master when only starting the SQL_Thread. + +--source include/have_binlog_format_statement.inc +--source include/master-slave.inc + +--disable_query_log +CALL mtr.add_suppression("Unsafe statement written to the binary log using statement format since BINLOG_FORMAT = STATEMENT"); +--enable_query_log + +CREATE TABLE t1 (a INT PRIMARY KEY, b INT); +--sync_slave_with_master + +-- echo ****************************************************************** +-- echo * Case1: SQL thread is in sync with IO thread and IO thread is UP +-- echo * Seconds_Behind_Master should be '0'. +-- echo ****************************************************************** +--let $assert_cond= [SHOW SLAVE STATUS, Seconds_Behind_Master, 1] = 0 +--let $assert_text= Seconds_Behind_Master should be 0 +--source include/assert.inc + +-- echo ****************************************************************** +-- echo * Case2: SQL thread is in sync with IO thread and IO thread is +-- echo * stopped. +-- echo * Seconds_Behind_Master should be 'NULL'. +-- echo ****************************************************************** +--source include/stop_slave_io.inc +--let $assert_cond= "[SHOW SLAVE STATUS, Seconds_Behind_Master, 1]" = "NULL" +--let $assert_text= Seconds_Behind_Master should be NULL +--source include/assert.inc + +-- echo ****************************************************************** +-- echo * Case3: SQL thread is stopped while IO thread is up and running. +-- echo * Seconds_Behind_Master should be 'NULL'. +-- echo ****************************************************************** +START SLAVE IO_THREAD; +--source include/wait_for_slave_io_to_start.inc +--source include/stop_slave_sql.inc +--let $assert_cond= "[SHOW SLAVE STATUS, Seconds_Behind_Master, 1]" = "NULL" +--let $assert_text= Seconds_Behind_Master should be NULL +--source include/assert.inc + +-- echo ****************************************************************** +-- echo * Case4: IO thread is stopped. SQL thread is consuming existing relay +-- echo * log. Hence the Seconds_Behind_Master should have a numeric +-- echo * value > 0 +-- echo ****************************************************************** +--connection master +--disable_warnings +INSERT INTO t1 VALUES (1,sleep(2)); +INSERT INTO t1 VALUES (2,sleep(2)); +--enable_warnings +--source include/sync_slave_io_with_master.inc +--source include/stop_slave_io.inc + +START SLAVE SQL_THREAD; +--source include/wait_for_slave_sql_to_start.inc +--let $assert_cond= [SHOW SLAVE STATUS, Seconds_Behind_Master, 1] > 0 +--let $assert_text= Seconds_Behind_Master should be > 0 +--source include/assert.inc +START SLAVE IO_THREAD; +--source include/wait_for_slave_io_to_start.inc + +--echo ******* CLEANUP ********* +--connection master +DROP TABLE t1; + +--source include/rpl_end.inc diff --git a/sql/slave.cc b/sql/slave.cc index a8946c69d18..7b4b7bd857e 100644 --- a/sql/slave.cc +++ b/sql/slave.cc @@ -2192,38 +2192,66 @@ bool show_master_info(THD* thd, Master_info* mi) protocol->store(mi->ssl_cert, &my_charset_bin); protocol->store(mi->ssl_cipher, &my_charset_bin); protocol->store(mi->ssl_key, &my_charset_bin); - /* - Seconds_Behind_Master: if SQL thread is running and I/O thread is - connected, we can compute it otherwise show NULL (i.e. unknown). + The pseudo code to compute Seconds_Behind_Master: + if (SQL thread is running) + { + if (SQL thread processed all the available relay log) + { + if (IO thread is running) + print 0; + else + print NULL; + } + else + compute Seconds_Behind_Master; + } + else + print NULL; */ - if ((mi->slave_running == MYSQL_SLAVE_RUN_CONNECT) && - mi->rli.slave_running) + if (mi->rli.slave_running) { - long time_diff= ((long)(time(0) - mi->rli.last_master_timestamp) - - mi->clock_diff_with_master); /* - Apparently on some systems time_diff can be <0. Here are possible - reasons related to MySQL: - - the master is itself a slave of another master whose time is ahead. - - somebody used an explicit SET TIMESTAMP on the master. - Possible reason related to granularity-to-second of time functions - (nothing to do with MySQL), which can explain a value of -1: - assume the master's and slave's time are perfectly synchronized, and - that at slave's connection time, when the master's timestamp is read, - it is at the very end of second 1, and (a very short time later) when - the slave's timestamp is read it is at the very beginning of second - 2. Then the recorded value for master is 1 and the recorded value for - slave is 2. At SHOW SLAVE STATUS time, assume that the difference - between timestamp of slave and rli->last_master_timestamp is 0 - (i.e. they are in the same second), then we get 0-(2-1)=-1 as a result. - This confuses users, so we don't go below 0: hence the max(). - - last_master_timestamp == 0 (an "impossible" timestamp 1970) is a - special marker to say "consider we have caught up". + Check if SQL thread is at the end of relay log + Checking should be done using two conditions + condition1: compare the log positions and + condition2: compare the file names (to handle rotation case) */ - protocol->store((longlong)(mi->rli.last_master_timestamp ? - max(0, time_diff) : 0)); + if ((mi->master_log_pos == mi->rli.group_master_log_pos) && + (!strcmp(mi->master_log_name, mi->rli.group_master_log_name))) + { + if (mi->slave_running == MYSQL_SLAVE_RUN_CONNECT) + protocol->store(0LL); + else + protocol->store_null(); + } + else + { + long time_diff = ((long)(time(0) - mi->rli.last_master_timestamp) + - mi->clock_diff_with_master); + /* + Apparently on some systems time_diff can be <0. Here are possible + reasons related to MySQL: + - the master is itself a slave of another master whose time is ahead. + - somebody used an explicit SET TIMESTAMP on the master. + Possible reason related to granularity-to-second of time functions + (nothing to do with MySQL), which can explain a value of -1: + assume the master's and slave's time are perfectly synchronized, and + that at slave's connection time, when the master's timestamp is read, + it is at the very end of second 1, and (a very short time later) when + the slave's timestamp is read it is at the very beginning of second + 2. Then the recorded value for master is 1 and the recorded value for + slave is 2. At SHOW SLAVE STATUS time, assume that the difference + between timestamp of slave and rli->last_master_timestamp is 0 + (i.e. they are in the same second), then we get 0-(2-1)=-1 as a result. + This confuses users, so we don't go below 0: hence the max(). + + last_master_timestamp == 0 (an "impossible" timestamp 1970) is a + special marker to say "consider we have caught up". + */ + protocol->store((longlong)(mi->rli.last_master_timestamp ? + max(0, time_diff) : 0)); + } } else {

2 1

[Commits] 52f6aa1c548: Disable rocksdb_rpl.rpl_gtid_crash_safe_optimized
by Sergei Petrunia 16 Jul '19

16 Jul '19

revision-id: 52f6aa1c548b80cb93f9ec49c85adb843f7a5082 (mariadb-10.2.25-74-g52f6aa1c548) parent(s): a2dc3b94617fd6e3ed9d7d0ea36f8dc845832419 author: Sergei Petrunia committer: Sergei Petrunia timestamp: 2019-07-16 18:42:19 +0300 message: Disable rocksdb_rpl.rpl_gtid_crash_safe_optimized It uses slave_gtid_info=optimized which is not supported in MariaDB --- storage/rocksdb/mysql-test/rocksdb_rpl/t/disabled.def | 1 + 1 file changed, 1 insertion(+) diff --git a/storage/rocksdb/mysql-test/rocksdb_rpl/t/disabled.def b/storage/rocksdb/mysql-test/rocksdb_rpl/t/disabled.def index 05e5ae0ed46..2147e3e086d 100644 --- a/storage/rocksdb/mysql-test/rocksdb_rpl/t/disabled.def +++ b/storage/rocksdb/mysql-test/rocksdb_rpl/t/disabled.def @@ -12,6 +12,7 @@ singledelete_idempotent_recovery: MariaDB doesn't support --slave-use-idempotent rpl_mts_dependency_unique_key_conflicts: MariaDB doesn't support --slave-use-idempotent-for-recovery rpl_missing_columns_sk_update : Uses log_column_names=ON feature which is only present in FB/MySQL optimize_myrocks_replace_into: requires @@enable_blind_replace support. +rpl_gtid_crash_safe_optimized: requires slave_gtid_info=optimized ## ## Tests that do not fit MariaDB's test environment (Functional tests only,

1 0

[Commits] a2dc3b94617: Disable rocksdb_rpl.optimize_myrocks_replace_into
by Sergei Petrunia 16 Jul '19

16 Jul '19

revision-id: a2dc3b94617fd6e3ed9d7d0ea36f8dc845832419 (mariadb-10.2.25-73-ga2dc3b94617) parent(s): e9a191837671442260426f256c4c3ab5c073b40a author: Sergei Petrunia committer: Sergei Petrunia timestamp: 2019-07-16 17:16:59 +0300 message: Disable rocksdb_rpl.optimize_myrocks_replace_into It requires @@enable_blind_replace which MariaDB doesn't support --- storage/rocksdb/mysql-test/rocksdb_rpl/t/disabled.def | 1 + 1 file changed, 1 insertion(+) diff --git a/storage/rocksdb/mysql-test/rocksdb_rpl/t/disabled.def b/storage/rocksdb/mysql-test/rocksdb_rpl/t/disabled.def index b0fc68b84b2..05e5ae0ed46 100644 --- a/storage/rocksdb/mysql-test/rocksdb_rpl/t/disabled.def +++ b/storage/rocksdb/mysql-test/rocksdb_rpl/t/disabled.def @@ -11,6 +11,7 @@ rpl_gtid_rocksdb_sys_header : MariaDB doesn't support printing "RocksDB: Last My singledelete_idempotent_recovery: MariaDB doesn't support --slave-use-idempotent-for-recovery rpl_mts_dependency_unique_key_conflicts: MariaDB doesn't support --slave-use-idempotent-for-recovery rpl_missing_columns_sk_update : Uses log_column_names=ON feature which is only present in FB/MySQL +optimize_myrocks_replace_into: requires @@enable_blind_replace support. ## ## Tests that do not fit MariaDB's test environment (Functional tests only,

1 0

[Commits] e9a19183767: Disable rocksdb.rpl_row_not_found
by Sergei Petrunia 16 Jul '19

16 Jul '19

revision-id: e9a191837671442260426f256c4c3ab5c073b40a (mariadb-10.2.25-72-ge9a19183767) parent(s): 612f4908d2f048ef5db45b184875af8d21c9fd4d author: Sergei Petrunia committer: Sergei Petrunia timestamp: 2019-07-16 16:50:05 +0300 message: Disable rocksdb.rpl_row_not_found It requires slave_exec_mode='SEMI_STRICT' --- storage/rocksdb/mysql-test/rocksdb/t/disabled.def | 2 ++ 1 file changed, 2 insertions(+) diff --git a/storage/rocksdb/mysql-test/rocksdb/t/disabled.def b/storage/rocksdb/mysql-test/rocksdb/t/disabled.def index 45e19bf88e8..7847815c6c9 100644 --- a/storage/rocksdb/mysql-test/rocksdb/t/disabled.def +++ b/storage/rocksdb/mysql-test/rocksdb/t/disabled.def @@ -70,6 +70,8 @@ gap_lock_raise_error: MDEV-11735: MyRocks: Gap Lock detector support show_engine : MariaRocks: MariaDB doesnt support SHOW ENGINE rocksdb TRANSACTION STATUS issue243_transactionStatus: MariaDB doesnt support SHOW ENGINE rocksdb TRANSACTION STATUS rpl_row_not_found : MariaDB doesnt support slave_exec_mode='SEMI_STRICT' +rpl_row_not_found_rc : MariaDB doesnt support slave_exec_mode='SEMI_STRICT' + ddl_high_priority: Needs fractional @@lock_wait_timeout deadlock_tracking : Needs SHOW ENGINE ROCKSDB TRANSACTION STATUS bytes_written: Needs I_S.TABLE_STATISTICS.IO_WRITE_BYTES

1 0

[Commits] 7cabdc461b2: MDEV-6860 Parallel async replication hangs on a Galera node
by sachin.setiya＠mariadb.com 15 Jul '19

15 Jul '19

revision-id: 7cabdc461b24fdebe599799d7964efa4b53815e3 (mariadb-10.1.39-91-g7cabdc461b2) parent(s): bdc961acc7ae9d5a3661ac425e936cd03dc5ccbb author: Sachin committer: Sachin timestamp: 2019-07-15 14:04:22 +0530 message: MDEV-6860 Parallel async replication hangs on a Galera node Wait for previous commit beore preparing next transation for galera (TODO a better commit message) --- mysql-test/suite/galera/r/6860.result | 40 +++++++++++++++++ mysql-test/suite/galera/t/6860.cnf | 4 ++ mysql-test/suite/galera/t/6860.test | 81 +++++++++++++++++++++++++++++++++++ sql/rpl_parallel.cc | 2 +- 4 files changed, 126 insertions(+), 1 deletion(-) diff --git a/mysql-test/suite/galera/r/6860.result b/mysql-test/suite/galera/r/6860.result new file mode 100644 index 00000000000..5c9c2d9a3bb --- /dev/null +++ b/mysql-test/suite/galera/r/6860.result @@ -0,0 +1,40 @@ +include/start_slave.inc +CREATE TABLE t1 (f1 int, f2 int) ENGINE=innodb; +CREATE TABLE t2 (f1 int, f2 int) ENGINE=innodb; +SET SESSION debug_dbug="+d,binlog_force_commit_id"; +set global binlog_commit_wait_usec=1000; +set global binlog_commit_wait_count=2; +SELECT COUNT(*) FROM t1; +COUNT(*) +500 +include/save_master_gtid.inc +#NODE 2 +include/sync_with_master_gtid.inc +SELECT COUNT(*) FROM t1; +COUNT(*) +500 +include/stop_slave.inc +set global slave_parallel_mode=optimistic; +include/start_slave.inc +set global binlog_commit_wait_usec=100000; +set global binlog_commit_wait_count=0; +SELECT COUNT(*) FROM t1; +COUNT(*) +1000 +include/save_master_gtid.inc +#NODE 2 +include/sync_with_master_gtid.inc +SELECT COUNT(*) FROM t1; +COUNT(*) +1000 +#NODE 3 +SELECT COUNT(*) FROM t1; +COUNT(*) +1000 +DROP TABLE t1; +DROP TABLE t2; +include/save_master_gtid.inc +include/sync_with_master_gtid.inc +STOP SLAVE; +RESET SLAVE ALL; +set global slave_parallel_mode=conservative; diff --git a/mysql-test/suite/galera/t/6860.cnf b/mysql-test/suite/galera/t/6860.cnf new file mode 100644 index 00000000000..1bd1adc305a --- /dev/null +++ b/mysql-test/suite/galera/t/6860.cnf @@ -0,0 +1,4 @@ +!include ../galera_2nodes_as_slave.cnf + +[mysqld.2] +slave-parallel-threads=10 diff --git a/mysql-test/suite/galera/t/6860.test b/mysql-test/suite/galera/t/6860.test new file mode 100644 index 00000000000..21b5e4f0fbb --- /dev/null +++ b/mysql-test/suite/galera/t/6860.test @@ -0,0 +1,81 @@ +--source include/have_innodb.inc +--source include/have_debug.inc + +--connect node_2a, 127.0.0.1, root, , test, $NODE_MYPORT_2 +--source include/galera_cluster.inc + +--connection node_2 +--disable_query_log +--eval CHANGE MASTER TO MASTER_HOST='127.0.0.1', MASTER_USER='root', MASTER_PORT=$NODE_MYPORT_1, MASTER_USE_GTID=slave_pos; +#--query_vertical SHOW SLAVE STATUS +--enable_query_log +--source include/start_slave.inc +--connect node_3, 127.0.0.1, root, , test, $NODE_MYPORT_3 + +--connection node_1 +CREATE TABLE t1 (f1 int, f2 int) ENGINE=innodb; +CREATE TABLE t2 (f1 int, f2 int) ENGINE=innodb; + +--let $inserts=500 +--let $count=0 +SET SESSION debug_dbug="+d,binlog_force_commit_id"; +set global binlog_commit_wait_usec=1000; +set global binlog_commit_wait_count=2; +--disable_query_log +while($count < $inserts) +{ + --eval SET @commit_id= 10000+$count; + --eval insert into t1 values ($count,1) + --eval insert into t2 values ($count,1) + --inc $count +} +--enable_query_log +SELECT COUNT(*) FROM t1; +--source include/save_master_gtid.inc + +--connection node_2 +--echo #NODE 2 +--source include/sync_with_master_gtid.inc +SELECT COUNT(*) FROM t1; +--source include/stop_slave.inc +set global slave_parallel_mode=optimistic; +--source include/start_slave.inc + +--connection node_1 +set global binlog_commit_wait_usec=100000; +set global binlog_commit_wait_count=0; +--disable_query_log +--let $count=0 +while($count < $inserts) +{ + --eval SET @commit_id= 10500 + $count; + --eval insert into t1 values (500 + $count,1) + --eval insert into t2 values (500 + $count,1) + --inc $count +} +--enable_query_log +SELECT COUNT(*) FROM t1; +--source include/save_master_gtid.inc + +--connection node_2 +--echo #NODE 2 +--source include/sync_with_master_gtid.inc +SELECT COUNT(*) FROM t1; + +--connection node_3 +--echo #NODE 3 +--let $wait_condition= SELECT COUNT(*)=1000 from t1; +--source include/wait_condition.inc +SELECT COUNT(*) FROM t1; + +--connection node_1 +DROP TABLE t1; +DROP TABLE t2; +--source include/save_master_gtid.inc + +--connection node_2 +--source include/sync_with_master_gtid.inc + +STOP SLAVE; +RESET SLAVE ALL; +set global slave_parallel_mode=conservative; diff --git a/sql/rpl_parallel.cc b/sql/rpl_parallel.cc index 8fef2d66635..7d38c36b840 100644 --- a/sql/rpl_parallel.cc +++ b/sql/rpl_parallel.cc @@ -1181,7 +1181,7 @@ handle_rpl_parallel_thread(void *arg) before, then wait now for the prior transaction to complete its commit. */ - if (rgi->speculation == rpl_group_info::SPECULATE_WAIT && + if ((rgi->speculation == rpl_group_info::SPECULATE_WAIT || WSREP_ON) && (err= thd->wait_for_prior_commit())) { slave_output_error_info(rgi, thd);

1 0

[Commits] 57659c37d: MDEV-19986: MyRocks: Range Locking: SeekForUpdate support: backward scans
by Sergei Petrunia 14 Jul '19

14 Jul '19

revision-id: 57659c37daab6048c7d7ec4a6434b39182bd8825 (v5.8-1044-g57659c37d) parent(s): cba804d57d693e5cf7763d404f29d2483992f96a author: Sergei Petrunia committer: Sergei Petrunia timestamp: 2019-07-14 23:19:46 +0300 message: MDEV-19986: MyRocks: Range Locking: SeekForUpdate support: backward scans Add support for backward scans. --- utilities/transactions/pessimistic_transaction.cc | 179 +++++++++++++++------- 1 file changed, 123 insertions(+), 56 deletions(-) diff --git a/utilities/transactions/pessimistic_transaction.cc b/utilities/transactions/pessimistic_transaction.cc index cbac16437..1d46436e7 100644 --- a/utilities/transactions/pessimistic_transaction.cc +++ b/utilities/transactions/pessimistic_transaction.cc @@ -97,19 +97,17 @@ class LockingIterator : public Iterator { // Note: MyRocks doesn't ever call these: virtual void SeekToFirst() override; - virtual void SeekToLast() override { assert(0); } + virtual void SeekToLast() override; virtual void Seek(const Slice& target) override; // Position at the last key in the source that at or before target. // The iterator is Valid() after this call iff the source contains // an entry that comes at or before target. - virtual void SeekForPrev(const Slice& target) { assert(0); } + virtual void SeekForPrev(const Slice& target) override; virtual void Next() override; - virtual void Prev() override { - assert(0); // TODO: implement this - } + virtual void Prev() override; virtual Slice key() const override { assert(Valid()); @@ -125,8 +123,74 @@ class LockingIterator : public Iterator { return status_; } -private: - void ScanForward(const Slice& target, bool call_next); + private: + + template <bool forward> void Scan(const Slice& target, bool call_next) { + if (!iter_->Valid()) { + status_ = iter_->status(); + return; + } + + while (1) { + /* + note: the underlying iterator checks iterator bounds, so we don't need + to check them here + */ + auto end_key = iter_->key(); + if (forward) + status_ = txn_->GetRangeLock(cfh_, Endpoint(target), Endpoint(end_key)); + else + status_ = txn_->GetRangeLock(cfh_, Endpoint(end_key), Endpoint(target)); + + if (!status_.ok()) { + // Failed to get a lock (most likely lock wait timeout) + return; + } + + //Ok, now we have a lock which is inhibiting modifications in the range + // Somebody might have done external modifications, though: + // - removed the key we've found + // - added a key before that key. + if (forward) + iter_->Seek(target); + else + iter_->SeekForPrev(target); + + if (call_next && iter_->Valid()) { + if (forward) + iter_->Next(); + else + iter_->Prev(); + } + + if (iter_->Valid()) { + int invert= forward? 1 : -1; + if (cfh_->GetComparator()->Compare(iter_->key(), end_key) * invert <= 0) { + // Ok, the key is within the range. + status_ = Status::OK(); + break; + } else { + // We've got a row but it is outside the range we've locked. + // Re-try the lock-and-read step. + continue; + } + } else { + // There's no row (within the iterator bounds perhaps). Exit now. + // (we might already have locked a range in this function but there's + // nothing we can do about it) + status_ = iter_->status(); + break; + } + } + } + + inline void ScanForward(const Slice& target, bool call_next) { + Scan<true>(target, call_next); + } + + inline void ScanBackward(const Slice& target, bool call_next) { + Scan<false>(target, call_next); + } }; @@ -145,15 +209,30 @@ Iterator* PessimisticTransaction::GetLockingIterator( return nullptr; } +/* + @brief + Seek to the first key K that is equal or greater than target, + locking the range [target; K]. +*/ void LockingIterator::Seek(const Slice& target) { iter_->Seek(target); ScanForward(target, false); } +void LockingIterator::SeekForPrev(const Slice& target) { + iter_->SeekForPrev(target); + ScanBackward(target, false); +} + /* - Lock from the current position up to the next key - (This is basically like Seek(right_after(current_position)) + @brief + Move the iterator to the next key, locking the range between the current + and the next key. + + @detail + Implementation is similar to Seek(next_key). Since we don't know what the + next_key is, we reach it by calling { Seek(current_key); Next(); } */ void LockingIterator::Next() { assert(Valid()); @@ -165,65 +244,53 @@ void LockingIterator::Next() { ScanForward(Slice(current_key), true); } -// Note: MyRocks never uses this as call as it has index_nr as prefix for all -// keys. -void LockingIterator::SeekToFirst() { +/* + @brief + Move the iterator to the previous key, locking the range between the current + and the previous key. +*/ - iter_->SeekToFirst(); - if (!iter_->Valid()) { - status_ = iter_->status(); - return; - } +void LockingIterator::Prev() { + assert(Valid()); std::string current_key = iter_->key().ToString(); - ScanForward(Slice(current_key), true); + iter_->Prev(); + ScanBackward(Slice(current_key), true); } -void LockingIterator::ScanForward(const Slice& target, bool call_next) { +/* + @detail + Ideally, this function should + - find the first key $first_key + - lock the range [-inf; $first_key] + - return, the iterator is positioned on $first_key + + The problem here is that we cannot have "-infinity" bound. + + Note: we don't have a practical use for this function - MyRocks always + searches within one index_name.table_name, which means we are only looking + at the keys with index_number as the prefix. +*/ + +void LockingIterator::SeekToFirst() { + iter_->SeekToFirst(); if (!iter_->Valid()) { status_ = iter_->status(); return; } - while (1) { - /* - TODO: the underlying iterator respects iterator bounds, so we don't need - to check them here - */ - auto end_key = iter_->key(); - status_ = txn_->GetRangeLock(cfh_, Endpoint(target), Endpoint(end_key)); - if (!status_.ok()) { - // Failed to get a lock (most likely lock wait timeout) - return; - } + std::string current_key = iter_->key().ToString(); + ScanForward(Slice(current_key), true); +} - //Ok, now we have a lock which is inhibiting modifications in the range - // Somebody might have done external modifications, though: - // - removed the key we've found - // - added a key before that key. - iter_->Seek(target); - if (call_next && iter_->Valid()) - iter_->Next(); - - if (iter_->Valid()) { - if (cfh_->GetComparator()->Compare(iter_->key(), end_key) <= 0) { - // Ok, the key is within the range. - status_ = Status::OK(); - break; - } else { - // We've got a row but it is outside the range we've locked. - // Re-try the lock-and-read step. - continue; - } - } else { - // There's no row (within the iterator bounds perhaps). Exit now. - // (we might already have locked a range in this function but there's - // nothing we can do about it) - status_ = iter_->status(); - break; - } - } +/* + @detail + See SeekToFirst. +*/ + +void LockingIterator::SeekToLast() { + status_ = Status::NotSupported("Not implemented"); } /////////////////////////////////////////////////////////////////////////////

1 0