Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-12306

The main.auth_rpl 'row' test fail in i386

Details

    Description

      The Debian unstable i386 fails with:

      main.auth_rpl 'row'                      w3 [ fail ]  Found warnings/errors in server log file!
              Test ended at 2017-03-20 10:13:07
      line
      2017-03-20 10:13:06 f5940800 InnoDB: Error: page 5 log sequence number 1629826
      ^ Found warnings in /«PKGBUILDDIR»/builddir/mysql-test/var/3/log/mysqld.2.err
      ok
       
       - saving '/«PKGBUILDDIR»/builddir/mysql-test/var/3/log/main.auth_rpl-row/' to '/«PKGBUILDDIR»/builddir/mysql-test/var/log/main.auth_rpl-row/'
       
      Retrying test main.auth_rpl, attempt(2/3)...
      [...]
      main.auth_rpl 'row'                      w3 [ retry-pass ]    437
       
      Retrying test main.auth_rpl, attempt(3/3)...
      [...]
      main.auth_rpl 'row'                      w3 [ retry-fail ]
              Test ended at 2017-03-20 10:18:13
       
      CURRENT_TEST: main.auth_rpl
      mysqltest: In included file "/«PKGBUILDDIR»/mysql-test/include/wait_for_slave_param.inc": 
      included from /«PKGBUILDDIR»/mysql-test/include/wait_for_slave_io_to_start.inc at line 40:
      included from /«PKGBUILDDIR»/mysql-test/include/wait_for_slave_to_start.inc at line 26:
      included from /«PKGBUILDDIR»/mysql-test/include/start_slave.inc at line 35:
      included from /«PKGBUILDDIR»/mysql-test/include/rpl_for_each_slave.inc at line 33:
      included from /«PKGBUILDDIR»/mysql-test/include/rpl_start_slaves.inc at line 30:
      included from /«PKGBUILDDIR»/mysql-test/include/rpl_init.inc at line 210:
      included from /«PKGBUILDDIR»/mysql-test/include/master-slave.inc at line 38:
      included from /«PKGBUILDDIR»/mysql-test/t/auth_rpl.test at line 4:
      At line 119: Timeout in include/wait_for_slave_param.inc
       
      The result from queries just before the failure was:
      < snip >
      15	root	localhost:42277	test	Query	0	init	SHOW PROCESSLIST	0.000
      16	root	localhost:42278	test	Sleep	303		NULL	0.000
       
      **** SHOW BINARY LOGS on server_1 ****
      SHOW BINARY LOGS;
      Log_name	File_size
      master-bin.000001	314
       
      **** SHOW BINLOG EVENTS on server_1 ****
      binlog_name = 'master-bin.000001'
      SHOW BINLOG EVENTS IN 'master-bin.000001';
      Log_name	Pos	Event_type	Server_id	End_log_pos	Info
      master-bin.000001	4	Format_desc	1	249	Server ver: 10.1.22-MariaDB-, Binlog ver: 4
      master-bin.000001	249	Gtid_list	1	274	[]
      master-bin.000001	274	Binlog_checkpoint	1	314	master-bin.000001
       
      **** SHOW RELAYLOG EVENTS on server_1 ****
      relaylog_name = 'No such row'
      SHOW RELAYLOG EVENTS IN 'No such row';
      Log_name	Pos	Event_type	Server_id	End_log_pos	Info
       
      More results from queries before failure can be found in /«PKGBUILDDIR»/builddir/mysql-test/var/3/log/auth_rpl.log
       
       - saving '/«PKGBUILDDIR»/builddir/mysql-test/var/3/log/main.auth_rpl-row/' to '/«PKGBUILDDIR»/builddir/mysql-test/var/log/main.auth_rpl-row/'
      --------------------------------------------------------------------------
      The servers were restarted 1032 times
      Spent 3868.127 of 1987 seconds executing testcases
       
      Completed: Failed 1/4450 tests, 99.98% were successful.
       
      Failing test(s): main.auth_rpl
      

      A full build log can be found here: https://buildd.debian.org/status/fetch.php?pkg=mariadb-10.1&arch=i386&ver=10.1.22-1&stamp=1490005100&raw=0

      Attachments

        Activity

          Strangely enough, I can't reproduce the issue when building the package locally within i386 chroot (pbuilder). I could ask Debian buildd admins for triggering the build again to see if the issue persists on the buildd machine.

          oerdnj Ondřej Surý (Inactive) added a comment - Strangely enough, I can't reproduce the issue when building the package locally within i386 chroot (pbuilder). I could ask Debian buildd admins for triggering the build again to see if the issue persists on the buildd machine.

          And the second rebuild on the Debian i386 infrastructure went well. I would however appreciate if there's some insight why this might have failed, but I understand that a bug not reproducible is not very useful.

          oerdnj Ondřej Surý (Inactive) added a comment - And the second rebuild on the Debian i386 infrastructure went well. I would however appreciate if there's some insight why this might have failed, but I understand that a bug not reproducible is not very useful.

          A relevant part of the error message is missing in the output, because InnoDB used to split error messages into several lines. I believe that the message wanted to say that the log sequence number is in the future. The explanation could be that replication tests used to (or maybe still do) kill the replica servers (see the mysqld.2.err below) instead of waiting for a graceful shutdown. Maybe the log checkpoints were seriously lagging behind. Ultimately, this could have been fixed by MDEV-28415 (2022-04-27).

          The latest such failure for a main branch is the following:

          10.2 99945d77d748470fbb3939be5f7d0e36d24d8097

          main.auth_rpl 'row'                      w28 [ fail ]  Found warnings/errors in server log file!
                  Test ended at 2021-03-30 23:59:17
          line
          2021-03-30 23:59:15 140603632383936 [ERROR] InnoDB: Page [page id: space=0, page number=5] log sequence number 1628272 is in the future! Current system log sequence number 1628262.
          2021-03-30 23:59:15 140603632383936 [ERROR] InnoDB: Your database may be corrupt or you may have copied the InnoDB tablespace but not the InnoDB log files. Please refer to https://mariadb.com/kb/en/library/innodb-recovery-modes/ for information about forcing recovery.
          ^ Found warnings in /buildbot/amd64-ubuntu-1804-clang6/build/mysql-test/var/28/log/mysqld.2.err
          

          The latest failure for a non-main branch was 2021-05-25 23 on a 10.2 based branch.

          marko Marko Mäkelä added a comment - A relevant part of the error message is missing in the output, because InnoDB used to split error messages into several lines. I believe that the message wanted to say that the log sequence number is in the future . The explanation could be that replication tests used to (or maybe still do) kill the replica servers (see the mysqld.2.err below) instead of waiting for a graceful shutdown. Maybe the log checkpoints were seriously lagging behind. Ultimately, this could have been fixed by MDEV-28415 (2022-04-27). The latest such failure for a main branch is the following: 10.2 99945d77d748470fbb3939be5f7d0e36d24d8097 main.auth_rpl 'row' w28 [ fail ] Found warnings/errors in server log file! Test ended at 2021-03-30 23:59:17 line 2021-03-30 23:59:15 140603632383936 [ERROR] InnoDB: Page [page id: space=0, page number=5] log sequence number 1628272 is in the future! Current system log sequence number 1628262. 2021-03-30 23:59:15 140603632383936 [ERROR] InnoDB: Your database may be corrupt or you may have copied the InnoDB tablespace but not the InnoDB log files. Please refer to https://mariadb.com/kb/en/library/innodb-recovery-modes/ for information about forcing recovery. ^ Found warnings in /buildbot/amd64-ubuntu-1804-clang6/build/mysql-test/var/28/log/mysqld.2.err The latest failure for a non-main branch was 2021-05-25 23 on a 10.2 based branch.

          People

            marko Marko Mäkelä
            oerdnj Ondřej Surý (Inactive)
            Votes:
            0 Vote for this issue
            Watchers:
            3 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved:

              Git Integration

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