> ./mtr full_backup --mysqld="--innodb_data_file_path=ibdata1:10M;ibdata2:5M:autoextend" --force
|
Logging: /home/a/spd/_depot/m-branch/10.2/mysql-test/mysql-test-run.pl full_backup --mysqld=--innodb_data_file_path=ibdata1:10M;ibdata2:5M:autoextend --force
|
vardir: /home/a/spd/m1-10.2/build/mysql-test/var
|
Checking leftover processes...
|
Removing old var directory...
|
Creating var directory '/home/a/spd/m1-10.2/build/mysql-test/var'...
|
Checking supported features...
|
MariaDB Version 10.2.8-MariaDB
|
- SSL connections supported
|
Collecting tests...
|
Installing system database...
|
|
==============================================================================
|
|
TEST RESULT TIME (ms) or COMMENT
|
--------------------------------------------------------------------------
|
|
worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
|
mariabackup.full_backup '32k,innodb' [ fail ]
|
Test ended at 2017-07-28 23:47:06
|
|
CURRENT_TEST: mariabackup.full_backup
|
mysqltest: At line 17: exec of '/home/a/spd/m1-10.2/build/extra/mariabackup/mariabackup --prepare --target-dir=/home/a/spd/m1-10.2/build/mysql-test/var/tmp/backup 2>&1' failed, error: 256, status: 1, errno: 11
|
Output from before failure:
|
/home/a/spd/m1-10.2/build/extra/mariabackup/mariabackup based on MariaDB server 10.2.8-MariaDB Linux (x86_64)
|
xtrabackup: cd to /home/a/spd/m1-10.2/build/mysql-test/var/tmp/backup/
|
xtrabackup: This target seems to be not prepared yet.
|
InnoDB: The universal page size of the database is set to 32768.
|
xtrabackup: using the following InnoDB configuration for recovery:
|
xtrabackup: innodb_data_home_dir = .
|
xtrabackup: innodb_data_file_path = ibdata1:10M;ibdata2:5M:autoextend
|
xtrabackup: innodb_log_group_home_dir = .
|
xtrabackup: Starting InnoDB instance for recovery.
|
xtrabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter)
|
2017-07-28 23:47:05 139740263680192 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
|
2017-07-28 23:47:05 139740263680192 [Note] InnoDB: Uses event mutexes
|
2017-07-28 23:47:05 139740263680192 [Note] InnoDB: Compressed tables use zlib 1.2.7
|
2017-07-28 23:47:05 139740263680192 [Note] InnoDB: Number of pools: 1
|
2017-07-28 23:47:05 139740263680192 [Note] InnoDB: Using SSE2 crc32 instructions
|
2017-07-28 23:47:05 139740263680192 [Note] InnoDB: Initializing buffer pool, total size = 100M, instances = 1, chunk size = 100M
|
2017-07-28 23:47:05 139740263680192 [Note] InnoDB: Completed initialization of buffer pool
|
2017-07-28 23:47:05 139739991480064 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
|
2017-07-28 23:47:05 139740263680192 [Note] InnoDB: Need to create a new innodb_system data file 'ibdata2'.
|
2017-07-28 23:47:05 139740263680192 [Note] InnoDB: Setting file './ibdata2' size to 5 MB. Physically writing the file full; Please wait ...
|
2017-07-28 23:47:05 139740263680192 [Note] InnoDB: File './ibdata2' size is now 5 MB.
|
2017-07-28 23:47:05 139740263680192 [Note] InnoDB: Highest supported file format is Barracuda.
|
2017-07-28 23:47:05 139740263680192 [Note] InnoDB: Starting crash recovery from checkpoint LSN=3116833
|
2017-07-28 23:47:05 139740263680192 [Note] InnoDB: Recovered page [page id: space=0, page number=320] from the doublewrite buffer.
|
2017-07-28 23:47:05 139740263680192 [Note] InnoDB: Recovered page [page id: space=0, page number=322] from the doublewrite buffer.
|
2017-07-28 23:47:05 139740263680192 [Note] InnoDB: Recovered page [page id: space=0, page number=321] from the doublewrite buffer.
|
2017-07-28 23:47:05 139740263680192 [Note] InnoDB: Recovered page [page id: space=0, page number=323] from the doublewrite buffer.
|
2017-07-28 23:47:05 139740263680192 [Note] InnoDB: Recovered page [page id: space=0, page number=324] from the doublewrite buffer.
|
2017-07-28 23:47:05 139740263680192 [Note] InnoDB: Starting final batch to recover 9 pages from redo log.
|
2017-07-28 23:47:05 139740263680192 [ERROR] InnoDB: Tablespace size stored in header is 2688 pages, but the sum of data file sizes is 480 pages
|
2017-07-28 23:47:05 139740263680192 [ERROR] InnoDB: Cannot start InnoDB. The tail of the system tablespace is missing. Have you edited innodb_data_file_path in my.cnf in an inappropriate way, removing data files from there? You can set innodb_force_recovery=1 in my.cnf to force a startup if you are trying to recover a badly corrupt database.
|
2017-07-28 23:47:05 139740263680192 [ERROR] InnoDB: Plugin initialization aborted with error Generic error
|
xtrabackup: innodb_init() returned 11 (Generic error).
|
|
|
|
The result from queries just before the failure was:
|
CREATE TABLE t(i INT) ENGINE INNODB;
|
INSERT INTO t VALUES(1);
|
# xtrabackup backup
|
INSERT INTO t VALUES(2);
|
# xtrabackup prepare
|
|
- saving '/home/a/spd/m1-10.2/build/mysql-test/var/log/mariabackup.full_backup-32k,innodb/' to '/home/a/spd/m1-10.2/build/mysql-test/var/log/mariabackup.full_backup-32k,innodb/'
|
mariabackup.full_backup '64k,innodb' [ skipped ] Test requires InnoDB.
|
line
|
2017-07-28 23:47:07 139809037383872 [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 8716, less than the log sequence number in the first system tablespace file header, 130988.
|
2017-07-28 23:47:08 139809037383872 [ERROR] InnoDB: Cannot create doublewrite buffer: the first file in innodb_data_file_path must be at least 12M.
|
2017-07-28 23:47:08 139809037383872 [ERROR] InnoDB: Plugin initialization aborted with error Generic error
|
2017-07-28 23:47:08 139809037383872 [ERROR] Plugin 'InnoDB' init function returned error.
|
2017-07-28 23:47:08 139809037383872 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
|
^ Found warnings in /home/a/spd/m1-10.2/build/mysql-test/var/log/mysqld.1.err
|
ok
|
|
mariabackup.full_backup '16k,innodb' [ pass ] 5727
|
mariabackup.full_backup '4k,innodb' [ pass ] 5767
|
mariabackup.full_backup '8k,innodb' [ pass ] 5751
|
--------------------------------------------------------------------------
|
The servers were restarted 4 times
|
Spent 17.245 of 44 seconds executing testcases
|
mysql-test-run: WARNING: Got errors/warnings while running tests, please examine '/home/a/spd/m1-10.2/build/mysql-test/var/log/warnings' for details.
|
|
Completed: Failed 1/4 tests, 75.00% were successful.
|
|
Failing test(s): mariabackup.full_backup
|
|
The log files in var/log may give you some hint of what went wrong.
|
|
If you want to report this error, please read first the documentation
|
at http://dev.mysql.com/doc/mysql/en/mysql-test-suite.html
|
|
1 tests were skipped, 1 by the test itself.
|
|
mysql-test-run: *** ERROR: there were failing test cases
|
I think that this is a design problem of the MariaDB encryption.
MariaDB encryption is reusing the field FIL_PAGE_FILE_FLUSH_LSN which used to be 0 in all pages except the first page of each data file of the InnoDB system tablespace.
In MySQL 5.7, the field was repurposed for FIL_RTREE_SPLIT_SEQ_NUM. This is the reason why MariaDB 10.2 will not support encryption in SPATIAL INDEX (
MDEV-11974).The problem here appears to be that xtrabackup is incorrectly mistaking the first page of the second data file of the system tablespace for an encrypted one, because the FIL_PAGE_FILE_FLUSH_LSN field is not 0.
MDEV-11939was filed for a similar issue in the innochecksum utility.In xtrabackup, we should add a check that FIL_PAGE_FILE_FLUSH_LSN can be nonzero in an unencrypted system tablespace. Also, MariaDB 10.1 should probably stop writing FIL_PAGE_FILE_FLUSH_LSN at shutdown to the first page of other than the first system tablespace file (10.2 already stopped this because of the SPATIAL INDEX mentioned above), so that it will not make an encrypted page unaccessible by corrupting the encryption key ID.