test galera_sst_xtrabackup-v2 fails with "Cleanup after exit with status:1"

++ innobackupex --no-version-check --apply-log /home/a/env1/m5-10.1/build/mysql-test/var/mysqld.2/data//.sst

+ extcode=0

+ return 0

+ '[' 0 -ne 0 ']'

+ MAGIC_FILE=/home/a/env1/m5-10.1/build/mysql-test/var/mysqld.2/data//xtrabackup_galera_info

+ set +e

+ rm /home/a/env1/m5-10.1/build/mysql-test/var/mysqld.2/data//innobackup.prepare.log /home/a/env1/m5-10.1/build/mysql-test/var/mysqld.2/data//innobackup.move.log

rm: cannot remove '/home/a/env1/m5-10.1/build/mysql-test/var/mysqld.2/data//innobackup.prepare.log': No such file or directory

rm: cannot remove '/home/a/env1/m5-10.1/build/mysql-test/var/mysqld.2/data//innobackup.move.log': No such file or directory

+ set -e

+ wsrep_log_info 'Moving the backup to /home/a/env1/m5-10.1/build/mysql-test/var/mysqld.2/data/'

+ wsrep_log '[INFO] Moving the backup to /home/a/env1/m5-10.1/build/mysql-test/var/mysqld.2/data/'

++ date '+%Y%m%d %H:%M:%S.%N'

++ cut -b -21

+ local readonly 'tst=20171009 12:19:46.774'

+ echo 'WSREP_SST: [INFO] Moving the backup to /home/a/env1/m5-10.1/build/mysql-test/var/mysqld.2/data/ (20171009 12:19:46.774)'

WSREP_SST: [INFO] Moving the backup to /home/a/env1/m5-10.1/build/mysql-test/var/mysqld.2/data/ (20171009 12:19:46.774)

+ timeit 'Xtrabackup move stage' 'innobackupex --defaults-file=--defaults-file=/home/a/env1/m5-10.1/build/mysql-test/var/my.cnf   --defaults-group=mysqld --no-version-check  --datadir=/home/a/env1/m5-10.1/build/mysql-test/var/mysqld.2/data/ --move-back --force-non-empty-directories ${DATA} &>${DATA}/innobackup.move.log'

+ local 'stage=Xtrabackup move stage'

+ shift

+ local 'cmd=innobackupex --defaults-file=--defaults-file=/home/a/env1/m5-10.1/build/mysql-test/var/my.cnf   --defaults-group=mysqld --no-version-check  --datadir=/home/a/env1/m5-10.1/build/mysql-test/var/mysqld.2/data/ --move-back --force-non-empty-directories ${DATA} &>${DATA}/innobackup.move.log'

+ local x1 x2 took extcode

+ [[ 0 -eq 1 ]]

+ wsrep_log_info 'Evaluating innobackupex --defaults-file=--defaults-file=/home/a/env1/m5-10.1/build/mysql-test/var/my.cnf   --defaults-group=mysqld --no-version-check  --datadir=/home/a/env1/m5-10.1/build/mysql-test/var/mysqld.2/data/ --move-back --force-non-empty-directories ${DATA} &>${DATA}/innobackup.move.log'

+ wsrep_log '[INFO] Evaluating innobackupex --defaults-file=--defaults-file=/home/a/env1/m5-10.1/build/mysql-test/var/my.cnf   --defaults-group=mysqld --no-version-check  --datadir=/home/a/env1/m5-10.1/build/mysql-test/var/mysqld.2/data/ --move-back --force-non-empty-directories ${DATA} &>${DATA}/innobackup.move.log'

++ date '+%Y%m%d %H:%M:%S.%N'

++ cut -b -21

+ local readonly 'tst=20171009 12:19:46.776'

