[MDEV-14447] mariabackup --incremental --prepare fails to extend last file when applying ibdata1.delta Created: 2017-11-20  Updated: 2022-11-24  Resolved: 2017-11-24

Status: Closed
Project: MariaDB Server
Component/s: Backup
Affects Version/s: 10.1.29, 10.2.10, 10.3.3
Fix Version/s: 10.1.30, 10.2.11, 10.3.3

Type: Bug Priority: Blocker
Reporter: Gokhan Demir Assignee: Marko Mäkelä
Resolution: Fixed Votes: 0
Labels: incremental, mariabackup
Environment:

Centos 6, 7

Issue Links:
Blocks
is blocked by MDEV-14499 Mariabackup 10.2 fails to back up a m... Closed
Problem/Incident
is caused by MDEV-13822 Mariabackup --prepare --incremental s... Closed
Relates
relates to MDEV-11556 InnoDB redo log apply fails to adjust... Closed
relates to MDEV-29115 mariabackup.mdev-14447 started failin... Closed

 Description   

When applying the first incremental backup onto an existing full backup using apply-log-only, mariabackup 10.1.29 changes ibdata1 size when applying ibdata1.delta.

Here are the critical lines from the mariabackup output:

mariabackup based on MariaDB server 10.1.29-MariaDB Linux (x86_64) 
incremental backup from 63608267966808 is enabled.
 
mariabackup: cd to /var/backup/backup0/xtrabackup/00_full/
 
mariabackup: This target seems to be already prepared with --apply-log-only.
 
mariabackup: xtrabackup_logfile detected: size=33619968, start_lsn=(63609603317650)
 
mariabackup: using the following InnoDB configuration for recovery:
 
mariabackup:   innodb_data_home_dir = ./
 
mariabackup:   innodb_data_file_path = ibdata1:1G;ibdata2:1G:autoextend:max:16G
 
mariabackup:   innodb_log_group_home_dir = /var/backup/backup0/xtrabackup/20171120_001001/
 
mariabackup:   innodb_log_files_in_group = 1
 
mariabackup:   innodb_log_file_size = 33619968
 
mariabackup: Generating a list of tablespaces
 
2017-11-20  3:02:52 140704255141920 [Note] InnoDB: Processed 2541 .ibd/.isl files
 
2017-11-20  3:03:08 140704255141920 [Note] InnoDB: Processed 4653 .ibd/.isl files
 
mariabackup: page size for /var/backup/backup0/xtrabackup/20171120_001001//ibdata1.delta is 16384 bytes
 
Applying /var/backup/backup0/xtrabackup/20171120_001001//ibdata1.delta to ./ibdata1...
 
mariabackup: page size for /var/backup/backup0/xtrabackup/20171120_001001//ibdata2.delta is 16384 bytes
 
Applying /var/backup/backup0/xtrabackup/20171120_001001//ibdata2.delta to ./ibdata2...
 
....
 
....
 
mariabackup: using the following InnoDB configuration for recovery:
 
mariabackup:   innodb_data_home_dir = ./
 
mariabackup:   innodb_data_file_path = ibdata1:1G;ibdata2:1G:autoextend:max:16G
 
mariabackup:   innodb_log_group_home_dir = /var/backup/backup0/xtrabackup/20171120_001001/
 
mariabackup:   innodb_log_files_in_group = 1
 
mariabackup:   innodb_log_file_size = 33619968
 
mariabackup: Starting InnoDB instance for recovery.
 
mariabackup: Using 8589934592 bytes for buffer pool (set by --use-memory parameter)
 
2017-11-20  3:06:06 140704255141920 [Note] InnoDB: Using mutexes to ref count buffer pool pages
 
2017-11-20  3:06:06 140704255141920 [Note] InnoDB: The InnoDB memory heap is disabled
 
2017-11-20  3:06:06 140704255141920 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
 
2017-11-20  3:06:06 140704255141920 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
 
2017-11-20  3:06:06 140704255141920 [Note] InnoDB: Compressed tables use zlib 1.2.3
 
2017-11-20  3:06:06 140704255141920 [Note] InnoDB: Using generic crc32 instructions
 
2017-11-20  3:06:06 140704255141920 [Note] InnoDB: Initializing buffer pool, size = 8.0G
 
2017-11-20  3:06:07 140704255141920 [Note] InnoDB: Completed initialization of buffer pool
 
2017-11-20  3:06:07 140704255141920 [ERROR] InnoDB: Data file ./ibdata1 is of a different size 1015808 pages (rounded down to MB) than specified in the .cnf file 65536 pages!
 
2017-11-20  3:06:07 140704255141920 [ERROR] InnoDB: Could not open or create the system tablespace. If you tried to add new data files to the system tablespace, and it failed here, you should now edit innodb_data_file_path in my.cnf back to what it was, and remove the new ibdata files InnoDB created in this failed attempt. InnoDB only wrote those files full of zeros, but did not yet use them in any way. But be careful: do not remove old data files which contain your precious data!
 
mariabackup: innodb_init(): Error occured.
 
...
 
...

And mariabackup returns 1 as error code.

My ibdata1 size was 1GB. After the applying ibdata1.delta, the new size has been 16GB.

Previous 10.1.28 version of mariabackup was working correctly.,

My auto-growing ibdata2 size was 15 GB. Its new size after the delta is applied is still 15 GB. So, it seems only ibdata1 is affected.

What I think is probably my innodb_data_file_path is a bit unusual, such that ibdata1 is fixed 1 GB, but ibdata2 is initially 1 GB, growable to 16GB, and is currently 15GB.

This is a blocker to use mariabackup 10.1.29. I will probably revert to using mariabackup 10.1.28 until this has been fixed.

Note: My backed up data folder locations:
Full backup resides on folder:
/var/backup/backup0/xtrabackup/00_full

First (and only) incremental backup resides on folder:
/var/backup/backup0/xtrabackup/20171120_001001

 Comments   
Comment by Marko Mäkelä [ 2017-11-21 ]

I think that this must have been caused by
MDEV-13822 mariabackup incremental prepare incorrectly sets file size

In xtrabackup_apply_delta(), the system tablespace (space_id=0) is special in that it can consist of multiple files. When it does, then the call to os_file_set_size() is wrong. We should set the last system tablespace file size to correspond to the logical tablespace size minus the size of preceding files. Logically, the system tablespace is as if all the data files are concatenated together.

Comment by Marko Mäkelä [ 2017-11-21 ]

Note: Percona Xtrabackup does not extend data files when replaying incremental backup. Instead, it works around the issue at a lower level in InnoDB I/O, potentially losing the ability to check some inconsistency.

For non-incremental backup, the file sizes are correctly extended by MariaDB thanks to MDEV-11556.

Comment by Andrii Nikitin (Inactive) [ 2017-11-21 ]

The problem has been verified with mtr script below started with "--mysqld=--sequence --mysqld='--innodb-data-file-path=ibdata1:3M;ibdata2:1M:autoextend'" :

call mtr.add_suppression("InnoDB: New log files created");
 
 
 
let $basedir=$MYSQLTEST_VARDIR/tmp/backup;
 
let $incremental_dir=$MYSQLTEST_VARDIR/tmp/backup_inc1;
 
 
 
CREATE TABLE t(a varchar(40) PRIMARY KEY, b varchar(40), c varchar(40), d varchar(40), index(b,c,d)) ENGINE INNODB;
 
 
 
echo # Create full backup , modify table, then create incremental/differential backup;
 
--disable_result_log
 
exec $XTRABACKUP --defaults-file=$MYSQLTEST_VARDIR/my.cnf  --backup --target-dir=$basedir;
 
--enable_result_log
 
exec ls -la $basedir;
 
INSERT INTO t select uuid(), uuid(), uuid(), uuid() from seq_1_to_100000;
 
COMMIT;
 
SELECT count(*) FROM t;
 
 
 
exec ls -la $basedir;
 
exec $XTRABACKUP --defaults-file=$MYSQLTEST_VARDIR/my.cnf  --backup --target-dir=$incremental_dir --incremental-basedir=$basedir;
 
 
 
--disable_result_log
 
echo # Prepare full backup, apply incremental one;
 
exec $XTRABACKUP --prepare --apply-log-only --target-dir=$basedir;
 
exec $XTRABACKUP --prepare --apply-log-only --target-dir=$basedir --incremental-dir=$incremental_dir ;
 
 
 
echo # Restore and check results;
 
let $targetdir=$basedir;
 
-- source include/restart_and_restore.inc
 
--enable_result_log
 
exec ls -la $basedir;
 
 
 
DROP TABLE t;
 
 
 
# Cleanup
 
rmdir $basedir;
 
rmdir $incremental_dir;

Shows output:

$ ./mtr MDEV-14447 --mem --mysqld=--sequence --mysqld='--innodb-data-file-path=ibdata1:3M;ibdata2:1M:autoextend'
 
Logging: /home/a/env3/mariadb-environs/m8-10.1/src/mysql-test/mysql-test-run.pl  MDEV-14447 --mem --mysqld=--sequence --mysqld=--innodb-data-file-path=ibdata1:3M;ibdata2:1M:autoextend
 
vardir: /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var
 
Checking leftover processes...
 
Removing old var directory...
 
Creating var directory '/home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var'...
 
 - symlinking 'var' to '/dev/shm/var_auto_Y9TV'
 
Checking supported features...
 
MariaDB Version 10.1.30-MariaDB
 
 - SSL connections supported
 
Sphinx 'indexer' binary not found, sphinx suite will be skipped
 
Collecting tests...
 
Installing system database...
 
 
 
==============================================================================
 
 
 
TEST                                      RESULT   TIME (ms) or COMMENT
 
--------------------------------------------------------------------------
 
 
 
worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 16000..16019
 
call mtr.add_suppression("InnoDB: New log files created");
 
CREATE TABLE t(a varchar(40) PRIMARY KEY, b varchar(40), c varchar(40), d varchar(40), index(b,c,d)) ENGINE INNODB;
 
# Create full backup , modify table, then create incremental/differential backup
 
total 69664
 
drwxr-x--- 6 a a      280 Nov 21 14:03 .
 
drwxr-xr-x 4 a a      140 Nov 21 14:03 ..
 
-rw-r----- 1 a a     8192 Nov 21 14:03 aria_log.00000001
 
-rw-r----- 1 a a       52 Nov 21 14:03 aria_log_control
 
-rw-r----- 1 a a      370 Nov 21 14:03 backup-my.cnf
 
-rw-r----- 1 a a  3145728 Nov 21 14:03 ibdata1
 
-rw-r----- 1 a a 68157440 Nov 21 14:03 ibdata2
 
drwxr-x--- 2 a a      260 Nov 21 14:03 mtr
 
drwxr-x--- 2 a a     1800 Nov 21 14:03 mysql
 
drwxr-x--- 2 a a       60 Nov 21 14:03 performance_schema
 
drwxr-x--- 2 a a       80 Nov 21 14:03 test
 
-rw-r----- 1 a a      101 Nov 21 14:03 xtrabackup_checkpoints
 
-rw-r----- 1 a a      585 Nov 21 14:03 xtrabackup_info
 
-rw-r----- 1 a a     7168 Nov 21 14:03 xtrabackup_logfile
 
INSERT INTO t select uuid(), uuid(), uuid(), uuid() from seq_1_to_100000;
 
COMMIT;
 
SELECT count(*) FROM t;
 
count(*)
 
100000
 
total 69664
 
drwxr-x--- 6 a a      280 Nov 21 14:03 .
 
drwxr-xr-x 4 a a      140 Nov 21 14:03 ..
 
-rw-r----- 1 a a     8192 Nov 21 14:03 aria_log.00000001
 
-rw-r----- 1 a a       52 Nov 21 14:03 aria_log_control
 
-rw-r----- 1 a a      370 Nov 21 14:03 backup-my.cnf
 
-rw-r----- 1 a a  3145728 Nov 21 14:03 ibdata1
 
-rw-r----- 1 a a 68157440 Nov 21 14:03 ibdata2
 
drwxr-x--- 2 a a      260 Nov 21 14:03 mtr
 
drwxr-x--- 2 a a     1800 Nov 21 14:03 mysql
 
drwxr-x--- 2 a a       60 Nov 21 14:03 performance_schema
 
drwxr-x--- 2 a a       80 Nov 21 14:03 test
 
-rw-r----- 1 a a      101 Nov 21 14:03 xtrabackup_checkpoints
 
-rw-r----- 1 a a      585 Nov 21 14:03 xtrabackup_info
 
-rw-r----- 1 a a     7168 Nov 21 14:03 xtrabackup_logfile
 
# Prepare full backup, apply incremental one
 
mariabackup.MDEV-14447                   [ fail ]
 
        Test ended at 2017-11-21 14:04:00
 
 
 
CURRENT_TEST: mariabackup.MDEV-14447
 
171121 14:03:57 Connecting to MySQL server host: localhost, user: root, password: set, port: 16000, socket: /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/mysqld.1.sock
 
Using server version 10.1.30-MariaDB
 
/home/a/env3/mariadb-environs/m8-10.1/bld/extra/mariabackup/mariabackup based on MariaDB server 10.1.30-MariaDB Linux (x86_64) 
incremental backup from 1629347 is enabled.
 
mariabackup: uses posix_fadvise().
 
mariabackup: cd to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/mysqld.1/data/
 
mariabackup: open files limit requested 1024, set to 1024
 
mariabackup: using the following InnoDB configuration:
 
mariabackup:   innodb_data_home_dir = ./
 
mariabackup:   innodb_data_file_path = ibdata1:3M;ibdata2:1M:autoextend
 
mariabackup:   innodb_log_group_home_dir = ./
 
mariabackup:   innodb_log_files_in_group = 2
 
mariabackup:   innodb_log_file_size = 5242880
 
171121 14:03:57 >> log scanned up to (41613503)
 
mariabackup: Generating a list of tablespaces
 
mariabackup: using the full scan for incremental backup
 
171121 14:03:57 [01] Copying ./ibdata1 to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/ibdata1.delta
 
171121 14:03:57 [01]        ...done
 
171121 14:03:57 [01] Copying ./ibdata2 to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/ibdata2.delta
 
171121 14:03:57 [01]        ...done
 
171121 14:03:57 [01] Copying ./mysql/innodb_table_stats.ibd to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/innodb_table_stats.ibd.delta
 
171121 14:03:57 [01]        ...done
 
171121 14:03:57 [01] Copying ./mysql/innodb_index_stats.ibd to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/innodb_index_stats.ibd.delta
 
171121 14:03:57 [01]        ...done
 
171121 14:03:57 [01] Copying ./test/t.ibd to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/test/t.ibd.delta
 
171121 14:03:57 [01]        ...done
 
171121 14:03:58 >> log scanned up to (41613503)
 
171121 14:03:58 Executing FLUSH NO_WRITE_TO_BINLOG TABLES...
 
171121 14:03:58 Executing FLUSH TABLES WITH READ LOCK...
 
171121 14:03:58 Starting to backup non-InnoDB tables and files
 
171121 14:03:58 [01] Copying ./mysql/db.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/db.frm
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/db.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/db.MYI
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/db.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/db.MYD
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/host.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/host.frm
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/host.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/host.MYI
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/host.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/host.MYD
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/user.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/user.frm
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/user.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/user.MYI
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/user.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/user.MYD
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/roles_mapping.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/roles_mapping.frm
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/roles_mapping.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/roles_mapping.MYI
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/roles_mapping.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/roles_mapping.MYD
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/func.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/func.frm
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/func.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/func.MYI
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/func.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/func.MYD
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/plugin.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/plugin.frm
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/plugin.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/plugin.MYI
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/plugin.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/plugin.MYD
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/servers.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/servers.frm
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/servers.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/servers.MYI
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/servers.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/servers.MYD
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/tables_priv.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/tables_priv.frm
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/tables_priv.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/tables_priv.MYI
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/tables_priv.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/tables_priv.MYD
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/columns_priv.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/columns_priv.frm
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/columns_priv.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/columns_priv.MYI
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/columns_priv.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/columns_priv.MYD
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/help_topic.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/help_topic.frm
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/help_topic.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/help_topic.MYI
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/help_topic.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/help_topic.MYD
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/help_category.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/help_category.frm
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/help_category.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/help_category.MYI
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/help_category.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/help_category.MYD
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/help_relation.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/help_relation.frm
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/help_relation.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/help_relation.MYI
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/help_relation.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/help_relation.MYD
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/help_keyword.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/help_keyword.frm
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/help_keyword.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/help_keyword.MYI
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/help_keyword.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/help_keyword.MYD
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/time_zone_name.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_name.frm
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/time_zone_name.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_name.MYI
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/time_zone_name.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_name.MYD
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/time_zone.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone.frm
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/time_zone.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone.MYI
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/time_zone.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone.MYD
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/time_zone_transition.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_transition.frm
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/time_zone_transition.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_transition.MYI
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/time_zone_transition.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_transition.MYD
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/time_zone_transition_type.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_transition_type.frm
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/time_zone_transition_type.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_transition_type.MYI
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/time_zone_transition_type.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_transition_type.MYD
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/time_zone_leap_second.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_leap_second.frm
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/time_zone_leap_second.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_leap_second.MYI
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/time_zone_leap_second.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_leap_second.MYD
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/proc.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/proc.frm
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/proc.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/proc.MYI
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/proc.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/proc.MYD
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/procs_priv.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/procs_priv.frm
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/procs_priv.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/procs_priv.MYI
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/procs_priv.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/procs_priv.MYD
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/general_log.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/general_log.frm
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/general_log.CSM to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/general_log.CSM
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/general_log.CSV to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/general_log.CSV
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/slow_log.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/slow_log.frm
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/slow_log.CSM to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/slow_log.CSM
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/slow_log.CSV to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/slow_log.CSV
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/event.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/event.frm
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/event.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/event.MYI
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/event.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/event.MYD
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/innodb_table_stats.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/innodb_table_stats.frm
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/innodb_index_stats.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/innodb_index_stats.frm
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/proxies_priv.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/proxies_priv.frm
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/proxies_priv.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/proxies_priv.MYI
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/proxies_priv.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/proxies_priv.MYD
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/table_stats.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/table_stats.frm
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/table_stats.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/table_stats.MYI
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/table_stats.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/table_stats.MYD
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/column_stats.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/column_stats.frm
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/column_stats.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/column_stats.MYI
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/column_stats.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/column_stats.MYD
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/index_stats.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/index_stats.frm
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/index_stats.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/index_stats.MYI
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/index_stats.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/index_stats.MYD
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/gtid_slave_pos.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/gtid_slave_pos.MYI
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/gtid_slave_pos.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/gtid_slave_pos.MYD
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mysql/gtid_slave_pos.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mysql/gtid_slave_pos.frm
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./test/t.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/test/t.frm
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./performance_schema/db.opt to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/performance_schema/db.opt
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mtr/db.opt to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mtr/db.opt
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mtr/test_suppressions.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mtr/test_suppressions.frm
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mtr/test_suppressions.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mtr/test_suppressions.MYI
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mtr/test_suppressions.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mtr/test_suppressions.MYD
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mtr/ts_insert.TRN to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mtr/ts_insert.TRN
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mtr/test_suppressions.TRG to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mtr/test_suppressions.TRG
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mtr/global_suppressions.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mtr/global_suppressions.frm
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mtr/global_suppressions.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mtr/global_suppressions.MYI
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mtr/global_suppressions.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mtr/global_suppressions.MYD
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mtr/gs_insert.TRN to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mtr/gs_insert.TRN
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying ./mtr/global_suppressions.TRG to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/mtr/global_suppressions.TRG
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 Finished backing up non-InnoDB tables and files
 
