Details
-
Bug
-
Status: Closed (View Workflow)
-
Critical
-
Resolution: Fixed
-
10.4.20, 10.6.8
-
COLO running CentOS Linux release 7.9.2009 (Core)
Description
User upgraded from MariaDB Community Server 10.2 to 10.4. User had setup automation to check output of mariabackup --prepare to ensure no errors occurred which could imperil the health of the backup.
The basic procedure is to take a partial backup using tables-exclude or similar. Prepare is then performed with export.
In general, mariabackup does not seem to explicitly track what tables were excluded between backup and prepare steps. In 10.2, during prepare export we see-
2022-07-06 18:01:51 140608802916480 [Warning] InnoDB: Tablespace 5 was not found at ./mariadbslap/Slap2.ibd when restoring a (partial?) backup. All redo log for this file will be ignored!
|
To be clear, the backup stage for the above log snippet used tables-exclude='Slap2' successfully. The good news for 10.2 is this is flagged as a Warning, recognizing that prepare export simply does not know if this is a problem or not and it may be legitimate/intended behavior.
10.4 (possibly 10.3; most explicitly, possibly 10.3.5) changes this for the worse-
2022-07-06 17:00:51 0 [ERROR] InnoDB: Operating system error number 2 in a file operation.
|
2022-07-06 17:00:51 0 [ERROR] InnoDB: The error means the system cannot find the path specified.
|
2022-07-06 17:00:51 0 [ERROR] InnoDB: If you are installing InnoDB, remember that you must create directories yourself, InnoDB does not create them.
|
2022-07-06 17:00:51 0 [ERROR] InnoDB: Cannot open datafile for read-only: './mariadbslap/Slap2.ibd' OS error: 71
|
2022-07-06 17:00:51 0 [ERROR] InnoDB: Operating system error number 2 in a file operation.
|
2022-07-06 17:00:51 0 [ERROR] InnoDB: The error means the system cannot find the path specified.
|
2022-07-06 17:00:51 0 [ERROR] InnoDB: If you are installing InnoDB, remember that you must create directories yourself, InnoDB does not create them.
|
2022-07-06 17:00:51 0 [ERROR] InnoDB: Could not find a valid tablespace file for ``mariadbslap`.`Slap2``. Please refer to https://mariadb.com/kb/en/innodb-data-dictionary-troubleshooting/ for how to resolve the issue.
|
So now in 10.4, it is referencing the same table which 10.2 identified, but instead of throwing a WARNING, 10.4 is putting an ERROR into its output. While it seems both 10.2 and 10.4 return 0 indicating a successful process exit, users practicing due diligence are rightly going to see an ERROR entry and figure out what to do about it. Between the 10.2 and 10.4 behaviors, the 10.2 behavior of flagging this as a WARNING is preferable because it differentiates the issue from breaking errors, especially given this is just expected partial backup operation. And while the specific concern being expressed here is for how this makes life difficult for automation, it is also worth pointing out that 10.4's behavior makes it less clear than 10.2 does for what is going on and what may be the cause, such that it is likely to cause even experienced DBAs who have not encountered this situation yet cause to panic and worry that their partial backup is broken.
In an ideal case though, no errors or warnings should be thrown for table files which are missing due to exclusions made during mariabackup backup. According to our KB documentation for --tables-exclude-
If a backup is a partial backup, then Mariabackup will record that detail in the xtrabackup_info file.
In short, mariabackup currently advertises retaining this information for it to use later. This is the behavior we would like to see mariabackup prepare export provide.
The problematic behavior can be reproduced via the following steps on MariaDB Community Server 10.6.8:
# Note that binary logging must be enabled and active in the MariaDB Server instance for this to work
|
mariabackup_password='securePasswordHere'; |
backup_path='/where/i/want/my/backup/to/go; |
backup_log='/where/i/want/my/prepre/log/to/go; |
|
|
mariadb -e "CREATE USER 'mariabackup'@'localhost' IDENTIFIED BY '${mariabackup_password}';"; |
mariadb -e "GRANT RELOAD, PROCESS, LOCK TABLES, BINLOG MONITOR ON *.* TO 'mariabackup'@'localhost';"; |
|
|
# Create database and tables
|
mariadb -e 'CREATE DATABASE mariadbslap'; |
mariadb mariadbslap -e 'CREATE TABLE Slap (i int);'; |
mariadb mariadbslap -e 'CREATE TABLE Slap2 (i int);'; |
|
|
# Create some writes on the table
|
for ((i=1; i<2000; i++)) ; do |
# Once the workload has gotten a little bit in... |
if (($i == 100)) ; then |
# Start a backup in parallel so writes can continue to roll in during the backup (forces mariabackup to need to leverage logs to obtain point in time consistency during prepare later on) |
mariabackup --backup -u mariabackup -p"${mariabackup_password}" --target-dir="${backup_path}" --tables-exclude='Slap2' & |
fi; |
|
|
# Generate writes on both the included and excluded tables |
mariadb mariadbslap -e 'INSERT INTO Slap VALUES ('"${i}"');'; |
mariadb mariadbslap -e 'INSERT INTO Slap2 VALUES ('"${i}"');'; |
done; |
|
|
# Prepare the backup
|
mariabackup --export --prepare -u mariabackup -p"${mariabackup_password}" --target-dir="${backup_path}" 2>&1 | tee "${backup_log}"; |
In the output for the last mariabackup command you should see [ERROR] InnoDB: Operating system error number 2 in a file operation..
You can adapt the above procedure for Community Server 10.2 by adjusting the mariabackup user GRANT to-
GRANT RELOAD, PROCESS, LOCK TABLES, REPLICATION CLIENT ON *.* TO 'mariabackup'@'localhost'; |
The process is otherwise the same and should output a WARNING instead of an ERROR.
A .zip is attached with log output from backup and {{prepare}] commands run from the above procedure for MariaDB versions 10.2.27, 10.2.43, 10.4.20, and 10.6.8.
Attachments
Issue Links
- relates to
-
-
- Open
-
- mentioned in
-
Page Failed to load
-
Page Failed to load
-
Page Failed to load
-
Page Failed to load
-
Page Loading...
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
-
Activity
thejaka, I think that it would be better to adjust the low-level code that triggers the error than to duplicate some logic. I think that a better approach would be to check the latest 10.6 branch and identify the code that causes the trouble, and add some conditions of srv_operation as needed.
Once we have something that works for 10.6, we can see how to backport that to earlier major versions. The data dictionary interface was heavily refactored in 10.6 to support atomic DDL.
I can reproduce the following with some changes to an existing test:
diff --git a/mysql-test/suite/mariabackup/partial_exclude.test b/mysql-test/suite/mariabackup/partial_exclude.test
|
index 3642a2c6f46..a404daa9ff6 100644
|
--- a/mysql-test/suite/mariabackup/partial_exclude.test
|
+++ b/mysql-test/suite/mariabackup/partial_exclude.test
|
@@ -14,10 +14,14 @@ INSERT INTO t1 VALUES(1);
|
CREATE TABLE t2(i int) ENGINE INNODB;
|
|
CREATE DATABASE db2;
|
-USE db2;
|
-CREATE TABLE t1(i INT) ENGINE INNODB;
|
+CREATE TABLE db2.t1(i INT) ENGINE INNODB;
|
+
|
+connect con1,localhost,root;
|
+send INSERT INTO t1 SELECT * FROM seq_1_to_2000;
|
+connect con2,localhost,root;
|
+send INSERT INTO db2.t1 SELECT * FROM seq_1_to_2000;
|
|
-USE test;
|
+connection default;
|
|
echo # xtrabackup backup;
|
|
@@ -47,4 +51,9 @@ DROP DATABASE db2;
|
rmdir $MYSQLD_DATADIR/db3;
|
rmdir $MYSQLD_DATADIR/db4;
|
rmdir $MYSQLD_DATADIR/db5;
|
+
|
+--disable_result_log
|
+exec rr record $XTRABACKUP --defaults-file=$MYSQLTEST_VARDIR/my.cnf --export --prepare --target-dir="$targetdir";
|
+--enable_result_log
|
+
|
rmdir $targetdir; |
mkdir /dev/shm/rr
|
_RR_TRACE_DIR=/dev/shm/rr ./mtr mariabackup.partial_exclude
|
rr replay /dev/shm/rr/latest-trace
|
(The rr record command in the test should not be part of the final modification to the test.)
|
10.6 1872a142b5f827758a68e7ee745b3451f5dbea2e |
2022-09-14 16:44:38 0 [Note] InnoDB: 128 rollback segments are active.
|
2022-09-14 16:44:38 0 [ERROR] InnoDB: Operating system error number 2 in a file operation.
|
2022-09-14 16:44:38 0 [ERROR] InnoDB: The error means the system cannot find the path specified.
|
2022-09-14 16:44:38 0 [ERROR] InnoDB: Cannot open datafile for read-only: './db2/t1.ibd' OS error: 71
|
2022-09-14 16:44:38 0 [ERROR] InnoDB: Operating system error number 2 in a file operation.
|
2022-09-14 16:44:38 0 [ERROR] InnoDB: The error means the system cannot find the path specified.
|
2022-09-14 16:44:38 0 [ERROR] InnoDB: Could not find a valid tablespace file for db2/t1. Please refer to https://mariadb.com/kb/en/innodb-data-dictionary-troubleshooting/ for how to resolve the issue.
|
2022-09-14 16:44:38 0 [Warning] InnoDB: Ignoring tablespace for db2/t1 because it could not be opened.
|
2022-09-14 16:44:38 0 [ERROR] InnoDB: Operating system error number 2 in a file operation.
|
2022-09-14 16:44:38 0 [ERROR] InnoDB: The error means the system cannot find the path specified.
|
2022-09-14 16:44:38 0 [ERROR] InnoDB: Cannot open datafile for read-only: './test/t2.ibd' OS error: 71
|
2022-09-14 16:44:38 0 [ERROR] InnoDB: Operating system error number 2 in a file operation.
|
2022-09-14 16:44:38 0 [ERROR] InnoDB: The error means the system cannot find the path specified.
|
2022-09-14 16:44:38 0 [ERROR] InnoDB: Could not find a valid tablespace file for test/t2. Please refer to https://mariadb.com/kb/en/innodb-data-dictionary-troubleshooting/ for how to resolve the issue.
|
2022-09-14 16:44:38 0 [Warning] InnoDB: Ignoring tablespace for test/t2 because it could not be opened.
|
2022-09-14 16:44:38 0 [Note] InnoDB: Creating shared tablespace for temporary tables
|
2022-09-14 16:44:38 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
|
2022-09-14 16:44:38 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
|
2022-09-14 16:44:38 0 [Note] InnoDB: 10.6.10 started; log sequence number 0; transaction id 43
|
…
|
2022-09-14 16:44:38 0 [Note] InnoDB: Loading buffer pool(s) from /dev/shm/10.6/mysql-test/var/tmp/backup/ib_buffer_pool
|
2022-09-14 16:44:38 0 [Note] InnoDB: Cannot open '/dev/shm/10.6/mysql-test/var/tmp/backup/ib_buffer_pool' for reading: No such file or directory
|
2022-09-14 16:44:38 0 [ERROR] InnoDB: Operating system error number 2 in a file operation.
|
2022-09-14 16:44:38 0 [ERROR] InnoDB: The error means the system cannot find the path specified.
|
2022-09-14 16:44:38 0 [ERROR] InnoDB: Cannot open datafile for read-only: './db2/t1.ibd' OS error: 71
|
2022-09-14 16:44:38 0 [ERROR] InnoDB: Operating system error number 2 in a file operation.
|
2022-09-14 16:44:38 0 [ERROR] InnoDB: The error means the system cannot find the path specified.
|
2022-09-14 16:44:38 0 [ERROR] InnoDB: Could not find a valid tablespace file for db2/t1. Please refer to https://mariadb.com/kb/en/innodb-data-dictionary-troubleshooting/ for how to resolve the issue.
|
For some reason, my breakpoints would not work in rr, so I cannot determine the call stacks for those messages.
When it comes to the server version that I tested, this appears to be a cosmetic error to me: the non-excluded data files ought to be exported just fine. I think that the correct fix would be to suppress those messages if the file names match the exclude patterns.
Side note: In mariabackup --export, there should be no need to create an InnoDB temporary tablespace.
10.4 is a bit more spammy:
|
10.4 3e3cfa893481abe9524a1657c4246fa9f91d4826 |
2022-09-14 17:00:53 0 [Note] InnoDB: Completed initialization of buffer pool
|
2022-09-14 17:00:53 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
|
2022-09-14 17:00:53 0 [Note] InnoDB: Setting log file ./ib_logfile101 size to 5242880 bytes
|
2022-09-14 17:00:53 0 [Note] InnoDB: Setting log file ./ib_logfile1 size to 5242880 bytes
|
2022-09-14 17:00:53 0 [Note] InnoDB: Renaming log file ./ib_logfile101 to ./ib_logfile0
|
2022-09-14 17:00:53 0 [Note] InnoDB: New log files created, LSN=406567
|
2022-09-14 17:00:53 0 [ERROR] InnoDB: Operating system error number 2 in a file operation.
|
2022-09-14 17:00:53 0 [ERROR] InnoDB: The error means the system cannot find the path specified.
|
2022-09-14 17:00:53 0 [ERROR] InnoDB: If you are installing InnoDB, remember that you must create directories yourself, InnoDB does not create them.
|
2022-09-14 17:00:53 0 [ERROR] InnoDB: Cannot open datafile for read-only: './db2/t1.ibd' OS error: 71
|
2022-09-14 17:00:53 0 [ERROR] InnoDB: Operating system error number 2 in a file operation.
|
2022-09-14 17:00:53 0 [ERROR] InnoDB: The error means the system cannot find the path specified.
|
2022-09-14 17:00:53 0 [ERROR] InnoDB: If you are installing InnoDB, remember that you must create directories yourself, InnoDB does not create them.
|
2022-09-14 17:00:53 0 [ERROR] InnoDB: Could not find a valid tablespace file for ``db2`.`t1``. Please refer to https://mariadb.com/kb/en/innodb-data-dictionary-troubleshooting/ for how to resolve the issue.
|
2022-09-14 17:00:53 0 [Warning] InnoDB: Ignoring tablespace for `db2`.`t1` because it could not be opened.
|
2022-09-14 17:00:53 0 [ERROR] InnoDB: Operating system error number 2 in a file operation.
|
2022-09-14 17:00:53 0 [ERROR] InnoDB: The error means the system cannot find the path specified.
|
2022-09-14 17:00:53 0 [ERROR] InnoDB: If you are installing InnoDB, remember that you must create directories yourself, InnoDB does not create them.
|
2022-09-14 17:00:53 0 [ERROR] InnoDB: Cannot open datafile for read-only: './test/t2.ibd' OS error: 71
|
2022-09-14 17:00:53 0 [ERROR] InnoDB: Operating system error number 2 in a file operation.
|
2022-09-14 17:00:53 0 [ERROR] InnoDB: The error means the system cannot find the path specified.
|
2022-09-14 17:00:53 0 [ERROR] InnoDB: If you are installing InnoDB, remember that you must create directories yourself, InnoDB does not create them.
|
2022-09-14 17:00:53 0 [ERROR] InnoDB: Could not find a valid tablespace file for ``test`.`t2``. Please refer to https://mariadb.com/kb/en/innodb-data-dictionary-troubleshooting/ for how to resolve the issue.
|
2022-09-14 17:00:53 0 [Warning] InnoDB: Ignoring tablespace for `test`.`t2` because it could not be opened.
|
2022-09-14 17:00:53 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
|
2022-09-14 17:00:53 0 [Note] InnoDB: Creating shared tablespace for temporary tables
|
2022-09-14 17:00:53 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
|
2022-09-14 17:00:53 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
|
…
|
2022-09-14 17:00:53 6 [Note] InnoDB: Sync to disk of `mysql`.`innodb_index_stats` started.
|
2022-09-14 17:00:53 6 [Note] InnoDB: Stopping purge
|
2022-09-14 17:00:53 4 [ERROR] InnoDB: Operating system error number 2 in a file operation.
|
2022-09-14 17:00:53 4 [ERROR] InnoDB: The error means the system cannot find the path specified.
|
2022-09-14 17:00:53 4 [ERROR] InnoDB: Cannot open datafile for read-only: './db2/t1.ibd' OS error: 71
|
2022-09-14 17:00:53 4 [ERROR] InnoDB: Operating system error number 2 in a file operation.
|
2022-09-14 17:00:53 4 [ERROR] InnoDB: The error means the system cannot find the path specified.
|
2022-09-14 17:00:53 4 [ERROR] InnoDB: Could not find a valid tablespace file for ``db2`.`t1``. Please refer to https://mariadb.com/kb/en/innodb-data-dictionary-troubleshooting/ for how to resolve the issue.
|
2022-09-14 17:00:54 6 [Note] InnoDB: Writing table metadata to './mysql/innodb_index_stats.cfg'
|
2022-09-14 17:00:54 6 [Note] InnoDB: Table `mysql`.`innodb_index_stats` flushed to disk
|
2022-09-14 17:00:54 6 [Note] InnoDB: Resuming purge
|
…
|
The difference between 10.3 and 10.6 is in "strict" variable calculation in fil_ibd_open() .
10.3:
/* Always look for a file at the default location. But don't log |
an error if the tablespace is already open in remote or dict. */ |
ut_a(df_default.filepath());
|
const bool strict = (tablespaces_found == 0); |
if (df_default.open_read_only(strict) == DB_SUCCESS) { |
ut_ad(df_default.is_open());
|
++tablespaces_found;
|
}
|
10.6
/* Always look for a file at the default location. But don't log |
an error if the tablespace is already open in remote or dict. */ |
ut_a(df_default.filepath());
|
|
/* Mariabackup will not copy files whose names start with |
#sql-. We will suppress messages about such files missing on
|
the first server startup. The tables ought to be dropped by
|
drop_garbage_tables_after_restore() a little later. */ |
|
const bool strict = validate && !tablespaces_found |
&& !(srv_operation == SRV_OPERATION_NORMAL
|
&& srv_start_after_restore
|
&& srv_force_recovery < SRV_FORCE_NO_BACKGROUND
|
&& dict_table_t::is_temporary_name(
|
df_default.filepath()));
|
|
if (df_default.open_read_only(strict) == DB_SUCCESS) { |
ut_ad(df_default.is_open());
|
++tablespaces_found;
|
}
|
We could partially repeat the logic in 10.[345] to fix the bug.
Addressed the above review feedback from Marko and revised the PR. The revised PR is in https://github.com/MariaDB/server/pull/2183.
The revised fix has the following:
1. Revert the code changes made in the previous submission
2. Added code to exclude tables that are not in the data directory when processing undo log records during recovery and in RESTORE_EXPORT mode. The basic idea is that if a transaction includes multiple tables and if we export only a subset of those tables, then during recovery we apply relevant to non-existing tables.
Appreciate your feedback on the revised PR.