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

mariabackup.data_directory, mariabackup.partial_exclude failed in buildbot with error on exec

Details

    Description

      10.2 cdb7a8fa6928f3fb103ed7f66486dc91 kvm-deb-xenial-x86 2018-01-10 23:54:03 4987 nm Normal run, no --ps-protocol

      mariabackup.data_directory               w4 [ fail ]
              Test ended at 2018-01-10 17:37:01
       
      CURRENT_TEST: mariabackup.data_directory
      mysqltest: At line 9: exec of '/usr/bin/mariabackup --defaults-file=/dev/shm/var/4/my.cnf --backup --target-dir=/dev/shm/var/4/tmp/backup 2>&1' failed, error: 256, status: 1, errno: 11
      Output from before failure:
      180110 17:37:01 Connecting to MySQL server host: localhost, user: root, password: set, port: 16040, socket: /dev/shm/var/tmp/4/mysqld.1.sock
      Using server version 10.2.13-MariaDB-10.2.13+maria~xenial-log
      /usr/bin/mariabackup based on MariaDB server 10.2.13-MariaDB debian-linux-gnu (i686) 
      mariabackup: uses posix_fadvise().
      mariabackup: cd to /dev/shm/var/4/mysqld.1/data/
      mariabackup: open files limit requested 1024, set to 1024
      mariabackup: using the following InnoDB configuration:
      mariabackup:   innodb_data_home_dir = .
      mariabackup:   innodb_data_file_path = ibdata1:12M:autoextend
      mariabackup:   innodb_log_group_home_dir = ./
      2018-01-10 17:37:01 3068790720 [Note] InnoDB: Number of pools: 1
      180110 17:37:01 >> log scanned up to (1656143)
      2018-01-10 17:37:01 3068790720 [Note] InnoDB: Log sequence number at the start 1637250 and the end 1652116 do not match
      2018-01-10 17:37:01 3068790720 [ERROR] InnoDB: Checksum mismatch in datafile: ./ibdata1, Space ID:0, Flags: 0. Please refer to http://dev.mysql.com/doc/refman/5.7/en/innodb-troubleshooting-datadict.html for how to resolve the issue.
      2018-01-10 17:37:01 3068790720 [Note] InnoDB: Restoring page [page id: space=0, page number=0] of datafile './ibdata1' from the doublewrite buffer. Writing 16384 bytes into file './ibdata1'
      2018-01-10 17:37:01 3068790720 [Warning] InnoDB: Retry attempts for writing partial data failed.
      2018-01-10 17:37:01 3068790720 [ERROR] InnoDB: Write to file ./ibdata1failed at offset 0, 16384 bytes should have been written, only 0 were written. Operating system error number 9. Check that your OS and file system support files of this size. Check also that the disk is not full or a disk quota exceeded.
      2018-01-10 17:37:01 3068790720 [ERROR] InnoDB: Error number 9 means 'Bad file descriptor'
      2018-01-10 17:37:01 3068790720 [Note] InnoDB: Some operating system error numbers are described at https://mariadb.com/kb/en/library/operating-system-error-codes/
      mariabackup: Could not open or create data files.
      mariabackup: If you tried to add new data files, and it failed here,
      mariabackup: you should now edit innodb_data_file_path in my.cnf back
      mariabackup: to what it was, and remove the new ibdata files InnoDB created
      mariabackup: in this failed attempt. InnoDB only wrote those files full of
      mariabackup: zeros, but did not yet use them in any way. But be careful: do not
      mariabackup: remove old data files which contain your precious data!
      mariabackup: error: xb_load_tablespaces() failed witherror code 39
      mariabackup: Stopping log copying thread.
      .
       
       
       
      The result from queries just before the failure was:
      CREATE TABLE t(a INT) ENGINE=InnoDB DATA DIRECTORY='table_data_dir';
      INSERT INTO t VALUES(1);
      # xtrabackup backup
       
       - saving '/dev/shm/var/4/log/mariabackup.data_directory/' to '/dev/shm/var/log/mariabackup.data_directory/'
       
      Retrying test mariabackup.data_directory, attempt(2/3)...
       
      worker[4] > Restart  - not started
      

      Logs not available

      Attachments

        Issue Links

          Activity

            Looks similar, but with log (for now)
            http://buildbot.askmonty.org/buildbot/builders/kvm-deb-artful-amd64/builds/420/steps/mtr/logs/stdio

            mariabackup.partial_exclude              w1 [ fail ]
                    Test ended at 2018-01-12 23:59:24
             
            CURRENT_TEST: mariabackup.partial_exclude
            mysqltest: At line 19: exec of '/usr/bin/mariabackup --defaults-file=/dev/shm/var/1/my.cnf  --backup "--tables-exclude=test.*2" "--databases-exclude=db2" --target-dir=/dev/shm/var/1/tmp/backup 2>&1' failed, error: 256, status: 1, errno: 95
            Output from before failure:
            180112 23:59:23 Connecting to MySQL server host: localhost, user: root, password: set, port: 16000, socket: /dev/shm/var/tmp/1/mysqld.1.sock
            Using server version 10.2.13-MariaDB-10.2.13+maria~artful-log
            /usr/bin/mariabackup based on MariaDB server 10.2.13-MariaDB debian-linux-gnu (x86_64) 
            mariabackup: uses posix_fadvise().
            mariabackup: cd to /dev/shm/var/1/mysqld.1/data/
            mariabackup: open files limit requested 1024, set to 1024
            mariabackup: using the following InnoDB configuration:
            mariabackup:   innodb_data_home_dir = .
            mariabackup:   innodb_data_file_path = ibdata1:12M:autoextend
            mariabackup:   innodb_log_group_home_dir = ./
            2018-01-12 23:59:23 140110908889280 [Note] InnoDB: Number of pools: 1
            180112 23:59:23 >> log scanned up to (1685180)
            2018-01-12 23:59:23 140110908889280 [Note] InnoDB: Log sequence number at the start 1668276 and the end 1682680 do not match
            2018-01-12 23:59:23 140110908889280 [ERROR] InnoDB: Checksum mismatch in datafile: ./ibdata1, Space ID:0, Flags: 0. Please refer to http://dev.mysql.com/doc/refman/5.7/en/innodb-troubleshooting-datadict.html for how to resolve the issue.
            2018-01-12 23:59:23 140110908889280 [Note] InnoDB: Restoring page [page id: space=0, page number=0] of datafile './ibdata1' from the doublewrite buffer. Writing 16384 bytes into file './ibdata1'
            2018-01-12 23:59:23 140110908889280 [Warning] InnoDB: Retry attempts for writing partial data failed.
            2018-01-12 23:59:23 140110908889280 [ERROR] InnoDB: Write to file ./ibdata1failed at offset 0, 16384 bytes should have been written, only 0 were written. Operating system error number 9. Check that your OS and file system support files of this size. Check also that the disk is not full or a disk quota exceeded.
            2018-01-12 23:59:23 140110908889280 [ERROR] InnoDB: Error number 9 means 'Bad file descriptor'
            2018-01-12 23:59:23 140110908889280 [Note] InnoDB: Some operating system error numbers are described at https://mariadb.com/kb/en/library/operating-system-error-codes/
            mariabackup: Could not open or create data files.
            mariabackup: If you tried to add new data files, and it failed here,
            mariabackup: you should now edit innodb_data_file_path in my.cnf back
            mariabackup: to what it was, and remove the new ibdata files InnoDB created
            mariabackup: in this failed attempt. InnoDB only wrote those files full of
            mariabackup: zeros, but did not yet use them in any way. But be careful: do not
            mariabackup: remove old data files which contain your precious data!
            mariabackup: error: xb_load_tablespaces() failed witherror code 39
            mariabackup: Stopping log copying thread.
            .
             
             
             
            The result from queries just before the failure was:
            CREATE TABLE t1(i INT) ENGINE INNODB;
            INSERT INTO t1 VALUES(1);
            CREATE TABLE t2(i int) ENGINE INNODB;
            CREATE DATABASE db2;
            USE db2;
            CREATE TABLE t1(i INT) ENGINE INNODB;
            USE test;
            # xtrabackup backup
             
             - saving '/dev/shm/var/1/log/mariabackup.partial_exclude/' to '/dev/shm/var/log/mariabackup.partial_exclude/'
             
            Retrying test mariabackup.partial_exclude, attempt(2/3)...
             
            worker[1] > Restart  - not started
            main.partition_binlog                    w2 [ pass ]    106
            worker[2] > Restart [mysqld.1 - pid: 32442, winpid: 32442] - running with different options '--loose-plugin-load-add=ha_mroonga.so --loose-plugin-mroonga=ON --log-bin=master-bin' != '--log-bin=master-bin --loose-enable-partition'
            mroonga/storage.binlog_TODO_SPLIT_ME     w2 [ pass ]     71
            worker[2] > Restart [mysqld.1 - pid: 32480, winpid: 32480] - running with different options '--log-bin=master-bin --tmp_table_size=1024' != '--loose-plugin-load-add=ha_mroonga.so --loose-plugin-mroonga=ON --log-bin=master-bin'
            mariabackup.partial_exclude              w1 [ retry-pass ]   1102
             
            Retrying test mariabackup.partial_exclude, attempt(3/3)...
             
            mariabackup.partial_exclude              w1 [ retry-pass ]   1078
            

            elenst Elena Stepanova added a comment - Looks similar, but with log (for now) http://buildbot.askmonty.org/buildbot/builders/kvm-deb-artful-amd64/builds/420/steps/mtr/logs/stdio mariabackup.partial_exclude w1 [ fail ] Test ended at 2018-01-12 23:59:24   CURRENT_TEST: mariabackup.partial_exclude mysqltest: At line 19: exec of '/usr/bin/mariabackup --defaults-file=/dev/shm/var/1/my.cnf --backup "--tables-exclude=test.*2" "--databases-exclude=db2" --target-dir=/dev/shm/var/1/tmp/backup 2>&1' failed, error: 256, status: 1, errno: 95 Output from before failure: 180112 23:59:23 Connecting to MySQL server host: localhost, user: root, password: set, port: 16000, socket: /dev/shm/var/tmp/1/mysqld.1.sock Using server version 10.2.13-MariaDB-10.2.13+maria~artful-log /usr/bin/mariabackup based on MariaDB server 10.2.13-MariaDB debian-linux-gnu (x86_64) mariabackup: uses posix_fadvise(). mariabackup: cd to /dev/shm/var/1/mysqld.1/data/ mariabackup: open files limit requested 1024, set to 1024 mariabackup: using the following InnoDB configuration: mariabackup: innodb_data_home_dir = . mariabackup: innodb_data_file_path = ibdata1:12M:autoextend mariabackup: innodb_log_group_home_dir = ./ 2018-01-12 23:59:23 140110908889280 [Note] InnoDB: Number of pools: 1 180112 23:59:23 >> log scanned up to (1685180) 2018-01-12 23:59:23 140110908889280 [Note] InnoDB: Log sequence number at the start 1668276 and the end 1682680 do not match 2018-01-12 23:59:23 140110908889280 [ERROR] InnoDB: Checksum mismatch in datafile: ./ibdata1, Space ID:0, Flags: 0. Please refer to http://dev.mysql.com/doc/refman/5.7/en/innodb-troubleshooting-datadict.html for how to resolve the issue. 2018-01-12 23:59:23 140110908889280 [Note] InnoDB: Restoring page [page id: space=0, page number=0] of datafile './ibdata1' from the doublewrite buffer. Writing 16384 bytes into file './ibdata1' 2018-01-12 23:59:23 140110908889280 [Warning] InnoDB: Retry attempts for writing partial data failed. 2018-01-12 23:59:23 140110908889280 [ERROR] InnoDB: Write to file ./ibdata1failed at offset 0, 16384 bytes should have been written, only 0 were written. Operating system error number 9. Check that your OS and file system support files of this size. Check also that the disk is not full or a disk quota exceeded. 2018-01-12 23:59:23 140110908889280 [ERROR] InnoDB: Error number 9 means 'Bad file descriptor' 2018-01-12 23:59:23 140110908889280 [Note] InnoDB: Some operating system error numbers are described at https://mariadb.com/kb/en/library/operating-system-error-codes/ mariabackup: Could not open or create data files. mariabackup: If you tried to add new data files, and it failed here, mariabackup: you should now edit innodb_data_file_path in my.cnf back mariabackup: to what it was, and remove the new ibdata files InnoDB created mariabackup: in this failed attempt. InnoDB only wrote those files full of mariabackup: zeros, but did not yet use them in any way. But be careful: do not mariabackup: remove old data files which contain your precious data! mariabackup: error: xb_load_tablespaces() failed witherror code 39 mariabackup: Stopping log copying thread. .       The result from queries just before the failure was: CREATE TABLE t1(i INT) ENGINE INNODB; INSERT INTO t1 VALUES(1); CREATE TABLE t2(i int) ENGINE INNODB; CREATE DATABASE db2; USE db2; CREATE TABLE t1(i INT) ENGINE INNODB; USE test; # xtrabackup backup   - saving '/dev/shm/var/1/log/mariabackup.partial_exclude/' to '/dev/shm/var/log/mariabackup.partial_exclude/'   Retrying test mariabackup.partial_exclude, attempt(2/3)...   worker[1] > Restart - not started main.partition_binlog w2 [ pass ] 106 worker[2] > Restart [mysqld.1 - pid: 32442, winpid: 32442] - running with different options '--loose-plugin-load-add=ha_mroonga.so --loose-plugin-mroonga=ON --log-bin=master-bin' != '--log-bin=master-bin --loose-enable-partition' mroonga/storage.binlog_TODO_SPLIT_ME w2 [ pass ] 71 worker[2] > Restart [mysqld.1 - pid: 32480, winpid: 32480] - running with different options '--log-bin=master-bin --tmp_table_size=1024' != '--loose-plugin-load-add=ha_mroonga.so --loose-plugin-mroonga=ON --log-bin=master-bin' mariabackup.partial_exclude w1 [ retry-pass ] 1102   Retrying test mariabackup.partial_exclude, attempt(3/3)...   mariabackup.partial_exclude w1 [ retry-pass ] 1078

            marko, can you check where this message comes from? I recall doublewrite was disabled in mariabackup in 10.1. There should not be "Restoring from doublewrite buffer", neither backup not prepare should ever use it.

            wlad Vladislav Vaintroub added a comment - marko , can you check where this message comes from? I recall doublewrite was disabled in mariabackup in 10.1. There should not be "Restoring from doublewrite buffer", neither backup not prepare should ever use it.

            one more
            https://buildbot.askmonty.org/buildbot/builders/kvm-bintar-quantal-x86/builds/10684/steps/test/logs/stdio

            CURRENT_TEST: mariabackup.mdev-14447
            180209 01:15:52 Connecting to MySQL server host: localhost, user: root, password: set, port: 16040, socket: /usr/local/mariadb-10.2.13-linux-i686/mysql-test/var/tmp/3/mysqld.1.sock
            Using server version 10.2.13-MariaDB-log
            /usr/local/mariadb-10.2.13-linux-i686/bin/mariabackup based on MariaDB server 10.2.13-MariaDB Linux (i686) 
            incremental backup from 1633659 is enabled.
            mariabackup: uses posix_fadvise().
            mariabackup: cd to /usr/local/mariadb-10.2.13-linux-i686/mysql-test/var/3/mysqld.1/data/
            mariabackup: open files limit requested 1024, set to 1024
            mariabackup: using the following InnoDB configuration:
            mariabackup:   innodb_data_home_dir = .
            mariabackup:   innodb_data_file_path = ibdata_first:3M;ibdata_second:1M:autoextend
            mariabackup:   innodb_log_group_home_dir = ./
            2018-02-09  1:15:53 3056838400 [Note] InnoDB: Number of pools: 1
            180209 01:15:53 >> log scanned up to (42087927)
            2018-02-09  1:15:53 3056838400 [Note] InnoDB: Log sequence number at the start 37713758 and the end 42087927 do not match
            2018-02-09  1:15:53 3056838400 [ERROR] InnoDB: Checksum mismatch in datafile: ./ibdata_first, Space ID:0, Flags: 0. Please refer to http://dev.mysql.com/doc/refman/5.7/en/innodb-troubleshooting-datadict.html for how to resolve the issue.
            2018-02-09  1:15:53 3056838400 [Note] InnoDB: Restoring page [page id: space=0, page number=0] of datafile './ibdata_first' from the doublewrite buffer. Writing 16384 bytes into file './ibdata_first'
            2018-02-09  1:15:53 3056838400 [Warning] InnoDB: Retry attempts for writing partial data failed.
            2018-02-09  1:15:53 3056838400 [ERROR] InnoDB: Write to file ./ibdata_firstfailed at offset 0, 16384 bytes should have been written, only 0 were written. Operating system error number 9. Check that your OS and file system support files of this size. Check also that the disk is not full or a disk quota exceeded.
            2018-02-09  1:15:53 3056838400 [ERROR] InnoDB: Error number 9 means 'Bad file descriptor'
            2018-02-09  1:15:53 3056838400 [Note] InnoDB: Some operating system error numbers are described at https://mariadb.com/kb/en/library/operating-system-error-codes/
            mariabackup: Could not open or create data files.
            mariabackup: If you tried to add new data files, and it failed here,
            mariabackup: you should now edit innodb_data_file_path in my.cnf back
            mariabackup: to what it was, and remove the new ibdata files InnoDB created
            mariabackup: in this failed attempt. InnoDB only wrote those files full of
            mariabackup: zeros, but did not yet use them in any way. But be careful: do not
            mariabackup: remove old data files which contain your precious data!
            mariabackup: error: xb_load_tablespaces() failed witherror code 39
            mariabackup: Stopping log copying thread.
            

            wlad Vladislav Vaintroub added a comment - one more https://buildbot.askmonty.org/buildbot/builders/kvm-bintar-quantal-x86/builds/10684/steps/test/logs/stdio CURRENT_TEST: mariabackup.mdev-14447 180209 01:15:52 Connecting to MySQL server host: localhost, user: root, password: set, port: 16040, socket: /usr/local/mariadb-10.2.13-linux-i686/mysql-test/var/tmp/3/mysqld.1.sock Using server version 10.2.13-MariaDB-log /usr/local/mariadb-10.2.13-linux-i686/bin/mariabackup based on MariaDB server 10.2.13-MariaDB Linux (i686) incremental backup from 1633659 is enabled. mariabackup: uses posix_fadvise(). mariabackup: cd to /usr/local/mariadb-10.2.13-linux-i686/mysql-test/var/3/mysqld.1/data/ mariabackup: open files limit requested 1024, set to 1024 mariabackup: using the following InnoDB configuration: mariabackup: innodb_data_home_dir = . mariabackup: innodb_data_file_path = ibdata_first:3M;ibdata_second:1M:autoextend mariabackup: innodb_log_group_home_dir = ./ 2018-02-09 1:15:53 3056838400 [Note] InnoDB: Number of pools: 1 180209 01:15:53 >> log scanned up to (42087927) 2018-02-09 1:15:53 3056838400 [Note] InnoDB: Log sequence number at the start 37713758 and the end 42087927 do not match 2018-02-09 1:15:53 3056838400 [ERROR] InnoDB: Checksum mismatch in datafile: ./ibdata_first, Space ID:0, Flags: 0. Please refer to http://dev.mysql.com/doc/refman/5.7/en/innodb-troubleshooting-datadict.html for how to resolve the issue. 2018-02-09 1:15:53 3056838400 [Note] InnoDB: Restoring page [page id: space=0, page number=0] of datafile './ibdata_first' from the doublewrite buffer. Writing 16384 bytes into file './ibdata_first' 2018-02-09 1:15:53 3056838400 [Warning] InnoDB: Retry attempts for writing partial data failed. 2018-02-09 1:15:53 3056838400 [ERROR] InnoDB: Write to file ./ibdata_firstfailed at offset 0, 16384 bytes should have been written, only 0 were written. Operating system error number 9. Check that your OS and file system support files of this size. Check also that the disk is not full or a disk quota exceeded. 2018-02-09 1:15:53 3056838400 [ERROR] InnoDB: Error number 9 means 'Bad file descriptor' 2018-02-09 1:15:53 3056838400 [Note] InnoDB: Some operating system error numbers are described at https://mariadb.com/kb/en/library/operating-system-error-codes/ mariabackup: Could not open or create data files. mariabackup: If you tried to add new data files, and it failed here, mariabackup: you should now edit innodb_data_file_path in my.cnf back mariabackup: to what it was, and remove the new ibdata files InnoDB created mariabackup: in this failed attempt. InnoDB only wrote those files full of mariabackup: zeros, but did not yet use them in any way. But be careful: do not mariabackup: remove old data files which contain your precious data! mariabackup: error: xb_load_tablespaces() failed witherror code 39 mariabackup: Stopping log copying thread.

            I pushed a simple clean-up patch to prevent any potential disaster (writing to a source file in --backup). It probably does not prevent any disaster, because we would have opened the source files in read-only mode, and the writes were blocked by that.

            thiru, please try to reproduce this problem. It probably is most feasible with DBUG_EXECUTE_IF("backup_read_page_fail", …) and something like

            mariabackup --backup --dbug=d,xxx
            

            Implement appropriate retry logic when a data file page appears corrupted. Test this with the system tablespace, the undo tablespace files, and with .ibd files, both with the first page and with some subsequent page (say, page 1).

            At least in the function xb_load_single_table_tablespace() we should try rereading, and we should not call exit(EXIT_FAILURE) but instead return any errors to the caller. Also, we could try to tolerate missing files, because the user could be executing DROP TABLE or RENAME TABLE in parallel with the backup.

            Once you have worked on the 10.2 fix, you should be able to tell if this fix is needed in Mariabackup 10.1.

            marko Marko Mäkelä added a comment - I pushed a simple clean-up patch to prevent any potential disaster (writing to a source file in --backup ). It probably does not prevent any disaster, because we would have opened the source files in read-only mode, and the writes were blocked by that. thiru , please try to reproduce this problem. It probably is most feasible with DBUG_EXECUTE_IF("backup_read_page_fail", …) and something like mariabackup --backup --dbug=d,xxx Implement appropriate retry logic when a data file page appears corrupted. Test this with the system tablespace, the undo tablespace files, and with .ibd files, both with the first page and with some subsequent page (say, page 1). At least in the function xb_load_single_table_tablespace() we should try rereading, and we should not call exit(EXIT_FAILURE) but instead return any errors to the caller. Also, we could try to tolerate missing files, because the user could be executing DROP TABLE or RENAME TABLE in parallel with the backup. Once you have worked on the 10.2 fix, you should be able to tell if this fix is needed in Mariabackup 10.1.

            I pushed a cleanup that removes Mariabackup use of the doublewrite buffer to MariaDB 10.2.13. With that fix merged, a test failed in bb-10.2-ext:

            CURRENT_TEST: mariabackup.apply-log-only-incr
            mysqltest: At line 21: exec of '/usr/bin/mariabackup --defaults-file=/dev/shm/var/2/my.cnf  --backup --target-dir=/dev/shm/var/2/tmp/backup 2>&1' failed, error: 256, status: 1, errno: 11
            Output from before failure:
            180213 19:29:11 Connecting to MySQL server host: localhost, user: root, password: set, port: 16040, socket: /dev/shm/var/tmp/2/mysqld.1.sock
            Using server version 10.2.13-MariaDB-10.2.13+maria~xenial-log
            /usr/bin/mariabackup based on MariaDB server 10.2.13-MariaDB debian-linux-gnu (i686) 
            mariabackup: uses posix_fadvise().
            mariabackup: cd to /dev/shm/var/2/mysqld.1/data/
            mariabackup: open files limit requested 1024, set to 1024
            mariabackup: using the following InnoDB configuration:
            mariabackup:   innodb_data_home_dir = .
            mariabackup:   innodb_data_file_path = ibdata1:12M:autoextend
            mariabackup:   innodb_log_group_home_dir = ./
            2018-02-13 19:29:11 3068540864 [Note] InnoDB: Number of pools: 1
            180213 19:29:11 >> log scanned up to (1647154)
            2018-02-13 19:29:11 3068540864 [Note] InnoDB: Log sequence number at the start 1638095 and the end 1642519 do not match
            2018-02-13 19:29:11 3068540864 [ERROR] InnoDB: Checksum mismatch in datafile: ./ibdata1, Space ID:0, Flags: 0. Please refer to http://dev.mysql.com/doc/refman/5.7/en/innodb-troubleshooting-datadict.html for how to resolve the issue.
            

            Just like I anticipated in my previous comment, Mariabackup fails to reread the page.
            Apparently the last two writes of the first page of ibdata1 took place at LSN 1638095 and 1642519, and the Mariabackup read operation of the page was interleaved with the page write operation by the server, causing the FIL_PAGE_LSN in the page header to differ from the LSN stored in the page trailer.

            marko Marko Mäkelä added a comment - I pushed a cleanup that removes Mariabackup use of the doublewrite buffer to MariaDB 10.2.13. With that fix merged, a test failed in bb-10.2-ext : CURRENT_TEST: mariabackup.apply-log-only-incr mysqltest: At line 21: exec of '/usr/bin/mariabackup --defaults-file=/dev/shm/var/2/my.cnf --backup --target-dir=/dev/shm/var/2/tmp/backup 2>&1' failed, error: 256, status: 1, errno: 11 Output from before failure: 180213 19:29:11 Connecting to MySQL server host: localhost, user: root, password: set, port: 16040, socket: /dev/shm/var/tmp/2/mysqld.1.sock Using server version 10.2.13-MariaDB-10.2.13+maria~xenial-log /usr/bin/mariabackup based on MariaDB server 10.2.13-MariaDB debian-linux-gnu (i686) mariabackup: uses posix_fadvise(). mariabackup: cd to /dev/shm/var/2/mysqld.1/data/ mariabackup: open files limit requested 1024, set to 1024 mariabackup: using the following InnoDB configuration: mariabackup: innodb_data_home_dir = . mariabackup: innodb_data_file_path = ibdata1:12M:autoextend mariabackup: innodb_log_group_home_dir = ./ 2018-02-13 19:29:11 3068540864 [Note] InnoDB: Number of pools: 1 180213 19:29:11 >> log scanned up to (1647154) 2018-02-13 19:29:11 3068540864 [Note] InnoDB: Log sequence number at the start 1638095 and the end 1642519 do not match 2018-02-13 19:29:11 3068540864 [ERROR] InnoDB: Checksum mismatch in datafile: ./ibdata1, Space ID:0, Flags: 0. Please refer to http://dev.mysql.com/doc/refman/5.7/en/innodb-troubleshooting-datadict.html for how to resolve the issue. Just like I anticipated in my previous comment, Mariabackup fails to reread the page. Apparently the last two writes of the first page of ibdata1 took place at LSN 1638095 and 1642519, and the Mariabackup read operation of the page was interleaved with the page write operation by the server, causing the FIL_PAGE_LSN in the page header to differ from the LSN stored in the page trailer.

            According to the cross-reference, the last regular failures of the mentioned tests in main branches occurred in 2018. The bogus use of the doublewrite buffer was removed in MariaDB 10.2.13.

            The probability of intermittent failures should have been drastically reduced by MDEV-12699 (in 2019) and some related changes.

            marko Marko Mäkelä added a comment - According to the cross-reference, the last regular failures of the mentioned tests in main branches occurred in 2018. The bogus use of the doublewrite buffer was removed in MariaDB 10.2.13. The probability of intermittent failures should have been drastically reduced by MDEV-12699 (in 2019) and some related changes.

            People

              marko Marko Mäkelä
              elenst Elena Stepanova
              Votes:
              0 Vote for this issue
              Watchers:
              4 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.