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

mariadb-backup --prepare fails to prepare a backup that involves DDL

    XMLWordPrintable

Details

    Description

      Hi

      Last Saturday, I migrated from 10.5 to 10.8.3, and since then, the backups created by mariabackup daily seem to always fail when trying to prepare them.

      The destination server (tried Docker and an actual server with similar specs to the original live server) also runs 10.8.3.

      This worries me because if I have an actual crash and need to restore from a backup, I may not be able to recover.

      —

      These new table extensions listed below are all tables that have been re-created and then swapped with the old ones, during the day.

      At the end of these logs, you can see it crashes due to "Attempted to open a previously opened tablespace. Previous tablespace:"

      On the actual server, the logs are very similar, except that I used 3G memory (instead of 10GB) and if failed on a later table (also in the list of renames).
      But otherwise, same symptoms.

      This never happened before, with 10.5.

      –

      Docker logs:

      mariabackup based on MariaDB server 10.8.3-MariaDB Linux (x86_64)
      		 
      [00] 2022-06-28 08:02:43 cd to /var/lib/mysql/
      		 
      [00] 2022-06-28 08:02:43 open files limit requested 0, set to 1048576
      		 
      [00] 2022-06-28 08:02:44 Renaming ./db_mydb1/tbl1_data1.new to ./db_mydb1/tbl1_data1.ibd
      		 
      [00] 2022-06-28 08:02:44 Renaming ./db_mydb1/tbl1_level2.new to ./db_mydb1/tbl1_level2.ibd
      		 
      [00] 2022-06-28 08:02:44 Renaming ./db_mydb1/tbl1_webclient.new to ./db_mydb1/tbl1_webclient.ibd
      		 
      [00] 2022-06-28 08:02:44 Renaming ./db_mydb1/tbl1_tbl2.new to ./db_mydb1/tbl1_tbl2.ibd
      		 
      [00] 2022-06-28 08:02:44 Renaming ./db_mydb1/tbl_c_data4.new to ./db_mydb1/tbl_c_data4.ibd
      		 
      [00] 2022-06-28 08:02:44 Renaming ./db_mydb1/aws_data4.new to ./db_mydb1/aws_data4.ibd
      		 
      [00] 2022-06-28 08:02:44 Renaming ./db_mydb1/tbl_a_data4.new to ./db_mydb1/tbl_a_data4.ibd
      		 
      [00] 2022-06-28 08:02:44 Renaming ./db_mydb1/tbl_d_data3.new to ./db_mydb1/tbl_d_data3.ibd
      		 
      [00] 2022-06-28 08:02:44 Renaming ./db_mydb1/tbl_d_data5.new to ./db_mydb1/tbl_d_data5.ibd
      		 
      [00] 2022-06-28 08:02:44 Renaming ./db_mydb1/tbl3.new to ./db_mydb1/tbl3.ibd
      		 
      [00] 2022-06-28 08:02:44 Renaming ./db_mydb1/tbl1_webserver.new to ./db_mydb1/tbl1_webserver.ibd
      		 
      [00] 2022-06-28 08:02:44 Renaming ./db_mydb1/tbl1_level3.new to ./db_mydb1/tbl1_level3.ibd
      		 
      [00] 2022-06-28 08:02:44 Renaming ./db_mydb1/tbl_a_data3.new to ./db_mydb1/tbl_a_data3.ibd
      		 
      [00] 2022-06-28 08:02:44 Renaming ./db_mydb1/tbl_d_data4.new to ./db_mydb1/tbl_d_data4.ibd
      		 
      [00] 2022-06-28 08:02:44 Renaming ./db_mydb1/tbl1_level1.new to ./db_mydb1/tbl1_level1.ibd
      		 
      [00] 2022-06-28 08:02:44 Renaming ./db_mydb1/tbl_highrisk.new to ./db_mydb1/tbl_highrisk.ibd
      		 
      [00] 2022-06-28 08:02:44 Renaming ./db_mydb1/tbl_data2.new to ./db_mydb1/tbl_data2.ibd
      		 
      [00] 2022-06-28 08:02:44 Renaming ./db_mydb1/tor_ips.new to ./db_mydb1/tor_ips.ibd
      		 
      [00] 2022-06-28 08:02:44 Renaming ./db_mydb1/tbl_c_data3.new to ./db_mydb1/tbl_c_data3.ibd
      		 
      [00] 2022-06-28 08:02:44 Renaming ./db_mydb1/tbl1_data6_1d.new to ./db_mydb1/tbl1_data6_1d.ibd
      		 
      [00] 2022-06-28 08:02:44 Renaming ./db_mydb1/aws_data3.new to ./db_mydb1/aws_data3.ibd
      		 
      [00] 2022-06-28 08:02:44 Renaming ./db_mydb2_archive/tbl10_internal.new to ./db_mydb2_archive/tbl10_internal.ibd
      		 
      [00] 2022-06-28 08:02:44 Renaming ./db_mydb2_archive/tbl10.new to ./db_mydb2_archive/tbl10.ibd
      		 
      [00] 2022-06-28 08:02:44 This target seems to be not prepared yet.
      		 
      [00] 2022-06-28 08:02:44 mariabackup: using the following InnoDB configuration for recovery:
      		 
      [00] 2022-06-28 08:02:44 innodb_data_home_dir = .
      		 
      [00] 2022-06-28 08:02:44 innodb_data_file_path = ibdata1:12M:autoextend
      		 
      [00] 2022-06-28 08:02:44 innodb_log_group_home_dir = .
      		 
      [00] 2022-06-28 08:02:44 InnoDB: Using Linux native AIO
      		 
      [00] 2022-06-28 08:02:44 Starting InnoDB instance for recovery.
      		 
      [00] 2022-06-28 08:02:44 mariabackup: Using 10737418240 bytes for buffer pool (set by --use-memory parameter)
      		 
      2022-06-28  8:02:44 0 [Note] InnoDB: Compressed tables use zlib 1.2.7
      		 
      2022-06-28  8:02:44 0 [Note] InnoDB: Number of transaction pools: 1
      		 
      2022-06-28  8:02:44 0 [Note] InnoDB: Using crc32 + pclmulqdq instructions
      		 
      2022-06-28  8:02:44 0 [Note] InnoDB: Using Linux native AIO
      		 
      2022-06-28  8:02:44 0 [Note] InnoDB: Initializing buffer pool, total size = 10.000GiB, chunk size = 10.000GiB
      		 
      2022-06-28  8:02:44 0 [Note] InnoDB: Completed initialization of buffer pool
      		 
      2022-06-28  8:02:44 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=10124335601183
      		 
      2022-06-28  8:02:59 0 [Note] InnoDB: Read redo log up to LSN=10125491182709
      		 
      2022-06-28  8:03:14 0 [Note] InnoDB: Read redo log up to LSN=10126769017887
      		 
      2022-06-28  8:03:29 0 [Note] InnoDB: Read redo log up to LSN=10125566511156
      		 
      2022-06-28  8:03:44 0 [Note] InnoDB: Read redo log up to LSN=10127351889951
      		 
      2022-06-28  8:03:46 0 [Note] InnoDB: Starting a batch to recover 249655 pages from redo log.
      		 
      2022-06-28  8:05:44 0 [Note] InnoDB: Read redo log up to LSN=10127544782324
      		 
      2022-06-28  8:05:45 0 [ERROR] InnoDB: Attempted to open a previously opened tablespace. Previous tablespace: ./db_mydb1/tbl_a_data4.ibd uses space ID: 283158. Cannot open filepath: db_mydb1/tbl_a_data4.ibd which uses the same space ID.
      		 
      2022-06-28  8:05:45 0 [Warning] InnoDB: We do not continue the crash recovery, because the table may become corrupt if we cannot apply the log records in the InnoDB log to it. To fix the problem and start mariadbd:
      		 
      2022-06-28  8:05:45 0 [Note] InnoDB: 1) If there is a permission problem in the file and mysqld cannot open the file, you should modify the permissions.
      		 
      2022-06-28  8:05:45 0 [Note] InnoDB: 2) If the tablespace is not needed, or you can restore an older version from a backup, then you can remove the .ibd file, and use --innodb_force_recovery=1 to force startup without this file.
      		 
      2022-06-28  8:05:45 0 [Note] InnoDB: 3) If the file system or the disk is broken, and you cannot remove the .ibd file, you can set --innodb_force_recovery.
      		 
      [00] 2022-06-28 08:05:45 mariadb-backup: srv_start() returned 11 (Generic error).

      –

      Actual server (slightly different):

      2022-06-28 16:16:57 0 [Note] InnoDB: Initializing buffer pool, total size = 3.000GiB, chunk size = 3.000GiB
      		 
      2022-06-28 16:16:57 0 [Note] InnoDB: Completed initialization of buffer pool
      		 
      2022-06-28 16:16:57 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=10124335601183
      		 
      2022-06-28 16:17:12 0 [Note] InnoDB: Read redo log up to LSN=10125664839619
      		 
      2022-06-28 16:17:12 0 [Note] InnoDB: Starting a batch to recover 155833 pages from redo log.
      		 
      2022-06-28 16:18:18 0 [Note] InnoDB: Read redo log up to LSN=10125853282335
      		 
      2022-06-28 16:18:23 0 [Note] InnoDB: Starting a batch to recover 88042 pages from redo log.
      		 
      2022-06-28 16:19:06 0 [Note] InnoDB: Read redo log up to LSN=10126641181182
      		 
      2022-06-28 16:19:06 0 [ERROR] InnoDB: Attempted to open a previously opened tablespace. Previous tablespace: ./db_mydb1/tbl_a_data4.ibd uses space ID: 283140. Cannot open filepath: db_mydb1/tbl_a_data4.ibd which uses the same space ID.
      		 
      2022-06-28 16:19:06 0 [Warning] InnoDB: We do not continue the crash recovery, because the table may become corrupt if we cannot apply the log records in the InnoDB log to it. To fix the problem and start mariadbd:
      		 
      2022-06-28 16:19:06 0 [Note] InnoDB: 1) If there is a permission problem in the file and mysqld cannot open the file, you should modify the permissions.
      		 
      2022-06-28 16:19:06 0 [Note] InnoDB: 2) If the tablespace is not needed, or you can restore an older version from a backup, then you can remove the .ibd file, and use --innodb_force_recovery=1 to force startup without this file.
      		 
      2022-06-28 16:19:06 0 [Note] InnoDB: 3) If the file system or the disk is broken, and you cannot remove the .ibd file, you can set --innodb_force_recovery.
      		 
      [00] 2022-06-28 16:19:06 mariadb-backup: srv_start() returned 11 (Generic error).

      Attachments

        Issue Links

          causes

          Bug - A problem which impairs or prevents the functions of the product. MDEV-29282 atomic.rename_trigger fails occasionally

          • Major - Major loss of function.
          • Closed
          is caused by

          Bug - A problem which impairs or prevents the functions of the product. MDEV-24626 Remove synchronous write of page0 and flushing file during file creation

          • Blocker - Blocks development and/or testing work, production could not run.
          • Closed

          Activity

            People

              marko Marko Mäkelä
              nunop Nuno
              Votes:
              1 Vote for this issue
              Watchers:
              6 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.