171121 14:03:58 [01] Copying aria_log.00000001 to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/aria_log.00000001
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 [01] Copying aria_log_control to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/aria_log_control
 
171121 14:03:58 [01]        ...done
 
171121 14:03:58 Executing FLUSH NO_WRITE_TO_BINLOG ENGINE LOGS...
 
mariabackup: The latest check point (for incremental): '34324737'
 
mariabackup: Stopping log copying thread.
 
.171121 14:03:58 >> log scanned up to (41613503)
 
 
 
171121 14:03:58 Executing UNLOCK TABLES
 
171121 14:03:58 All tables unlocked
 
171121 14:03:58 Backup created in directory '/home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/'
 
171121 14:03:58 [00] Writing backup-my.cnf
 
171121 14:03:58 [00]        ...done
 
171121 14:03:58 [00] Writing xtrabackup_info
 
171121 14:03:58 [00]        ...done
 
mariabackup: Transaction log of lsn (34324737) to (41613503) was copied.
 
171121 14:03:58 completed OK!
 
mysqltest: At line 23: exec of '/home/a/env3/mariadb-environs/m8-10.1/bld/extra/mariabackup/mariabackup --prepare --apply-log-only --target-dir=/home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup --incremental-dir=/home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1  2>&1' failed, error: 256, status: 1, errno: 0
 
Output from before failure:
 
/home/a/env3/mariadb-environs/m8-10.1/bld/extra/mariabackup/mariabackup based on MariaDB server 10.1.30-MariaDB Linux (x86_64) 
incremental backup from 1629347 is enabled.
 
mariabackup: cd to /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup/
 
mariabackup: This target seems to be already prepared with --apply-log-only.
 
mariabackup: xtrabackup_logfile detected: size=8257536, start_lsn=(34324737)
 
mariabackup: using the following InnoDB configuration for recovery:
 
mariabackup:   innodb_data_home_dir = ./
 
mariabackup:   innodb_data_file_path = ibdata1:3M;ibdata2:1M:autoextend
 
mariabackup:   innodb_log_group_home_dir = /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/
 
mariabackup:   innodb_log_files_in_group = 1
 
mariabackup:   innodb_log_file_size = 8257536
 
mariabackup: Generating a list of tablespaces
 
mariabackup: page size for /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1//ibdata2.delta is 16384 bytes
 
2017-11-21 14:03:59 139985980505024 [Warning] InnoDB: Failed to set O_DIRECT on file /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1//ibdata2.delta: OPEN: Invalid argument, continuing anyway. O_DIRECT is known to result in 'Invalid argument' on Linux on tmpfs, see MySQL Bug#26662.
 
Applying /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1//ibdata2.delta to ./ibdata2...
 
mariabackup: page size for /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1//ibdata1.delta is 16384 bytes
 
Applying /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1//ibdata1.delta to ./ibdata1...
 
mariabackup: page size for /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1//test/t.ibd.delta is 16384 bytes
 
Applying /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1//test/t.ibd.delta to ./test/t.ibd...
 
mariabackup: page size for /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1//mysql/innodb_index_stats.ibd.delta is 16384 bytes
 
Applying /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1//mysql/innodb_index_stats.ibd.delta to ./mysql/innodb_index_stats.ibd...
 
mariabackup: page size for /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1//mysql/innodb_table_stats.ibd.delta is 16384 bytes
 
Applying /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1//mysql/innodb_table_stats.ibd.delta to ./mysql/innodb_table_stats.ibd...
 
mariabackup: using the following InnoDB configuration for recovery:
 
mariabackup:   innodb_data_home_dir = ./
 
mariabackup:   innodb_data_file_path = ibdata1:3M;ibdata2:1M:autoextend
 
mariabackup:   innodb_log_group_home_dir = /home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/tmp/backup_inc1/
 
mariabackup:   innodb_log_files_in_group = 1
 
mariabackup:   innodb_log_file_size = 8257536
 
mariabackup: Starting InnoDB instance for recovery.
 
mariabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter)
 
2017-11-21 14:03:59 139985980505024 [Note] InnoDB: Using mutexes to ref count buffer pool pages
 
2017-11-21 14:03:59 139985980505024 [Note] InnoDB: The InnoDB memory heap is disabled
 
2017-11-21 14:03:59 139985980505024 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
 
2017-11-21 14:03:59 139985980505024 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
 
2017-11-21 14:03:59 139985980505024 [Note] InnoDB: Compressed tables use zlib 1.2.11
 
2017-11-21 14:03:59 139985980505024 [Note] InnoDB: Using SSE crc32 instructions
 
2017-11-21 14:03:59 139985980505024 [Note] InnoDB: Initializing buffer pool, size = 100.0M
 
2017-11-21 14:03:59 139985980505024 [Note] InnoDB: Completed initialization of buffer pool
 
2017-11-21 14:03:59 139985980505024 [ERROR] InnoDB: Data file ./ibdata1 is of a different size 4352 pages (rounded down to MB) than specified in the .cnf file 192 pages!
 
2017-11-21 14:03:59 139985980505024 [ERROR] InnoDB: Could not open or create the system tablespace. If you tried to add new data files to the system tablespace, and it failed here, you should now edit innodb_data_file_path in my.cnf back to what it was, and remove the new ibdata files InnoDB created in this failed attempt. InnoDB only wrote those files full of zeros, but did not yet use them in any way. But be careful: do not remove old data files which contain your precious data!
 
mariabackup: innodb_init(): Error occured.
 
 
 
 - saving '/home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/log/mariabackup.MDEV-14447/' to '/home/a/env3/mariadb-environs/_depot/m-branch/m8-10.1-bld/mysql-test/var/log/mariabackup.MDEV-14447/'
 
--------------------------------------------------------------------------
 
The servers were restarted 0 times
 
Spent 0.000 of 18 seconds executing testcases
 
 
 
Failure: Failed 1/1 tests, 0.00% were successful.
 
 
 
Failing test(s): mariabackup.MDEV-14447
 
 
 
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
 
 
 
mysql-test-run: *** ERROR: there were failing test cases

Comment by Marko Mäkelä [ 2017-11-21 ]

Incremental restore was probably not tested with a multi-file InnoDB system tablespace.
Some more remarks:

  • Apparently, for a multi-file system tablespace, a .delta file is being generated for every data file. For example, ibdata2.delta for ibdata2.
  • The FSP_SIZE field is only present in page 0, and the FIL_PAGE_OFFSET can only be 0 in the first page of the first file.
  • The function xtrabackup_apply_delta() seems to check FIL_PAGE_OFFSET (offset_on_page) before reading FSP_SIZE. So, it should not incorrectly set the size of ibdata2 based on what it finds in ibdata2.delta, provided that the contents of ibdata2.delta was derived from the source ibdata2 file only.

Maybe the fix should modify xtrabackup_apply_delta() so that it stores the size of the system tablespace in the loop, and adjusts the size at the end of the function. Other tablespaces can be adjusted immediately. The system tablespace size is a bit tricky to determine; I think that we must trust the innodb_data_file_path parameter for other than the last file.

Comment by Andrii Nikitin (Inactive) [ 2017-11-21 ]

mariabackup in 10.2 crashes in fil_space_extend_must_retry with the same mtr test like below

$ ./mtr MDEV-14447 --mem --mysqld=--sequence --mysqld='--innodb-data-file-path=ibdata1:3M;ibdata2:1M:autoextend'
 
Logging: /home/a/env3/mariadb-environs/m6-10.2/src/mysql-test/mysql-test-run.pl  MDEV-14447 --mem --mysqld=--sequence --mysqld=--innodb-data-file-path=ibdata1:3M;ibdata2:1M:autoextend
 
vardir: /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var
 
Removing old var directory...
 
Creating var directory '/home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var'...
 
 - symlinking 'var' to '/dev/shm/var_auto_4EsX'
 
Checking supported features...
 
MariaDB Version 10.2.11-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
 
call mtr.add_suppression("InnoDB: New log files created");
 
CREATE TABLE t(a varchar(40) PRIMARY KEY, b varchar(40), c varchar(40), d varchar(40), index(b,c,d)) ENGINE INNODB;
 
# Create full backup , modify table, then create incremental/differential backup
 
total 3108
 
drwxr-x--- 6 a a     280 Nov 21 14:29 .
 
drwxr-xr-x 4 a a     140 Nov 21 14:29 ..
 
-rw-r----- 1 a a    8192 Nov 21 14:29 aria_log.00000001
 
-rw-r----- 1 a a      52 Nov 21 14:29 aria_log_control
 
-rw-r----- 1 a a     307 Nov 21 14:29 backup-my.cnf
 
-rw-r----- 1 a a    2855 Nov 21 14:29 ib_buffer_pool
 
-rw-r----- 1 a a    7168 Nov 21 14:29 ib_logfile0
 
-rw-r----- 1 a a 3145728 Nov 21 14:29 ibdata1
 
drwxr-x--- 2 a a     260 Nov 21 14:29 mtr
 
drwxr-x--- 2 a a    1800 Nov 21 14:29 mysql
 
drwxr-x--- 2 a a      60 Nov 21 14:29 performance_schema
 
drwxr-x--- 2 a a      80 Nov 21 14:29 test
 
-rw-r----- 1 a a     101 Nov 21 14:29 xtrabackup_checkpoints
 
-rw-r----- 1 a a     589 Nov 21 14:29 xtrabackup_info
 
INSERT INTO t select uuid(), uuid(), uuid(), uuid() from seq_1_to_100000;
 
COMMIT;
 
SELECT count(*) FROM t;
 
count(*)
 
100000
 
total 3108
 
drwxr-x--- 6 a a     280 Nov 21 14:29 .
 
drwxr-xr-x 4 a a     140 Nov 21 14:29 ..
 
-rw-r----- 1 a a    8192 Nov 21 14:29 aria_log.00000001
 
-rw-r----- 1 a a      52 Nov 21 14:29 aria_log_control
 
-rw-r----- 1 a a     307 Nov 21 14:29 backup-my.cnf
 
-rw-r----- 1 a a    2855 Nov 21 14:29 ib_buffer_pool
 
-rw-r----- 1 a a    7168 Nov 21 14:29 ib_logfile0
 
-rw-r----- 1 a a 3145728 Nov 21 14:29 ibdata1
 
drwxr-x--- 2 a a     260 Nov 21 14:29 mtr
 
drwxr-x--- 2 a a    1800 Nov 21 14:29 mysql
 
drwxr-x--- 2 a a      60 Nov 21 14:29 performance_schema
 
drwxr-x--- 2 a a      80 Nov 21 14:29 test
 
-rw-r----- 1 a a     101 Nov 21 14:29 xtrabackup_checkpoints
 
-rw-r----- 1 a a     589 Nov 21 14:29 xtrabackup_info
 
# Prepare full backup, apply incremental one
 
mariabackup.MDEV-14447                   [ fail ]
 
        Test ended at 2017-11-21 14:29:18
 
 
 
CURRENT_TEST: mariabackup.MDEV-14447
 
171121 14:29:16 Connecting to MySQL server host: localhost, user: root, password: set, port: 16000, socket: /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/mysqld.1.sock
 
Using server version 10.2.11-MariaDB-log
 
/home/a/env3/mariadb-environs/m6-10.2/bld/extra/mariabackup/mariabackup based on MariaDB server 10.2.11-MariaDB Linux (x86_64) 
incremental backup from 1633659 is enabled.
 
mariabackup: uses posix_fadvise().
 
mariabackup: cd to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/mysqld.1/data/
 
mariabackup: open files limit requested 1024, set to 1024
 
mariabackup: using the following InnoDB configuration:
 
mariabackup:   innodb_data_home_dir = .
 
mariabackup:   innodb_data_file_path = ibdata1:3M;ibdata2:1M:autoextend
 
mariabackup:   innodb_log_group_home_dir = ./
 
2017-11-21 14:29:16 139652062795584 [Note] InnoDB: Number of pools: 1
 
171121 14:29:16 >> log scanned up to (41609955)
 
mariabackup: Generating a list of tablespaces
 
2017-11-21 14:29:16 139652062795584 [Warning] InnoDB: Allocated tablespace ID 1 for mysql/innodb_table_stats, old maximum was 0
 
mariabackup: using the full scan for incremental backup
 
171121 14:29:16 [01] Copying ./ibdata1 to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/ibdata1.delta
 
171121 14:29:16 [01]        ...done
 
[01] mariabackup: Error: Invalid tablespace flags: ffff.
 
[01] mariabackup: Warning: We assume the table was dropped during xtrabackup execution and ignore the file.
 
[01] mariabackup: Warning: skipping tablespace innodb_system.
 
171121 14:29:16 [01] Copying ./mysql/innodb_table_stats.ibd to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/innodb_table_stats.ibd.delta
 
171121 14:29:16 [01]        ...done
 
171121 14:29:16 [01] Copying ./mysql/innodb_index_stats.ibd to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/innodb_index_stats.ibd.delta
 
171121 14:29:16 [01]        ...done
 
171121 14:29:16 [01] Copying ./test/t.ibd to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/test/t.ibd.delta
 
171121 14:29:16 [01]        ...done
 
171121 14:29:17 >> log scanned up to (41609982)
 
171121 14:29:17 Executing FLUSH NO_WRITE_TO_BINLOG TABLES...
 
171121 14:29:17 Executing FLUSH TABLES WITH READ LOCK...
 
171121 14:29:17 Starting to backup non-InnoDB tables and files
 
171121 14:29:17 [01] Copying ./mysql/db.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/db.frm
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/db.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/db.MYI
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/db.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/db.MYD
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/host.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/host.frm
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/host.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/host.MYI
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/host.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/host.MYD
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/user.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/user.frm
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/user.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/user.MYI
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/user.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/user.MYD
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/roles_mapping.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/roles_mapping.frm
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/roles_mapping.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/roles_mapping.MYI
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/roles_mapping.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/roles_mapping.MYD
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/func.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/func.frm
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/func.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/func.MYI
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/func.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/func.MYD
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/plugin.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/plugin.frm
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/plugin.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/plugin.MYI
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/plugin.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/plugin.MYD
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/servers.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/servers.frm
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/servers.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/servers.MYI
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/servers.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/servers.MYD
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/tables_priv.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/tables_priv.frm
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/tables_priv.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/tables_priv.MYI
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/tables_priv.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/tables_priv.MYD
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/columns_priv.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/columns_priv.frm
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/columns_priv.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/columns_priv.MYI
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/columns_priv.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/columns_priv.MYD
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/help_topic.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/help_topic.frm
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/help_topic.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/help_topic.MYI
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/help_topic.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/help_topic.MYD
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/help_category.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/help_category.frm
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/help_category.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/help_category.MYI
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/help_category.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/help_category.MYD
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/help_relation.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/help_relation.frm
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/help_relation.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/help_relation.MYI
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/help_relation.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/help_relation.MYD
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/help_keyword.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/help_keyword.frm
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/help_keyword.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/help_keyword.MYI
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/help_keyword.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/help_keyword.MYD
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/time_zone_name.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_name.frm
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/time_zone_name.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_name.MYI
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/time_zone_name.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_name.MYD
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/time_zone.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone.frm
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/time_zone.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone.MYI
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/time_zone.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone.MYD
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/time_zone_transition.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_transition.frm
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/time_zone_transition.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_transition.MYI
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/time_zone_transition.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_transition.MYD
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/time_zone_transition_type.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_transition_type.frm
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/time_zone_transition_type.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_transition_type.MYI
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/time_zone_transition_type.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_transition_type.MYD
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/time_zone_leap_second.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_leap_second.frm
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/time_zone_leap_second.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_leap_second.MYI
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/time_zone_leap_second.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/time_zone_leap_second.MYD
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/proc.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/proc.frm
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/proc.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/proc.MYI
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/proc.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/proc.MYD
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/procs_priv.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/procs_priv.frm
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/procs_priv.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/procs_priv.MYI
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/procs_priv.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/procs_priv.MYD
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/general_log.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/general_log.frm
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/general_log.CSM to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/general_log.CSM
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/general_log.CSV to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/general_log.CSV
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/slow_log.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/slow_log.frm
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/slow_log.CSM to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/slow_log.CSM
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/slow_log.CSV to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/slow_log.CSV
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/event.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/event.frm
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/event.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/event.MYI
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/event.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/event.MYD
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/innodb_table_stats.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/innodb_table_stats.frm
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/innodb_index_stats.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/innodb_index_stats.frm
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/proxies_priv.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/proxies_priv.frm
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/proxies_priv.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/proxies_priv.MYI
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/proxies_priv.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/proxies_priv.MYD
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/table_stats.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/table_stats.frm
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/table_stats.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/table_stats.MYI
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/table_stats.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/table_stats.MYD
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/column_stats.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/column_stats.frm
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/column_stats.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/column_stats.MYI
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/column_stats.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/column_stats.MYD
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/index_stats.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/index_stats.frm
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/index_stats.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/index_stats.MYI
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/index_stats.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/index_stats.MYD
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/gtid_slave_pos.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/gtid_slave_pos.MYI
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/gtid_slave_pos.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/gtid_slave_pos.MYD
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mysql/gtid_slave_pos.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mysql/gtid_slave_pos.frm
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./test/t.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/test/t.frm
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./performance_schema/db.opt to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/performance_schema/db.opt
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mtr/db.opt to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mtr/db.opt
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mtr/test_suppressions.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mtr/test_suppressions.frm
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mtr/test_suppressions.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mtr/test_suppressions.MYI
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mtr/test_suppressions.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mtr/test_suppressions.MYD
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mtr/ts_insert.TRN to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mtr/ts_insert.TRN
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mtr/test_suppressions.TRG to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mtr/test_suppressions.TRG
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mtr/global_suppressions.frm to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mtr/global_suppressions.frm
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mtr/global_suppressions.MYI to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mtr/global_suppressions.MYI
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mtr/global_suppressions.MYD to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mtr/global_suppressions.MYD
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mtr/gs_insert.TRN to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mtr/gs_insert.TRN
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying ./mtr/global_suppressions.TRG to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/mtr/global_suppressions.TRG
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 Finished backing up non-InnoDB tables and files
 
171121 14:29:17 [01] Copying aria_log.00000001 to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/aria_log.00000001
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 [01] Copying aria_log_control to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/aria_log_control
 
171121 14:29:17 [01]        ...done
 
171121 14:29:17 Executing FLUSH NO_WRITE_TO_BINLOG ENGINE LOGS...
 
mariabackup: The latest check point (for incremental): '38968043'
 
mariabackup: Stopping log copying thread.
 
 
 
171121 14:29:17 >> log scanned up to (41609982)
 
171121 14:29:17 Executing UNLOCK TABLES
 
171121 14:29:17 All tables unlocked
 
171121 14:29:17 [00] Copying ib_buffer_pool to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/ib_buffer_pool
 
171121 14:29:17 [00]        ...done
 
171121 14:29:17 Backup created in directory '/home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup_inc1/'
 
171121 14:29:17 [00] Writing backup-my.cnf
 
171121 14:29:17 [00]        ...done
 
171121 14:29:17 [00] Writing xtrabackup_info
 
171121 14:29:17 [00]        ...done
 
mariabackup: Redo log (from LSN 38937159 to 41609982) was copied.
 
171121 14:29:17 completed OK!
 
sh: line 1:  7340 Aborted                 (core dumped) /home/a/env3/mariadb-environs/m6-10.2/bld/extra/mariabackup/mariabackup --prepare --apply-log-only --target-dir=/home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup 2>&1
 
mysqltest: At line 22: exec of '/home/a/env3/mariadb-environs/m6-10.2/bld/extra/mariabackup/mariabackup --prepare --apply-log-only --target-dir=/home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup 2>&1' failed, error: 34304, status: 134, errno: 11
 
Output from before failure:
 
/home/a/env3/mariadb-environs/m6-10.2/bld/extra/mariabackup/mariabackup based on MariaDB server 10.2.11-MariaDB Linux (x86_64) 
mariabackup: cd to /home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/tmp/backup/
 
mariabackup: This target seems to be not prepared yet.
 
mariabackup: using the following InnoDB configuration for recovery:
 
mariabackup:   innodb_data_home_dir = .
 
mariabackup:   innodb_data_file_path = ibdata1:3M;ibdata2:1M:autoextend
 
mariabackup:   innodb_log_group_home_dir = .
 
mariabackup: Starting InnoDB instance for recovery.
 
mariabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter)
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Uses event mutexes
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Compressed tables use zlib 1.2.11
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Number of pools: 1
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Using SSE2 crc32 instructions
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Initializing buffer pool, total size = 100M, instances = 1, chunk size = 100M
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Completed initialization of buffer pool
 
2017-11-21 14:29:17 140342552688384 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Need to create a new innodb_system data file 'ibdata2'.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Setting file './ibdata2' size to 1 MB. Physically writing the file full; Please wait ...
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: File './ibdata2' size is now 1 MB.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Highest supported file format is Barracuda.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Starting crash recovery from checkpoint LSN=1633659
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=290] in the doublewrite buffer slot 0 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=291] in the doublewrite buffer slot 1 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=292] in the doublewrite buffer slot 2 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=293] in the doublewrite buffer slot 3 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=294] in the doublewrite buffer slot 4 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=295] in the doublewrite buffer slot 5 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=296] in the doublewrite buffer slot 6 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=297] in the doublewrite buffer slot 7 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=298] in the doublewrite buffer slot 8 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=299] in the doublewrite buffer slot 9 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=300] in the doublewrite buffer slot 10 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=301] in the doublewrite buffer slot 12 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=302] in the doublewrite buffer slot 19 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=303] in the doublewrite buffer slot 21 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=304] in the doublewrite buffer slot 22 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=305] in the doublewrite buffer slot 23 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=306] in the doublewrite buffer slot 24 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=307] in the doublewrite buffer slot 25 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=308] in the doublewrite buffer slot 26 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=309] in the doublewrite buffer slot 27 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=310] in the doublewrite buffer slot 28 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=311] in the doublewrite buffer slot 31 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=312] in the doublewrite buffer slot 36 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=313] in the doublewrite buffer slot 39 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=314] in the doublewrite buffer slot 40 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=315] in the doublewrite buffer slot 41 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=316] in the doublewrite buffer slot 42 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=317] in the doublewrite buffer slot 43 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=318] in the doublewrite buffer slot 44 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=319] in the doublewrite buffer slot 45 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=320] in the doublewrite buffer slot 46 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=321] in the doublewrite buffer slot 47 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=323] in the doublewrite buffer slot 48 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=322] in the doublewrite buffer slot 49 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=324] in the doublewrite buffer slot 50 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=325] in the doublewrite buffer slot 51 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Recovered page [page id: space=0, page number=222] from the doublewrite buffer.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Recovered page [page id: space=0, page number=223] from the doublewrite buffer.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Recovered page [page id: space=0, page number=224] from the doublewrite buffer.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Recovered page [page id: space=0, page number=225] from the doublewrite buffer.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Recovered page [page id: space=0, page number=226] from the doublewrite buffer.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Recovered page [page id: space=0, page number=227] from the doublewrite buffer.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Recovered page [page id: space=0, page number=228] from the doublewrite buffer.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Recovered page [page id: space=0, page number=229] from the doublewrite buffer.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Recovered page [page id: space=0, page number=230] from the doublewrite buffer.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Recovered page [page id: space=0, page number=231] from the doublewrite buffer.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Recovered page [page id: space=0, page number=232] from the doublewrite buffer.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Recovered page [page id: space=0, page number=233] from the doublewrite buffer.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Recovered page [page id: space=0, page number=234] from the doublewrite buffer.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Recovered page [page id: space=0, page number=235] from the doublewrite buffer.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Recovered page [page id: space=0, page number=236] from the doublewrite buffer.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Recovered page [page id: space=0, page number=237] from the doublewrite buffer.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Recovered page [page id: space=0, page number=238] from the doublewrite buffer.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Recovered page [page id: space=0, page number=239] from the doublewrite buffer.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Recovered page [page id: space=0, page number=240] from the doublewrite buffer.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Recovered page [page id: space=0, page number=241] from the doublewrite buffer.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Recovered page [page id: space=0, page number=242] from the doublewrite buffer.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Recovered page [page id: space=0, page number=244] from the doublewrite buffer.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Recovered page [page id: space=0, page number=243] from the doublewrite buffer.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Recovered page [page id: space=0, page number=245] from the doublewrite buffer.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Recovered page [page id: space=0, page number=246] from the doublewrite buffer.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Recovered page [page id: space=0, page number=247] from the doublewrite buffer.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Recovered page [page id: space=0, page number=248] from the doublewrite buffer.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Recovered page [page id: space=0, page number=249] from the doublewrite buffer.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Recovered page [page id: space=0, page number=250] from the doublewrite buffer.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Recovered page [page id: space=0, page number=251] from the doublewrite buffer.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Recovered page [page id: space=0, page number=252] from the doublewrite buffer.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Recovered page [page id: space=0, page number=253] from the doublewrite buffer.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Recovered page [page id: space=0, page number=254] from the doublewrite buffer.
 
2017-11-21 14:29:17 140343395125056 [Note] InnoDB: Recovered page [page id: space=0, page number=255] from the doublewrite buffer.
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=256] in the doublewrite buffer slot 86 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=257] in the doublewrite buffer slot 87 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=258] in the doublewrite buffer slot 88 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=259] in the doublewrite buffer slot 89 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=260] in the doublewrite buffer slot 90 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=261] in the doublewrite buffer slot 91 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=262] in the doublewrite buffer slot 92 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=263] in the doublewrite buffer slot 93 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=264] in the doublewrite buffer slot 94 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=265] in the doublewrite buffer slot 95 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=266] in the doublewrite buffer slot 96 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=267] in the doublewrite buffer slot 97 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=268] in the doublewrite buffer slot 98 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=269] in the doublewrite buffer slot 99 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=270] in the doublewrite buffer slot 100 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=271] in the doublewrite buffer slot 101 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=272] in the doublewrite buffer slot 102 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=273] in the doublewrite buffer slot 103 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=274] in the doublewrite buffer slot 104 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=275] in the doublewrite buffer slot 105 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=276] in the doublewrite buffer slot 106 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=277] in the doublewrite buffer slot 107 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=278] in the doublewrite buffer slot 108 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=279] in the doublewrite buffer slot 109 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=280] in the doublewrite buffer slot 110 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=281] in the doublewrite buffer slot 111 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=282] in the doublewrite buffer slot 112 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=283] in the doublewrite buffer slot 113 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=284] in the doublewrite buffer slot 114 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=285] in the doublewrite buffer slot 115 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=286] in the doublewrite buffer slot 116 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=287] in the doublewrite buffer slot 117 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=288] in the doublewrite buffer slot 118 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [Warning] InnoDB: A copy of page [page id: space=0, page number=289] in the doublewrite buffer slot 119 is not within space bounds
 
2017-11-21 14:29:17 140343395125056 [ERROR] [FATAL] InnoDB: Trying to read page number 301 in space 0, space name innodb_system, which is outside the tablespace bounds. Byte offset 0, len 16384Please check that the configuration matches the InnoDB system tablespace location (ibdata files)
 
171121 14:29:17 [ERROR] mysqld got signal 6 ;
 
This could be because you hit a bug. It is also possible that this binary
 
or one of the libraries it was linked against is corrupt, improperly built,
 
or misconfigured. This error can also be caused by malfunctioning hardware.
 
 
 
To report this bug, see https://mariadb.com/kb/en/reporting-bugs
 
 
 
We will try our best to scrape up some info that will hopefully help
 
diagnose the problem, but since we have already crashed, 
something is definitely wrong and this may fail.
 
 
 
Server version: 10.2.11-MariaDB
 
key_buffer_size=0
 
read_buffer_size=131072
 
max_used_connections=0
 
max_threads=1
 
thread_count=0
 
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 5396 K  bytes of memory
 
Hope that's ok; if not, decrease some variables in the equation.
 
 
 
Thread pointer: 0x0
 
Attempting backtrace. You can use the following information to find out
 
where mysqld died. If you see no messages after this, something went
 
terribly wrong...
 
stack_bottom = 0x0 thread_stack 0x49000
 
/home/a/env3/mariadb-environs/m6-10.2/bld/extra/mariabackup/mariabackup(my_print_stacktrace+0x29)[0x560674e765c9]
 
/home/a/env3/mariadb-environs/m6-10.2/bld/extra/mariabackup/mariabackup(handle_fatal_signal+0x3bd)[0x560674a114cd]
 
/lib/x86_64-linux-gnu/libpthread.so.0(+0x11670)[0x7fa43df62670]
 
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0x9f)[0x7fa43c41077f]
 
/lib/x86_64-linux-gnu/libc.so.6(abort+0x16a)[0x7fa43c41237a]
 
/home/a/env3/mariadb-environs/m6-10.2/bld/extra/mariabackup/mariabackup(+0x9a103d)[0x560674d0103d]
 
/home/a/env3/mariadb-environs/m6-10.2/bld/extra/mariabackup/mariabackup(+0x40b8e7)[0x56067476b8e7]
 
mysys/stacktrace.c:268(my_print_stacktrace)[0x560674b76603]
 
fil/fil0fil.cc:1015(fil_space_extend_must_retry(fil_space_t*, fil_node_t*, unsigned long, bool*))[0x560674b462bd]
 
include/sync0types.h:1206(simple_counter<unsigned long, false>::add(unsigned long))[0x560674b46e67]
 
buf/buf0buf.cc:4319(buf_page_get_gen(page_id_t const&, page_size_t const&, unsigned long, buf_block_t*, unsigned long, char const*, unsigned int, mtr_t*, dberr_t*))[0x560674b24ee5]
 
include/trx0undo.ic:168(trx_undo_page_get)[0x560674cfa5a0]
 
trx/trx0rseg.cc:198(trx_rseg_mem_restore(trx_rseg_t*, mtr_t*))[0x560674ce41b6]
 
trx/trx0rseg.cc:261(trx_rseg_array_init())[0x560674ce51ad]
 
trx/trx0trx.cc:994(trx_lists_init_at_db_start())[0x560674cf4dc7]
 
trx/trx0sys.cc:513(trx_sys_init_at_db_start())[0x560674ce917d]
 
srv/srv0start.cc:2257(innobase_start_or_create_for_mysql())[0x560674cbcea9]
 
mariabackup/xtrabackup.cc:1654(innodb_init)[0x560674790415]
 
mariabackup/xtrabackup.cc:5296(main)[0x560674774611]
 
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf1)[0x7fa43c3fb3f1]
 
/home/a/env3/mariadb-environs/m6-10.2/bld/extra/mariabackup/mariabackup(_start+0x2a)[0x560674788fba]
 
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
 
information that should help you find out what is causing the crash.
 
 
 
 - saving '/home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/log/mariabackup.MDEV-14447/' to '/home/a/env3/mariadb-environs/_depot/m-branch/m6-10.2-bld/mysql-test/var/log/mariabackup.MDEV-14447/'
 
--------------------------------------------------------------------------
 
The servers were restarted 0 times
 
Spent 0.000 of 9 seconds executing testcases
 
 
 
Failure: Failed 1/1 tests, 0.00% were successful.
 
 
 
Failing test(s): mariabackup.MDEV-14447
 
 
 
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
 
 
 
mysql-test-run: *** ERROR: there were failing test cases

Comment by Vladislav Vaintroub [ 2017-11-24 ]

Fixed in 10.1
Leaving merge to 10.2, and fixes and possible adjustments to marko.
marko, when merging please note, I used fil_extend_space_to_desired_size() in 10.1, the 10.2 function for that is called file_space_extend()

Comment by Marko Mäkelä [ 2017-11-24 ]

I filed and fixed MDEV-14499 for the additional issue in 10.2.

Generated at Thu Feb 08 08:13:37 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.