Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-19813 Aria crash recovery failures
  3. MDEV-18187

Aria engine: Redo phase failed with "error 192 when executing record redo_index_new_page" upon startup on a restored datadir

    XMLWordPrintable

Details

    Description

      10.4 30da40bb8c

      2019-01-09 16:00:40 0 [Note] mysqld: Aria engine: starting recovery
      recovered pages: 0%
      2019-01-09 16:00:40 0 [ERROR] mysqld: failed to decrypt './test/t7'  rc: -1  dstlen: 0  size: 4294967275
       
      Got error 192 when executing record redo_index_new_page
      2019-01-09 16:00:40 0 [ERROR] mysqld: Aria engine: Redo phase failed
      tables to flush: 9 8 7 6 5 4 3 2 1 0
      2019-01-09 16:00:40 0 [ERROR] mysqld: Aria recovery failed. Please run aria_chk -r on all Aria tables and delete all aria_log.######## files
      2019-01-09 16:00:40 0 [ERROR] Plugin 'Aria' init function returned error.
      2019-01-09 16:00:40 0 [ERROR] Plugin 'Aria' registration as a STORAGE ENGINE failed.
      

      The backup dir (stored after prepare but before any server startup was attempted) is here:
      ftp://ftp.askmonty.org/public/mdev18187-backup.tar.gz

      To reproduce the failure, restore it to the datadir and start the server with

      --innodb-encrypt-tables --innodb-encrypt-log --innodb-encryption-threads=4 --aria-encrypt-tables=1 --encrypt-tmp-
      disk-tables=1 --plugin-load-add=file_key_management --file-key-management --file-key-management-filename=`pwd`/mysql-test/std_data/keys.txt
      

      (modify file-key-management-filename value as needed).


      Notes on the origin of the report. Please be aware it's not necessarily reproducible the same way.
      https://travis-ci.org/elenst/travis-tests/jobs/477279304

      The problem initially happened by running the concurrent test with MariaBackupFull scenario:

      elenst-jira-refs 5342873c9, mariadb-toolbox 6ded4b71568

      perl ./runall-new.pl --basedir=/home/travis/server --vardir=/home/travis/logs/vardir --duration=350 --threads=4 --seed=1547032472 --reporters=Backtrace,ErrorLog,Deadlock --skip-gendata --gendata-advanced --views --grammar=conf/mariadb/generic-dml.yy --redefine=conf/mariadb/bulk_insert.yy --mysqld=--log_output=FILE --mysqld=--max-statement-time=20 --mysqld=--lock-wait-timeout=10 --mysqld=--loose-innodb-lock-wait-timeout=5 --mysqld=--loose-debug_assert_on_not_freed_memory=0 --filter=/home/travis/mariadb-toolbox/travis/10.4-combo-filter.ff --mysqld=--innodb-encrypt-tables --mysqld=--innodb-encrypt-log --mysqld=--innodb-encryption-threads=4 --mysqld=--aria-encrypt-tables=1 --mysqld=--encrypt-tmp-disk-tables=1 --mysqld=--file-key-management --mysqld=--file-key-management-filename=/home/travis/mariadb-toolbox/data/keys.txt --mysqld=--plugin-load-add=file_key_management --engine=Aria --scenario=MariaBackupFull
      

      The test performs the following steps:

      • start the server with

        --no-defaults --basedir=/home/travis/server --lc-messages-dir=/home/travis/server/share --character-sets-dir=/home/travis/server/share/charsets --tmpdir=/home/travis/logs/vardir/tmp --core-file --datadir=/home/travis/logs/vardir/data --max-allowed-packet=128Mb --port=19300 --socket=/home/travis/logs/vardir/mysql.sock --pid-file=/home/travis/logs/vardir/mysql.pid --general-log --general-log-file=/home/travis/logs/vardir/mysql.log --log_output=FILE --max-statement-time=20 --lock-wait-timeout=10 --loose-innodb-lock-wait-timeout=5 --loose-debug_assert_on_not_freed_memory=0 --innodb-encrypt-tables --innodb-encrypt-log --innodb-encryption-threads=4 --aria-encrypt-tables=1 --encrypt-tmp-disk-tables=1 --file-key-management --file-key-management-filename=/home/travis/mariadb-toolbox/data/keys.txt --plugin-load-add=file_key_management
        

      • run concurrent DML/DDL flow on the server;
      • after ~100 seconds, take the full backup from the running server (succeeded, the log attached as mbackup_backup.log;
      • after another ~100 seconds, shut down the server gracefully (succeeded, the error log is attached as mysql.err_orig;
      • run mariabackup --prepare (succeded, the log attached as mbackup_prepare.log;
      • cleanup server datadir and restore the backup to it (succeeded, the log attached as mbackup_restore.log;
      • try to start the server with the same options as before.

      I have no information yet whether the problem happens on earlier versions.

      Attachments

        1. mysql.err_orig
          4 kB
          Elena Stepanova
        2. mysql.err
          11 kB
          Elena Stepanova
        3. mbackup_restore.log
          18 kB
          Elena Stepanova
        4. mbackup_prepare.log
          2 kB
          Elena Stepanova
        5. mbackup_backup.log
          21 kB
          Elena Stepanova

        Issue Links

          Activity

            People

              monty Michael Widenius
              elenst Elena Stepanova
              Votes:
              0 Vote for this issue
              Watchers:
              5 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.