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

InnoDB: Database page corruption on disk or a failed file read of tablespace upon prepare of mariabackup incremental backup

    XMLWordPrintable

    Details

      Description

      Note: Can't be a duplicate of MDEV-19348 anymore, as it was closed in the previous release set.

      10.2 5e65c67c

      ...
      2019-10-05  3:25:49 140645837592384 [Note] InnoDB: Ignoring data file 'test/t1.ibd' with space ID 275, since the redo log references test/t1.ibd with space ID 274.
      2019-10-05  3:25:49 140645837592384 [Note] InnoDB: Ignoring data file './test/#sql-2a07_12.ibd' with space ID 275. Another data file called test/t1.ibd exists with the same space ID.
      2019-10-05  3:25:49 140645837592384 [Note] InnoDB: Ignoring data file './test/#sql-2a07_12.ibd' with space ID 275. Another data file called test/t1.ibd exists with the same space ID.
      2019-10-05  3:25:49 140645837592384 [Warning] InnoDB: Are you sure you are using the right ib_logfiles to start up the database? Log sequence number in the ib_logfiles is 2570499, less than the log sequence number in the first system tablespace file header, 2570528.
      2019-10-05  3:25:49 140645837592384 [Note] InnoDB: Starting final batch to recover 963 pages from redo log.
      2019-10-05  3:25:49 140645669078784 [ERROR] InnoDB: Database page corruption on disk or a failed file read of tablespace test/t1 page [page id: space=275, page number=3]. You may have to recover from a backup.
      2019-10-05  3:25:49 140645669078784 [Note] InnoDB: Uncompressed page, stored checksum in field1 3500439468, calculated checksums for field1: crc32 228036971, innodb 3302731224,  page type 17855 == INDEX.none 3735928559, stored checksum in field2 3500439468, calculated checksums for field2: crc32 228036971, innodb 3703238392, none 3735928559,  page LSN 0 3445649, low 4 bytes of LSN at page end 3445649, page number (if stored to page already) 3, space id (if created with >= MySQL-4.1.1 and stored already) 275
      2019-10-05  3:25:49 140645669078784 [Note] InnoDB: Page may be an index page where index id is 8202515128101958035
      2019-10-05  3:25:49 140645669078784 [Note] InnoDB: It is also possible that your operating system has corrupted its own file cache and rebooting your computer removes the error. If the corrupt page is an index page. You can also try to fix the corruption by dumping, dropping, and reimporting the corrupt table. You can use CHECK TABLE to scan your table for corruption. Please refer to https://mariadb.com/kb/en/library/innodb-recovery-modes/ for information about forcing recovery.
      2019-10-05  3:25:49 140645669078784 [ERROR] InnoDB: Failed to read file 'test/t1.ibd' at offset 3: Page read from tablespace is corrupted.
      2019-10-05  3:25:50 140645837592384 [Note] InnoDB: Set innodb_force_recovery=1 to ignore corrupted pages.
      2019-10-05  3:25:50 140645837592384 [ERROR] InnoDB: Plugin initialization aborted at srv0start.cc[2250] with error Data structure corruption
      [00] FATAL ERROR: 2019-10-05 03:25:50 mariabackup: innodb_init() returned 39 (Data structure corruption).
      

      The test case is non-deterministic, run with --repeat=N and other options listed below. It usually fails for me within 5 attempts, but it can vary on different machines and builds. The probability seems higher with larger number of tables, columns and data. Running in shm also seems to help.

      MTR command line

      perl ./mtr bug2.innodb_page_corrupt2 --mysqld=--innodb-encrypt-tables --mysqld=--innodb-encrypt-log --mysqld=--innodb-encryption-threads=4  --mysqld=--file-key-management --mysqld=--file-key-management-filename=`pwd`/std_data/keys.txt --mysqld=--plugin-load-add=file_key_management --mem --repeat=5
      

      --source include/have_innodb.inc
       
      CREATE TABLE t1 (a BINARY(8), b CHAR(8), c INT) ENGINE=InnoDB;
      INSERT INTO t1 VALUES ('a','foobar',8);
       
      --exec $XTRABACKUP --backup --target-dir=$MYSQLTEST_VARDIR/tmp/backup_0 --protocol=tcp --port=$MASTER_MYPORT --user=root > $MYSQLTEST_VARDIR/log/backup0.log 2>&1
       
      --connect (con1,localhost,root,,)
      --let $conid= `SELECT CONNECTION_ID() AS con14`
      --delimiter |
      --send
        BEGIN NOT ATOMIC
          LOOP OPTIMIZE TABLE t1;
          END LOOP;
        END |
      --delimiter ;
       
      --connection default
       
      --exec $XTRABACKUP --backup --target-dir=$MYSQLTEST_VARDIR/tmp/backup_1 --incremental-basedir=$MYSQLTEST_VARDIR/tmp/backup_0 --protocol=tcp --port=$MASTER_MYPORT --user=root > $MYSQLTEST_VARDIR/log/backup1.log 2>&1
       
      --eval KILL $conid
       
      --exec $XTRABACKUP --prepare --apply-log-only --target-dir=$MYSQLTEST_VARDIR/tmp/backup_0 > $MYSQLTEST_VARDIR/log/prepare0.log 2>&1
      --error 0,1
      --exec $XTRABACKUP --prepare --apply-log-only --target-dir=$MYSQLTEST_VARDIR/tmp/backup_0 --incremental-dir=$MYSQLTEST_VARDIR/tmp/backup_1 > $MYSQLTEST_VARDIR/log/prepare1.log 2>&1
       
      if ($sys_errno)
      {
          --cat_file $MYSQLTEST_VARDIR/log/prepare1.log
          --die "Encountered error upon incremental backup"
      }
       
      # Cleanup
      DROP TABLE t1;
      --rmdir $MYSQLTEST_VARDIR/tmp/backup_0
      --rmdir $MYSQLTEST_VARDIR/tmp/backup_1
      

      Fails on 10.2-10.4, all of debug, ASAN, non-debug builds.
      10.1 fails with something irrelevant, I didn't pursue it.
      Couldn't reproduce on 10.5.

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              vlad.lesin Vladislav Lesin
              Reporter:
              elenst Elena Stepanova
              Votes:
              1 Vote for this issue
              Watchers:
              7 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved: