[MDEV-22964] main.mysqlbinlog_row_compressed fails with wrong result Created: 2020-06-19  Updated: 2020-06-19

Status: Open
Project: MariaDB Server
Component/s: Tests
Affects Version/s: 10.5
Fix Version/s: 10.5

Type: Bug Priority: Minor
Reporter: Elena Stepanova Assignee: Unassigned
Resolution: Unresolved Votes: 0
Labels: None


 Description   

A similar failure happened in buildbot, but long time ago (almost a year):

c9c689e1a37316593067f07ee248f858 kvm-deb-jessie-amd64

 
main.mysqlbinlog_row_compressed          w4 [ fail ]
 
        Test ended at 2019-08-14 19:26:00
 
 
 
CURRENT_TEST: main.mysqlbinlog_row_compressed
 
--- /usr/share/mysql/mysql-test/main/mysqlbinlog_row_compressed.result	2019-08-14 17:48:23.000000000 -0400
 
+++ /dev/shm/var/4/log/mysqlbinlog_row_compressed.reject	2019-08-14 19:26:00.375717628 -0400
 
@@ -29,10 +29,10 @@
 
 /*!100001 SET @@session.server_id=1*//*!*/;
 
 /*!100001 SET @@session.gtid_seq_no=1*//*!*/;
 
 # at 371
 
-#<date> server id 1  end_log_pos 533 CRC32 XXX 	Query_compressed	thread_id=5	exec_time=x	error_code=0
 
+#<date> server id 1  end_log_pos 533 CRC32 XXX 	Query_compressed	thread_id=9	exec_time=x	error_code=0
 
 use `test`/*!*/;
 
 SET TIMESTAMP=X/*!*/;
 
-SET @@session.pseudo_thread_id=5/*!*/;
 
+SET @@session.pseudo_thread_id=9/*!*/;
 
 SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1, @@session.check_constraint_checks=1/*!*/;
 
 SET @@session.sql_mode=1411383296/*!*/;
 
 SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
 
@@ -46,7 +46,7 @@
 
 #<date> server id 1  end_log_pos 575 CRC32 XXX 	GTID 0-1-2 ddl
 
 /*!100001 SET @@session.gtid_seq_no=2*//*!*/;
 
 # at 575
 
-#<date> server id 1  end_log_pos 727 CRC32 XXX 	Query_compressed	thread_id=5	exec_time=x	error_code=0
 
+#<date> server id 1  end_log_pos 727 CRC32 XXX 	Query_compressed	thread_id=9	exec_time=x	error_code=0
 
 SET TIMESTAMP=X/*!*/;
 
 CREATE TABLE t2 (pk INT PRIMARY KEY, f1 INT, f2 INT, f3 INT, f4 INT, f5 MEDIUMINT, f6 INT, f7 INT, f8 char(1))
 
 /*!*/;
 
@@ -61,7 +61,7 @@
 
 #Q> INSERT INTO t1 VALUES (10, 1, 2, 3, 4, 5, 6, 7, "")
 
 #<date> server id 1  end_log_pos 899 CRC32 XXX 	Table_map: `test`.`t1` mapped to number num
 
 # at 899
 
-#<date> server id 1  end_log_pos 967 CRC32 XXX 	Write_compressed_rows: table id 32 flags: STMT_END_F
 
+#<date> server id 1  end_log_pos 967 CRC32 XXX 	Write_compressed_rows: table id 40 flags: STMT_END_F
 
 ### INSERT INTO `test`.`t1`
 
 ### SET
 
 ###   @1=10 /* INT meta=0 nullable=0 is_null=0 */
 
@@ -75,7 +75,7 @@
 
 ###   @9='' /* STRING(1) meta=65025 nullable=1 is_null=0 */
 
 # Number of rows: 1
 
 # at 967
 
-#<date> server id 1  end_log_pos 1040 CRC32 XXX 	Query	thread_id=5	exec_time=x	error_code=0
 
+#<date> server id 1  end_log_pos 1040 CRC32 XXX 	Query	thread_id=9	exec_time=x	error_code=0
 
 SET TIMESTAMP=X/*!*/;
 
 COMMIT
 
 /*!*/;
 
@@ -90,7 +90,7 @@
 
 #Q> INSERT INTO t1 VALUES (11, 1, 2, 3, 4, 5, 6, 7, NULL)
 
 #<date> server id 1  end_log_pos 1214 CRC32 XXX 	Table_map: `test`.`t1` mapped to number num
 
 # at 1214
 
-#<date> server id 1  end_log_pos 1281 CRC32 XXX 	Write_compressed_rows: table id 32 flags: STMT_END_F
 
+#<date> server id 1  end_log_pos 1281 CRC32 XXX 	Write_compressed_rows: table id 40 flags: STMT_END_F
 
 ### INSERT INTO `test`.`t1`
 
 ### SET
 
 ###   @1=11 /* INT meta=0 nullable=0 is_null=0 */
 
@@ -104,7 +104,7 @@
 
 ###   @9=NULL /* STRING(1) meta=65025 nullable=1 is_null=1 */
 
 # Number of rows: 1
 
 # at 1281
 
-#<date> server id 1  end_log_pos 1354 CRC32 XXX 	Query	thread_id=5	exec_time=x	error_code=0
 
+#<date> server id 1  end_log_pos 1354 CRC32 XXX 	Query	thread_id=9	exec_time=x	error_code=0
 
 SET TIMESTAMP=X/*!*/;
 
 COMMIT
 
 /*!*/;
 
@@ -119,7 +119,7 @@
 
 #Q> INSERT INTO t1 VALUES (12, 1, 2, 3, NULL, 5, 6, 7, "A")
 
 #<date> server id 1  end_log_pos 1530 CRC32 XXX 	Table_map: `test`.`t1` mapped to number num
 
 # at 1530
 
-#<date> server id 1  end_log_pos 1596 CRC32 XXX 	Write_compressed_rows: table id 32 flags: STMT_END_F
 
+#<date> server id 1  end_log_pos 1596 CRC32 XXX 	Write_compressed_rows: table id 40 flags: STMT_END_F
 
 ### INSERT INTO `test`.`t1`
 
 ### SET
 
 ###   @1=12 /* INT meta=0 nullable=0 is_null=0 */
 
@@ -133,7 +133,7 @@
 
 ###   @9='A' /* STRING(1) meta=65025 nullable=1 is_null=0 */
 
 # Number of rows: 1
 
 # at 1596
 
-#<date> server id 1  end_log_pos 1669 CRC32 XXX 	Query	thread_id=5	exec_time=x	error_code=0
 
+#<date> server id 1  end_log_pos 1669 CRC32 XXX 	Query	thread_id=9	exec_time=x	error_code=0
 
 SET TIMESTAMP=X/*!*/;
 
 COMMIT
 
 /*!*/;
 
@@ -148,7 +148,7 @@
 
 #Q> INSERT INTO t1 VALUES (13, 1, 2, 3, 0, 5, 6, 7, "A")
 
 #<date> server id 1  end_log_pos 1842 CRC32 XXX 	Table_map: `test`.`t1` mapped to number num
 
 # at 1842
 
-#<date> server id 1  end_log_pos 1909 CRC32 XXX 	Write_compressed_rows: table id 32 flags: STMT_END_F
 
+#<date> server id 1  end_log_pos 1909 CRC32 XXX 	Write_compressed_rows: table id 40 flags: STMT_END_F
 
 ### INSERT INTO `test`.`t1`
 
 ### SET
 
 ###   @1=13 /* INT meta=0 nullable=0 is_null=0 */
 
@@ -162,7 +162,7 @@
 
 ###   @9='A' /* STRING(1) meta=65025 nullable=1 is_null=0 */
 
 # Number of rows: 1
 
 # at 1909
 
-#<date> server id 1  end_log_pos 1982 CRC32 XXX 	Query	thread_id=5	exec_time=x	error_code=0
 
+#<date> server id 1  end_log_pos 1982 CRC32 XXX 	Query	thread_id=9	exec_time=x	error_code=0
 
 SET TIMESTAMP=X/*!*/;
 
 COMMIT
 
 /*!*/;
 
@@ -177,7 +177,7 @@
 
 #Q> INSERT INTO t2 SELECT * FROM t1
 
 #<date> server id 1  end_log_pos 2134 CRC32 XXX 	Table_map: `test`.`t2` mapped to number num
 
 # at 2134
 
-#<date> server id 1  end_log_pos 2225 CRC32 XXX 	Write_compressed_rows: table id 33 flags: STMT_END_F
 
+#<date> server id 1  end_log_pos 2225 CRC32 XXX 	Write_compressed_rows: table id 41 flags: STMT_END_F
 
 ### INSERT INTO `test`.`t2`
 
 ### SET
 
 ###   @1=10 /* INT meta=0 nullable=0 is_null=0 */
 
