[MDEV-20530] binlog.binlog_mysqlbinlog_row_innodb and binlog.binlog_mysqlbinlog_row_myisam fail in buildbot on rhel8-ppc64le, binary files differ Created: 2019-09-08  Updated: 2023-10-07

Status: Stalled
Project: MariaDB Server
Component/s: Replication, Tests
Affects Version/s: 10.3, 10.4, 10.5
Fix Version/s: 10.4, 10.5

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Oleksandr Byelkin
Resolution: Unresolved Votes: 0
Labels: None

Issue Links:
Relates
relates to MDEV-20532 Tests fail massively in buildbot on r... Open
relates to MDEV-26960 binlog.binlog_mysqlbinlog_row_myisam ... Open

 Description   

http://buildbot.askmonty.org/buildbot/builders/kvm-rpm-rhel8-ppc64le/builds/120/steps/mtr/logs/stdio

10.3 f80e02e043103ab4e6ca12d9efffec6eb9aa3b74

 
binlog.binlog_mysqlbinlog_row_innodb 'innodb,row' w1 [ fail ]
 
        Test ended at 2019-09-07 12:36:34
 
 
 
CURRENT_TEST: binlog.binlog_mysqlbinlog_row_innodb
 
Binary files /usr/share/mysql-test/suite/binlog/r/binlog_mysqlbinlog_row_innodb.result and /dev/shm/var/1/log/binlog_mysqlbinlog_row_innodb.reject differ
 
 
 
mysqltest: Result length mismatch


binlog.binlog_mysqlbinlog_row_myisam 'row' w2 [ fail ]
 
        Test ended at 2019-09-07 12:36:51
 
 
 
CURRENT_TEST: binlog.binlog_mysqlbinlog_row_myisam
 
Binary files /usr/share/mysql-test/suite/binlog/r/binlog_mysqlbinlog_row_myisam.result and /dev/shm/var/2/log/binlog_mysqlbinlog_row_myisam.reject differ
 
 
 
mysqltest: Result length mismatch



 Comments   
Comment by Alice Sherepa [ 2020-07-02 ]

the same on 10.4, 10.5 + rhel8-ppc64le
http://buildbot.askmonty.org/buildbot/builders/kvm-rpm-rhel8-ppc64le/builds/1353/steps/mtr/logs/stdio
http://buildbot.askmonty.org/buildbot/builders/kvm-rpm-rhel8-ppc64le/builds/1355/steps/mtr/logs/stdio

Comment by Alice Sherepa [ 2020-09-04 ]

test fails every day, http://buildbot.askmonty.org/buildbot/reports/cross_reference#branch=&revision=&platform=&dt=&bbnum=&typ=&info=&fail_name=binlog.binlog_mysqlbinlog_row&fail_variant=&fail_info_short=&fail_info_full=&limit=50

Comment by Sujatha Sivakumar (Inactive) [ 2020-10-05 ]

Result length mismatch is reported for following test case.
File: mysql-test/suite/binlog/include/mysqlbinlog_row_engine.inc

--echo #
 
--echo # Update min values to max values.
 
--echo #

Test expects '1' row to be updated but this expectation fails in 'rhel8-ppc64le' platform. Please find a simplified test case.

set sql_mode="";
 
SET NAMES 'utf8';
 
--disable_warnings
 
DROP TABLE IF EXISTS t1;
 
--enable_warnings
 
 
 
--echo #
 
--echo # Create a test table with all data types.
 
--echo #
 
CREATE TABLE t1 ( c19 FLOAT, crn INT) ENGINE=Myisam DEFAULT CHARSET latin1;
 
 
 
--echo #
 
--echo # Insert minimum values.
 
--echo #
 
INSERT INTO t1 VALUES ( -3.402823466E+38,1);
 
 
 
--enable_info
 
--echo #
 
--echo # Update min values to max values.
 
--echo #
 
UPDATE t1 SET c19 = 3.402823466E+38 WHERE c19 < -3.402823465E+38 AND  crn = 1;
 
 
 
--echo #
 
--echo # Cleanup.
 
--echo #
 
DROP TABLE t1;

Result on ubuntu:

set sql_mode="";
 
SET NAMES 'utf8';
 
DROP TABLE IF EXISTS t1;
 
#
 
# Create a test table with all data types.
 
#
 
CREATE TABLE t1 ( c19 FLOAT, crn INT) ENGINE=Myisam DEFAULT CHARSET latin1;
 
