[MDEV-22964] main.mysqlbinlog_row_compressed fails with wrong result - Jira

Details

Type: Bug
Status: Closed (View Workflow)
Priority: Minor
Resolution: Fixed
Affects Version/s: 10.5
Fix Version/s: 10.5.28, 10.6.21, 10.11.11, 11.4.5, 11.7.2
Component/s: Tests
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)

Attachments

Issue Links

is duplicated by

MDEV-34001 Mismatched binlog positionining causing test failures in fedora:40

Closed

Activity

Transition	Time In Source Status	Execution Times

Daniel Black made transition - 2024-12-13 00:50

Open

Confirmed

1637d 6h 52m

Daniel Black made transition - 2024-12-13 00:51

Confirmed

In Review

55s

Kristian Nielsen made transition - 2024-12-14 11:58

In Review

Stalled

1d 11h 6m

Daniel Black made transition - 2024-12-15 23:09

Stalled

Closed

1d 11h 10m

People

Assignee:: Daniel Black

Reporter:: Elena Stepanova

Votes:: 0 Vote for this issue

Watchers:: 2 Start watching this issue

Dates

Created:: 2020-06-19 17:58

Updated:: 2024-12-15 23:09

Resolved:: 2024-12-15 23:09

Git Integration

Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.

MariaDB Server