+ echo 'WSREP_SST: [INFO] Evaluating innobackupex --defaults-file=--defaults-file=/home/a/env1/m5-10.1/build/mysql-test/var/my.cnf   --defaults-group=mysqld --no-version-check  --datadir=/home/a/env1/m5-10.1/build/mysql-test/var/mysqld.2/data/ --move-back --force-non-empty-directories ${DATA} &>${DATA}/innobackup.move.log (20171009 12:19:46.776)'

WSREP_SST: [INFO] Evaluating innobackupex --defaults-file=--defaults-file=/home/a/env1/m5-10.1/build/mysql-test/var/my.cnf   --defaults-group=mysqld --no-version-check  --datadir=/home/a/env1/m5-10.1/build/mysql-test/var/mysqld.2/data/ --move-back --force-non-empty-directories ${DATA} &>${DATA}/innobackup.move.log (20171009 12:19:46.776)

+ eval 'innobackupex --defaults-file=--defaults-file=/home/a/env1/m5-10.1/build/mysql-test/var/my.cnf   --defaults-group=mysqld --no-version-check  --datadir=/home/a/env1/m5-10.1/build/mysql-test/var/mysqld.2/data/ --move-back --force-non-empty-directories ${DATA} &>${DATA}/innobackup.move.log'

innobackupex --defaults-file=--defaults-file=/home/a/env1/m5-10.1/build/mysql-test/var/my.cnf   --defaults-group=mysqld --no-version-check  --datadir=/home/a/env1/m5-10.1/build/mysql-test/var/mysqld.2/data/ --move-back --force-non-empty-directories ${DATA} &>${DATA}/innobackup.move.log

++ innobackupex --defaults-file=--defaults-file=/home/a/env1/m5-10.1/build/mysql-test/var/my.cnf --defaults-group=mysqld --no-version-check --datadir=/home/a/env1/m5-10.1/build/mysql-test/var/mysqld.2/data/ --move-back --force-non-empty-directories /home/a/env1/m5-10.1/build/mysql-test/var/mysqld.2/data//.sst

cleanup_joiner

+ cleanup_joiner

+ local estatus=1

+ [[ 1 -ne 0 ]]

+ wsrep_log_error 'Cleanup after exit with status:1'

+ wsrep_log '[ERROR] Cleanup after exit with status:1'

++ date '+%Y%m%d %H:%M:%S.%N'

++ cut -b -21

+ local readonly 'tst=20171009 12:19:46.776'

+ echo 'WSREP_SST: [INFO] Evaluating innobackupex --defaults-file=--defaults-file=/home/a/env1/m5-10.1/build/mysql-test/var/my.cnf   --defaults-group=mysqld --no-version-check  --datadir=/home/a/env1/m5-10.1/build/mysql-test/var/mysqld.2/data/ --move-back --force-non-empty-directories ${DATA} &>${DATA}/innobackup.move.log (20171009 12:19:46.776)'

WSREP_SST: [INFO] Evaluating innobackupex --defaults-file=--defaults-file=/home/a/env1/m5-10.1/build/mysql-test/var/my.cnf   --defaults-group=mysqld --no-version-check  --datadir=/home/a/env1/m5-10.1/build/mysql-test/var/mysqld.2/data/ --move-back --force-non-empty-directories ${DATA} &>${DATA}/innobackup.move.log (20171009 12:19:46.776)

+ eval 'innobackupex --defaults-file=--defaults-file=/home/a/env1/m5-10.1/build/mysql-test/var/my.cnf   --defaults-group=mysqld --no-version-check  --datadir=/home/a/env1/m5-10.1/build/mysql-test/var/mysqld.2/data/ --move-back --force-non-empty-directories ${DATA} &>${DATA}/innobackup.move.log'

innobackupex --defaults-file=--defaults-file=/home/a/env1/m5-10.1/build/mysql-test/var/my.cnf   --defaults-group=mysqld --no-version-check  --datadir=/home/a/env1/m5-10.1/build/mysql-test/var/mysqld.2/data/ --move-back --force-non-empty-directories ${DATA} &>${DATA}/innobackup.move.log

++ innobackupex --defaults-file=--defaults-file=/home/a/env1/m5-10.1/build/mysql-test/var/my.cnf --defaults-group=mysqld --no-version-check --datadir=/home/a/env1/m5-10.1/build/mysql-test/var/mysqld.2/data/ --move-back --force-non-empty-directories /home/a/env1/m5-10.1/build/mysql-test/var/mysqld.2/data//.sst

cleanup_joiner

+ cleanup_joiner

+ local estatus=1

+ [[ 1 -ne 0 ]]

+ wsrep_log_error 'Cleanup after exit with status:1'

+ wsrep_log '[ERROR] Cleanup after exit with status:1'

++ date '+%Y%m%d %H:%M:%S.%N'

++ cut -b -21

+ local readonly 'tst=20171009 12:19:46.781'

+ echo 'WSREP_SST: [ERROR] Cleanup after exit with status:1 (20171009 12:19:46.781)'

WSREP_SST: [ERROR] Cleanup after exit with status:1 (20171009 12:19:46.781)

+ [[ -n '' ]]

+ [[ -n /tmp/tmp.QrAMDBPlUk ]]

+ [[ -d /tmp/tmp.QrAMDBPlUk ]]

+ rm -rf /tmp/tmp.QrAMDBPlUk

++ ps -o pgid= 32071

++ grep -o '[0-9]*'

+ pgid=32070

+ [[ 32071 -eq 32070 ]]

+ exit 1

2017-10-09 12:19:46 139871427491584 [ERROR] WSREP: Process completed with error: wsrep_sst_xtrabackup-v2 --role 'joiner' --address '127.0.0.1:16007' --datadir '/home/a/env1/m5-10.1/build/mysql-test/var/mysqld.2/data/'  --defaults-file '/home/a/env1/m5-10.1/build/mysql-test/var/my.cnf'  --parent '32035'  '' : 1 (Operation not permitted)

2017-10-09 12:19:46 139871427491584 [ERROR] WSREP: Failed to read uuid:seqno and wsrep_gtid_domain_id from joiner script.

2017-10-09 12:19:46 139871661820864 [ERROR] WSREP: SST failed: 1 (Operation not permitted)

2017-10-09 12:19:46 139871661820864 [ERROR] Aborting

m5-10.1/build/mysql-test/mtr galera_sst_xtrabackup-v2

Logging: /home/a/env1/_depot/m-branch/10.1/mysql-test/mysql-test-run.pl  galera_sst_xtrabackup-v2

vardir: /home/a/env1/m5-10.1/build/mysql-test/var

Checking leftover processes...

Removing old var directory...

Creating var directory '/home/a/env1/m5-10.1/build/mysql-test/var'...

Checking supported features...

MariaDB Version 10.1.29-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

worker[1] mysql-test-run: WARNING: Process [mysqld.2 - pid: 31176, winpid: 31176, exit: 256] died after mysql-test-run waited 32.6 seconds for /home/a/env1/m5-10.1/build/mysql-test/var/run/mysqld.2.pid to be created.

galera.galera_sst_xtrabackup-v2 'innodb_plugin' [ fail ]

        Test ended at 2017-10-09 12:17:45

CURRENT_TEST: galera.galera_sst_xtrabackup-v2

Failed to start mysqld.2

mysqltest failed but provided no output

 - saving '/home/a/env1/m5-10.1/build/mysql-test/var/log/galera.galera_sst_xtrabackup-v2-innodb_plugin/' to '/home/a/env1/m5-10.1/build/mysql-test/var/log/galera.galera_sst_xtrabackup-v2-innodb_plugin/'

Only  1  of 2 completed.

--------------------------------------------------------------------------

The servers were restarted 0 times

Spent 0.000 of 42 seconds executing testcases

Failure: Failed 1/1 tests, 0.00% were successful.

Failing test(s): galera.galera_sst_xtrabackup-v2