#
 
# Insert minimum values.
 
#
 
INSERT INTO t1 VALUES ( -3.402823466E+38,1);
 
#
 
# Update min values to max values.
 
#
 
UPDATE t1 SET c19 = 3.402823466E+38 WHERE c19 < -3.402823465E+38 AND  crn = 1;
 
affected rows: 1
 
info: Rows matched: 1  Changed: 1  Warnings: 0
 
#
 
# Cleanup.
 
#
 
DROP TABLE t1;
 
affected rows: 0
 
main.bug1                                [ pass ]      4
 
--------------------------------------------------------------------------
 
The servers were restarted 0 times
 
Spent 0.004 of 4 seconds executing testcases
 
 
 
Completed: All 1 tests were successful.

Result from rhel8-ppc64le:

set sql_mode="";
 
SET NAMES 'utf8';
 
DROP TABLE IF EXISTS t1;
 
#
 
# Create a test table with all data types.
 
#
 
CREATE TABLE t1 ( c19 FLOAT, crn INT) ENGINE=Myisam DEFAULT CHARSET latin1;
 
#
 
# Insert minimum values.
 
#
 
INSERT INTO t1 VALUES ( -3.402823466E+38,1);
 
#
 
# Update min values to max values.
 
#
 
UPDATE t1 SET c19 = 3.402823466E+38 WHERE c19 < -3.402823465E+38 AND  crn = 1;
 
affected rows: 0
 
info: Rows matched: 0  Changed: 0  Warnings: 0
 
#
 
# Cleanup.
 
#
 
DROP TABLE t1;
 
affected rows: 0
 
main.bug                                 [ pass ]     51

The issue is related to 'FLOAT' data type.

Comment by Otto Kekäläinen [ 2020-10-11 ]

I removed the skiplists for these tests in https://salsa.debian.org/mariadb-team/mariadb-10.5/-/commit/bde2cf481fa48a0dd85b9ad40e27ad5005ad1122 as we nowadays only run the main test suite as part of the builds (see debian/rules).

Comment by Otto Kekäläinen [ 2020-10-12 ]

Tested with an upload to Launchpad where the extended test suite is enabled. However the test seems to be globally disabled, so it didn't run at all:

binlog.binlog_mysqlbinlog_row_innodb     [ disabled ]  MDEV-20530 - Binary files differ
 
binlog.binlog_mysqlbinlog_row_myisam     [ disabled ]  MDEV-20530 - Binary files differ

Log: https://launchpadlibrarian.net/501650715/buildlog_ubuntu-groovy-s390x.mariadb-10.5_1%3A10.5.5-4~ubuntu20.10.1~1602458170.84f9c0e86.master.next_BUILDING.txt.gz

Comment by Otto Kekäläinen [ 2020-10-12 ]

I enabled this tests and they are passing successfully:

binlog.binlog_mysqlbinlog_row_innodb 'innodb,row' w1 [ pass ] 2865
binlog.binlog_row_mix_innodb_myisam 'innodb,row' w2 [ pass ] 29060

See e.g.
https://launchpadlibrarian.net/501710274/buildlog_ubuntu-groovy-amd64.mariadb-10.5_1%3A10.5.5-4~ubuntu20.10.1~1602488010.9ccdf6955.master.next_BUILDING.txt.gz
https://launchpadlibrarian.net/501702607/buildlog_ubuntu-groovy-s390x.mariadb-10.5_1%3A10.5.5-4~ubuntu20.10.1~1602488010.9ccdf6955.master.next_BUILDING.txt.gz
https://launchpadlibrarian.net/501703726/buildlog_ubuntu-groovy-ppc64el.mariadb-10.5_1%3A10.5.5-4~ubuntu20.10.1~1602488010.9ccdf6955.master.next_BUILDING.txt.gz

Comment by Marko Mäkelä [ 2021-08-28 ]

For the record, I noticed a result difference in the bb-10.6-MDEV-25919 branch, which no longer disables innodb_stats_persistent globally while running the regression test. The lines are being shifted in the output. I verified that by observing that the following returns the empty result:

diff -u <(grep ^-# result.diff|cut -c2-)  <(grep ^+# result.diff|cut -c2-)

The result difference that I got locally was as follows:

binlog.binlog_mysqlbinlog_row_innodb 'innodb,row' w26 [ 29 fail ]
 
        Test ended at 2021-08-28 09:57:49
 
 
 
CURRENT_TEST: binlog.binlog_mysqlbinlog_row_innodb
 
--- /mariadb/10.6/mysql-test/suite/binlog/r/binlog_mysqlbinlog_row_innodb.result2021-05-20 07:15:01.499178097 +0300
 
+++ /mariadb/10.6/mysql-test/suite/binlog/r/binlog_mysqlbinlog_row_innodb.reject2021-08-28 09:57:49.394914363 +0300
 
@@ -6165,36 +6165,6 @@
 
 ###   @1='2018:01:07' /* DATE meta=0 nullable=1 is_null=0 */
 
 ###   @2='VARCHAR-01-07' /* VARSTRING(255) meta=255 nullable=1 is_null=0 */
 
 ###   @3=7 /* INT meta=0 nullable=1 is_null=0 */
 
-### DELETE FROM `test`.`t2`
 
-### WHERE
 
-###   @1='2028:02:02' /* DATE meta=0 nullable=1 is_null=0 */
 
-###   @2='VARCHAR-02-02' /* VARSTRING(255) meta=255 nullable=1 is_null=0 */
 
-###   @3=2 /* INT meta=0 nullable=1 is_null=0 */
 
-### DELETE FROM `test`.`t2`
 
-### WHERE
 
-###   @1='2028:02:03' /* DATE meta=0 nullable=1 is_null=0 */
 
-###   @2='VARCHAR-02-03' /* VARSTRING(255) meta=255 nullable=1 is_null=0 */
 
-###   @3=3 /* INT meta=0 nullable=1 is_null=0 */
 
-### DELETE FROM `test`.`t2`
 
-### WHERE
 
-###   @1='2028:02:04' /* DATE meta=0 nullable=1 is_null=0 */
 
-###   @2='VARCHAR-02-04' /* VARSTRING(255) meta=255 nullable=1 is_null=0 */
 
-###   @3=4 /* INT meta=0 nullable=1 is_null=0 */
 
-### DELETE FROM `test`.`t2`
 
-### WHERE
 
-###   @1='2028:02:05' /* DATE meta=0 nullable=1 is_null=0 */
 
-###   @2='VARCHAR-02-05' /* VARSTRING(255) meta=255 nullable=1 is_null=0 */
 
-###   @3=5 /* INT meta=0 nullable=1 is_null=0 */
 
-### DELETE FROM `test`.`t2`
 
-### WHERE
 
-###   @1='2028:02:06' /* DATE meta=0 nullable=1 is_null=0 */
 
-###   @2='VARCHAR-02-06' /* VARSTRING(255) meta=255 nullable=1 is_null=0 */
 
-###   @3=6 /* INT meta=0 nullable=1 is_null=0 */
 
-### DELETE FROM `test`.`t2`
 
-### WHERE
 
-###   @1='2028:02:07' /* DATE meta=0 nullable=1 is_null=0 */
 
-###   @2='VARCHAR-02-07' /* VARSTRING(255) meta=255 nullable=1 is_null=0 */
 
-###   @3=7 /* INT meta=0 nullable=1 is_null=0 */
 
 ### DELETE FROM `test`.`t3`
 
 ### WHERE
 
 ###   @1='2038:03:02' /* DATE meta=0 nullable=1 is_null=0 */
 
@@ -6225,6 +6195,36 @@
 
 ###   @1='2038:03:07' /* DATE meta=0 nullable=1 is_null=0 */
 
 ###   @2='VARCHAR-03-07' /* VARSTRING(255) meta=255 nullable=1 is_null=0 */
 
 ###   @3=7 /* INT meta=0 nullable=1 is_null=0 */
 
+### DELETE FROM `test`.`t2`
 
+### WHERE
 
+###   @1='2028:02:02' /* DATE meta=0 nullable=1 is_null=0 */
 
+###   @2='VARCHAR-02-02' /* VARSTRING(255) meta=255 nullable=1 is_null=0 */
 
+###   @3=2 /* INT meta=0 nullable=1 is_null=0 */
 
+### DELETE FROM `test`.`t2`
 
+### WHERE
 
+###   @1='2028:02:03' /* DATE meta=0 nullable=1 is_null=0 */
 
+###   @2='VARCHAR-02-03' /* VARSTRING(255) meta=255 nullable=1 is_null=0 */
 
+###   @3=3 /* INT meta=0 nullable=1 is_null=0 */
 
+### DELETE FROM `test`.`t2`
 
+### WHERE
 
+###   @1='2028:02:04' /* DATE meta=0 nullable=1 is_null=0 */
 
+###   @2='VARCHAR-02-04' /* VARSTRING(255) meta=255 nullable=1 is_null=0 */
 
+###   @3=4 /* INT meta=0 nullable=1 is_null=0 */
 
+### DELETE FROM `test`.`t2`
 
+### WHERE
 
+###   @1='2028:02:05' /* DATE meta=0 nullable=1 is_null=0 */
 
+###   @2='VARCHAR-02-05' /* VARSTRING(255) meta=255 nullable=1 is_null=0 */
 
+###   @3=5 /* INT meta=0 nullable=1 is_null=0 */
 
+### DELETE FROM `test`.`t2`
 
+### WHERE
 
+###   @1='2028:02:06' /* DATE meta=0 nullable=1 is_null=0 */
 
+###   @2='VARCHAR-02-06' /* VARSTRING(255) meta=255 nullable=1 is_null=0 */
 
+###   @3=6 /* INT meta=0 nullable=1 is_null=0 */
 
+### DELETE FROM `test`.`t2`
 
+### WHERE
 
+###   @1='2028:02:07' /* DATE meta=0 nullable=1 is_null=0 */
 
+###   @2='VARCHAR-02-07' /* VARSTRING(255) meta=255 nullable=1 is_null=0 */
 
+###   @3=7 /* INT meta=0 nullable=1 is_null=0 */
 
 # Number of rows: 18
 
 # at #
 
 #010909  4:46:40 server id 1  end_log_pos # CRC32 XXX 	Xid = #
 
 
 
mysqltest: Result content mismatch

It looks like this failure can be prevented by innodb_stats_persistent=OFF or innodb_stats_auto_recalc=OFF. The failure occurred on buildbot a few different times:
http://buildbot.askmonty.org/buildbot/builders/kvm-fulltest2/builds/30523
http://buildbot.askmonty.org/buildbot/builders/kvm-deb-sid-x86/builds/12484
In both these occurrences, the difference starts in the same way, slightly different from the one that I posted above. Note: the line number is 6135, not 6165 like in my local failure (which I repeated twice).

CURRENT_TEST: binlog.binlog_mysqlbinlog_row_innodb
 
--- /usr/share/mysql/mysql-test/suite/binlog/r/binlog_mysqlbinlog_row_innodb.result	2021-08-26 12:00:15.000000000 +0300
 
+++ /dev/shm/var/3/log/binlog_mysqlbinlog_row_innodb.reject	2021-08-26 13:12:45.998446015 +0300
 
@@ -6135,36 +6135,6 @@
 
 #010909  4:46:40 server id 1  end_log_pos # CRC32 XXX 	Delete_rows: table id #
 
 #010909  4:46:40 server id 1  end_log_pos # CRC32 XXX 	Delete_rows: table id #
 
 #010909  4:46:40 server id 1  end_log_pos # CRC32 XXX 	Delete_rows: table id # flags: STMT_END_F
 
-### DELETE FROM `test`.`t1`
 
-### WHERE
 
…

In that MDEV-25919 related branch (soon to land in 10.6), I am fixing MDEV-4750 in a less intrusive way: not disabilng InnoDB persistent statistics globally, but only in specific tests. To stabilize this test, I will disable the automatic recalculation.

It would be useful to pass the -a option to diff so that we would see the output even if it might contain some binary data.

Comment by Elena Stepanova [ 2022-05-29 ]

From now on the tests will be skipped on this builder.
When the failure is fixed, please create a TODO task for re-enabling the tests.

Comment by Otto Kekäläinen [ 2023-10-07 ]

I ran extensive tests with 'mtr --big' and did not see this occurring on any architecture. Logs at https://launchpad.net/~otto/+archive/ubuntu/mariadb/+builds?build_text=&build_state=all.

From https://launchpadlibrarian.net/690729858/buildlog_ubuntu-mantic-ppc64el.mariadb_1%3A10.11.5-2~bpo23.10.1~1696620362.87d091ed5f9+feature.re.enable.all.tests_BUILDING.txt.gz:

binlog.binlog_mysqlbinlog_row_innodb 'innodb,row' w2 [ pass ]   1049
 
binlog.binlog_mysqlbinlog_row_myisam 'row' w1 [ pass ]    168

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