@@ -224,7 +224,7 @@
 
 ###   @9='A' /* STRING(1) meta=65025 nullable=1 is_null=0 */
 
 # Number of rows: 4
 
 # at 2225
 
-#<date> server id 1  end_log_pos 2298 CRC32 XXX 	Query	thread_id=5	exec_time=x	error_code=0
 
+#<date> server id 1  end_log_pos 2298 CRC32 XXX 	Query	thread_id=9	exec_time=x	error_code=0
 
 SET TIMESTAMP=X/*!*/;
 
 COMMIT
 
 /*!*/;
 
@@ -239,7 +239,7 @@
 
 #Q> UPDATE t2 SET f4=5 WHERE f4>0 or f4 is NULL
 
 #<date> server id 1  end_log_pos 2462 CRC32 XXX 	Table_map: `test`.`t2` mapped to number num
 
 # at 2462
 
-#<date> server id 1  end_log_pos 2561 CRC32 XXX 	Update_compressed_rows: table id 33 flags: STMT_END_F
 
+#<date> server id 1  end_log_pos 2561 CRC32 XXX 	Update_compressed_rows: table id 41 flags: STMT_END_F
 
 ### UPDATE `test`.`t2`
 
 ### WHERE
 
 ###   @1=10 /* INT meta=0 nullable=0 is_null=0 */
 
@@ -305,7 +305,7 @@
 
 ###   @9='A' /* STRING(1) meta=65025 nullable=1 is_null=0 */
 
 # Number of rows: 3
 
 # at 2561
 
-#<date> server id 1  end_log_pos 2634 CRC32 XXX 	Query	thread_id=5	exec_time=x	error_code=0
 
+#<date> server id 1  end_log_pos 2634 CRC32 XXX 	Query	thread_id=9	exec_time=x	error_code=0
 
 SET TIMESTAMP=X/*!*/;
 
 COMMIT
 
 /*!*/;
 
@@ -320,7 +320,7 @@
 
 #Q> DELETE FROM t1
 
 #<date> server id 1  end_log_pos 2769 CRC32 XXX 	Table_map: `test`.`t1` mapped to number num
 
 # at 2769
 
-#<date> server id 1  end_log_pos 2861 CRC32 XXX 	Delete_compressed_rows: table id 32 flags: STMT_END_F
 
+#<date> server id 1  end_log_pos 2861 CRC32 XXX 	Delete_compressed_rows: table id 40 flags: STMT_END_F
 
 ### DELETE FROM `test`.`t1`
 
 ### WHERE
 
 ###   @1=10 /* INT meta=0 nullable=0 is_null=0 */
 
@@ -367,7 +367,7 @@
 
 ###   @9='A' /* STRING(1) meta=65025 nullable=1 is_null=0 */
 
 # Number of rows: 4
 
 # at 2861
 
-#<date> server id 1  end_log_pos 2934 CRC32 XXX 	Query	thread_id=5	exec_time=x	error_code=0
 
+#<date> server id 1  end_log_pos 2934 CRC32 XXX 	Query	thread_id=9	exec_time=x	error_code=0
 
 SET TIMESTAMP=X/*!*/;
 
 COMMIT
 
 /*!*/;
 
@@ -382,7 +382,7 @@
 
 #Q> DELETE FROM t2
 
 #<date> server id 1  end_log_pos 3069 CRC32 XXX 	Table_map: `test`.`t2` mapped to number num
 
 # at 3069
 
-#<date> server id 1  end_log_pos 3154 CRC32 XXX 	Delete_compressed_rows: table id 33 flags: STMT_END_F
 
+#<date> server id 1  end_log_pos 3154 CRC32 XXX 	Delete_compressed_rows: table id 41 flags: STMT_END_F
 
 ### DELETE FROM `test`.`t2`
 
 ### WHERE
 
 ###   @1=10 /* INT meta=0 nullable=0 is_null=0 */
 
@@ -429,7 +429,7 @@
 
 ###   @9='A' /* STRING(1) meta=65025 nullable=1 is_null=0 */
 
 # Number of rows: 4
 
 # at 3154
 
-#<date> server id 1  end_log_pos 3227 CRC32 XXX 	Query	thread_id=5	exec_time=x	error_code=0
 
+#<date> server id 1  end_log_pos 3227 CRC32 XXX 	Query	thread_id=9	exec_time=x	error_code=0
 
 SET TIMESTAMP=X/*!*/;
 
 COMMIT
 
 /*!*/;
 
 
 
mysqltest: Result content mismatch

Now it happened on my local build, too

10.5 e341fb0d

 
main.mysqlbinlog_row_compressed          w1 [ fail ]
 
        Test ended at 2020-06-19 20:13:56
 
 
 
CURRENT_TEST: main.mysqlbinlog_row_compressed
 
--- /data/bld/10.5.4-unstable-tests/mysql-test/main/mysqlbinlog_row_compressed.result   2020-06-15 14:40:52.000000000 +0300
 
+++ /data/bld/10.5.4-unstable-tests/mysql-test/main/mysqlbinlog_row_compressed.reject   2020-06-19 20:13:55.883648703 +0300
 
@@ -29,10 +29,10 @@
 
 /*!100001 SET @@session.server_id=1*//*!*/;
 
 /*!100001 SET @@session.gtid_seq_no=1*//*!*/;
 
 # at 371
 
-#<date> server id 1  end_log_pos 533 CRC32 XXX         Query_compressed        thread_id=5     exec_time=x     error_code=0
 
+#<date> server id 1  end_log_pos 533 CRC32 XXX         Query_compressed        thread_id=9     exec_time=x     error_code=0
 
 use `test`/*!*/;
 
 SET TIMESTAMP=X/*!*/;
 
-SET @@session.pseudo_thread_id=5/*!*/;
 
+SET @@session.pseudo_thread_id=9/*!*/;
 
 SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1, @@session.check_constraint_checks=1, @@session.sql_if_exists=0/*!*/;
 
 SET @@session.sql_mode=#/*!*/;
 
 SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
 
@@ -46,7 +46,7 @@
 
 #<date> server id 1  end_log_pos 575 CRC32 XXX         GTID 0-1-2 ddl
 
 /*!100001 SET @@session.gtid_seq_no=2*//*!*/;
 
 # at 575
 
-#<date> server id 1  end_log_pos 727 CRC32 XXX         Query_compressed        thread_id=5     exec_time=x     error_code=0
 
+#<date> server id 1  end_log_pos 727 CRC32 XXX         Query_compressed        thread_id=9     exec_time=x     error_code=0
 
 SET TIMESTAMP=X/*!*/;
 
 CREATE TABLE t2 (pk INT PRIMARY KEY, f1 INT, f2 INT, f3 INT, f4 INT, f5 MEDIUMINT, f6 INT, f7 INT, f8 char(1))
 
 /*!*/;
 
@@ -61,7 +61,7 @@
 
 #Q> INSERT INTO t1 VALUES (10, 1, 2, 3, 4, 5, 6, 7, "")
 
 #<date> server id 1  end_log_pos 899 CRC32 XXX         Table_map: `test`.`t1` mapped to number num
 
 # at 899
 
-#<date> server id 1  end_log_pos 967 CRC32 XXX         Write_compressed_rows: table id 32 flags: STMT_END_F
 
+#<date> server id 1  end_log_pos 967 CRC32 XXX         Write_compressed_rows: table id 40 flags: STMT_END_F
 
 ### INSERT INTO `test`.`t1`
 
 ### SET
 
 ###   @1=10 /* INT meta=0 nullable=0 is_null=0 */
 
@@ -75,7 +75,7 @@
 
 ###   @9='' /* STRING(1) meta=65025 nullable=1 is_null=0 */
 
 # Number of rows: 1
 
 # at 967
 
-#<date> server id 1  end_log_pos 1040 CRC32 XXX        Query   thread_id=5     exec_time=x     error_code=0
 
+#<date> server id 1  end_log_pos 1040 CRC32 XXX        Query   thread_id=9     exec_time=x     error_code=0
 
 SET TIMESTAMP=X/*!*/;
 
 COMMIT
 
 /*!*/;
 
@@ -90,7 +90,7 @@
 
 #Q> INSERT INTO t1 VALUES (11, 1, 2, 3, 4, 5, 6, 7, NULL)
 
 #<date> server id 1  end_log_pos 1214 CRC32 XXX        Table_map: `test`.`t1` mapped to number num
 
 # at 1214
 
-#<date> server id 1  end_log_pos 1281 CRC32 XXX        Write_compressed_rows: table id 32 flags: STMT_END_F
 
...
 
(mangled output)


Generated at Thu Feb 08 09:18:49 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.