[MDEV-15836] MariaDB galera SST broken using mariabackup Created: 2018-04-10  Updated: 2018-09-11  Resolved: 2018-09-11

Status: Closed
Project: MariaDB Server
Component/s: Galera SST
Affects Version/s: 10.2.13
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: Massimo Assignee: Vladislav Vaintroub
Resolution: Duplicate Votes: 1
Labels: None
Environment:

Linux 3.10.0-693.21.1.el7.x86_64 #1 SMP Wed Mar 7 19:03:37 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux
CentOS Linux release 7.4.1708 (Core)
Derived from Red Hat Enterprise Linux 7.4 (Source)
NAME="CentOS Linux"
VERSION="7 (Core)"
ID="centos"
ID_LIKE="rhel fedora"
VERSION_ID="7"
PRETTY_NAME="CentOS Linux 7 (Core)"
ANSI_COLOR="0;31"
CPE_NAME="cpe:/o:centos:centos:7"
HOME_URL="https://www.centos.org/"
BUG_REPORT_URL="https://bugs.centos.org/"

CENTOS_MANTISBT_PROJECT="CentOS-7"
CENTOS_MANTISBT_PROJECT_VERSION="7"
REDHAT_SUPPORT_PRODUCT="centos"
REDHAT_SUPPORT_PRODUCT_VERSION="7"

CentOS Linux release 7.4.1708 (Core)
CentOS Linux release 7.4.1708 (Core)
cpe:/o:centos:centos:7

Issue Links:
Duplicate
duplicates MDEV-12956 datadir must be specified in [mysqld]... Closed

 Description   

Bootstrap the first node (1.1 T) and start the second node with mariabackup as SST option.
With mariabackup it fail, with xtraback-v2 it works.
details:

same for node01( bootstap) and node02:
[root@~]# rpm -qa | grep -i maria
MariaDB-compat-10.2.13-1.el7.centos.x86_64
MariaDB-backup-10.2.13-1.el7.centos.x86_64
MariaDB-common-10.2.13-1.el7.centos.x86_64
MariaDB-server-10.2.13-1.el7.centos.x86_64
MariaDB-client-10.2.13-1.el7.centos.x86_64
[root@~]# rpm -qa | grep -i xtra
percona-xtrabackup-24-2.4.9-1.el7.x86_64

when mariaback is used:
SST started and it fail basically at the end :

mysql error log node02:

2018-04-09 20:34:06 140370872628992 [Note] WSREP: view((empty))
2018-04-09 20:34:06 140370872628992 [Note] WSREP: gcomm: closed
2018-04-09 20:34:06 140370872628992 [Note] WSREP: /usr/sbin/mysqld: Terminated.
WSREP_SST: [ERROR] Removing /data/mysql//.sst/xtrabackup_galera_info file due to signal (20180409 20:34:12.897)
rm: cannot remove ‘/data/mysql//innobackup.prepare.log’: No such file or directory
rm: cannot remove ‘/data/mysql//innobackup.move.log’: No such file or directory
WSREP_SST: [INFO] Moving the backup to /data/mysql/ (20180409 20:34:12.906)
WSREP_SST: [INFO] Evaluating mariabackup --innobackupex --move-back --force-non-empty-directories ${DATA} &>${DATA}/innobackup.move.log (20180409 20:34:12.910)
WSREP_SST: [INFO] Move successful, removing /data/mysql//.sst (20180409 20:34:12.987)
WSREP_SST: [ERROR] SST magic file /data/mysql//xtrabackup_galera_info not found/readable (20180409 20:34:12.995)
WSREP_SST: [ERROR] Cleanup after exit with status:2 (20180409 20:34:12.999)

from innobackup.prepare.log of node02:

180409 20:34:00 innobackupex: Starting the apply-log operation

IMPORTANT: Please check that the apply-log run completes successfully.
At the end of a successful apply-log run innobackupex
prints "completed OK!".

--innobackupex based on MariaDB server 10.2.13-MariaDB Linux (x86_64)
mariabackup: cd to /data/mysql/.sst/
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:10M: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)
2018-04-09 20:34:00 140560545577088 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2018-04-09 20:34:00 140560545577088 [Note] InnoDB: Uses event mutexes
2018-04-09 20:34:00 140560545577088 [Note] InnoDB: Compressed tables use zlib 1.2.7
2018-04-09 20:34:00 140560545577088 [Note] InnoDB: Number of pools: 1
2018-04-09 20:34:00 140560545577088 [Note] InnoDB: Using SSE2 crc32 instructions
2018-04-09 20:34:00 140560545577088 [Note] InnoDB: Initializing buffer pool, total size = 100M, instances = 1, chunk size = 100M
2018-04-09 20:34:00 140560545577088 [Note] InnoDB: Completed initialization of buffer pool
2018-04-09 20:34:00 140560264582912 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2018-04-09 20:34:00 140560545577088 [Note] InnoDB: Highest supported file format is Barracuda.
2018-04-09 20:34:00 140560545577088 [Note] InnoDB: Starting crash recovery from checkpoint LSN=1129738763324
2018-04-09 20:34:03 140560545577088 [Note] InnoDB: Starting a batch to recover 16805 pages from redo log.
2018-04-09 20:34:06 140560545577088 [Note] InnoDB: Starting a batch to recover 16949 pages from redo log.
2018-04-09 20:34:09 140560545577088 [Note] InnoDB: Starting a batch to recover 17923 pages from redo log.
2018-04-09 20:34:11 140560545577088 [ERROR] InnoDB: We scanned the log up to 1129739289600. A checkpoint was at 1129642536715 and the maximum LSN on a database page was 1131122644674. It is possible that the database is now corrupt!
2018-04-09 20:34:11 140560545577088 [Note] InnoDB: Starting final batch to recover 893 pages from redo log.
2018-04-09 20:34:11 140560545577088 [ERROR] InnoDB: Page [page id: space=444, page number=1277953] log sequence number 1130614587164 is in the future! Current system log sequence number 1129739289517.
2018-04-09 20:34:11 140560545577088 [ERROR] InnoDB: Your database may be corrupt or you may have copied the InnoDB tablespace but not the InnoDB log files. Please refer to https://mariadb.com/kb/en/library/xtradbinnodb-recovery-modes/ for information about forcing recovery.
2018-04-09 20:34:11 140560331724544 [ERROR] InnoDB: Page [page id: space=0, page number=98338] log sequence number 1129739977516 is in the future! Current system log sequence number 1129739289517.
2018-04-09 20:34:11 140560331724544 [ERROR] InnoDB: Your database may be corrupt or you may have copied the InnoDB tablespace but not the InnoDB log files. Please refer to https://mariadb.com/kb/en/library/xtradbinnodb-recovery-modes/ for information about forcing recovery.
2018-04-09 20:34:11 140560331724544 [ERROR] InnoDB: Page [page id: space=0, page number=98339] log sequence number 1129764554732 is in the future! Current system log sequence number 1129739289517.
2018-04-09 20:34:11 140560331724544 [ERROR] InnoDB: Your database may be corrupt or you may have copied the InnoDB tablespace but not the InnoDB log files. Please refer to https://mariadb.com/kb/en/library/xtradbinnodb-recovery-modes/ for information about forcing recovery.
2018-04-09 20:34:11 140560306546432 [ERROR] InnoDB: Page [page id: space=503, page number=732882] log sequence number 1130160000447 is in the future! Current system log sequence number 1129739289517.
2018-04-09 20:34:11 140560306546432 [ERROR] InnoDB: Your database may be corrupt or you may have copied the InnoDB tablespace but not the InnoDB log files. Please refer to https://mariadb.com/kb/en/library/xtradbinnodb-recovery-modes/ for information about forcing recovery.
2018-04-09 20:34:11 140560314939136 [ERROR] InnoDB: Page [page id: space=196, page number=232866] log sequence number 1129861043014 is in the future! Current system log sequence number 1129739289517.
2018-04-09 20:34:11 140560314939136 [ERROR] InnoDB: Your database may be corrupt or you may have copied the InnoDB tablespace but not the InnoDB log files. Please refer to https://mariadb.com/kb/en/library/xtradbinnodb-recovery-modes/ for information about forcing recovery.
2018-04-09 20:34:11 140560331724544 [ERROR] InnoDB: Page [page id: space=343, page number=3] log sequence number 1130893331080 is in the future! Current system log sequence number 1129739289517.
2018-04-09 20:34:11 140560331724544 [ERROR] InnoDB: Your database may be corrupt or you may have copied the InnoDB tablespace but not the InnoDB log files. Please refer to https://mariadb.com/kb/en/library/xtradbinnodb-recovery-modes/ for information about forcing recovery.
2018-04-09 20:34:11 140560306546432 [ERROR] InnoDB: Page [page id: space=503, page number=732884] log sequence number 1130291341737 is in the future! Current system log sequence number 1129739289517.
2018-04-09 20:34:11 140560306546432 [ERROR] InnoDB: Your database may be corrupt or you may have copied the InnoDB tablespace but not the InnoDB log files. Please refer to https://mariadb.com/kb/en/library/xtradbinnodb-recovery-modes/ for information about forcing recovery.
2018-04-09 20:34:11 140560323331840 [ERROR] InnoDB: Page [page id: space=240, page number=2897] log sequence number 1129964191715 is in the future! Current system log sequence number 1129739289517.
2018-04-09 20:34:11 140560323331840 [ERROR] InnoDB: Your database may be corrupt or you may have copied the InnoDB tablespace but not the InnoDB log files. Please refer to https://mariadb.com/kb/en/library/xtradbinnodb-recovery-modes/ for information about forcing recovery.
2018-04-09 20:34:11 140560314939136 [ERROR] InnoDB: Page [page id: space=552, page number=536491] log sequence number 1129770654451 is in the future! Current system log sequence number 1129739289517.
2018-04-09 20:34:11 140560331724544 [ERROR] InnoDB: Page [page id: space=343, page number=8] log sequence number 1130929049236 is in the future! Current system log sequence number 1129739289517.
2018-04-09 20:34:11 140560331724544 [ERROR] InnoDB: Your database may be corrupt or you may have copied the InnoDB tablespace but not the InnoDB log files. Please refer to https://mariadb.com/kb/en/library/xtradbinnodb-recovery-modes/ for information about forcing recovery.
2018-04-09 20:34:11 140560306546432 [ERROR] InnoDB: Page [page id: space=215, page number=480] log sequence number 1130655708639 is in the future! Current system log sequence number 1129739289517.
2018-04-09 20:34:11 140560306546432 [ERROR] InnoDB: Your database may be corrupt or you may have copied the InnoDB tablespace but not the InnoDB log files. Please refer to https://mariadb.com/kb/en/library/xtradbinnodb-recovery-modes/ for information about forcing recovery.
2018-04-09 20:34:11 140560314939136 [ERROR] InnoDB: Your database may be corrupt or you may have copied the InnoDB tablespace but not the InnoDB log files. Please refer to https://mariadb.com/kb/en/library/xtradbinnodb-recovery-modes/ for information about forcing recovery.
2018-04-09 20:34:11 140560323331840 [ERROR] InnoDB: Page [page id: space=487, page number=101980] log sequence number 1130093651881 is in the future! Current system log sequence number 1129739289517.
2018-04-09 20:34:11 140560331724544 [ERROR] InnoDB: Page [page id: space=343, page number=9] log sequence number 1130929049254 is in the future! Current system log sequence number 1129739289517.
2018-04-09 20:34:11 140560331724544 [ERROR] InnoDB: Your database may be corrupt or you may have copied the InnoDB tablespace but not the InnoDB log files. Please refer to https://mariadb.com/kb/en/library/xtradbinnodb-recovery-modes/ for information about forcing recovery.
2018-04-09 20:34:11 140560323331840 [ERROR] InnoDB: Your database may be corrupt or you may have copied the InnoDB tablespace but not the InnoDB log files. Please refer to https://mariadb.com/kb/en/library/xtradbinnodb-recovery-modes/ for information about forcing recovery.
2018-04-09 20:34:11 140560314939136 [ERROR] InnoDB: Page [page id: space=558, page number=7314] log sequence number 1130083883336 is in the future! Current system log sequence number 1129739289517.
2018-04-09 20:34:11 140560314939136 [ERROR] InnoDB: Your database may be corrupt or you may have copied the InnoDB tablespace but not the InnoDB log files. Please refer to https://mariadb.com/kb/en/library/xtradbinnodb-recovery-modes/ for information about forcing recovery.
......
......
2018-04-09 20:34:12 140560331724544 [ERROR] InnoDB: Page [page id: space=127, page number=2788865] log sequence number 1130197446545 is in the future! Current system log sequence number 1129739289517.
2018-04-09 20:34:12 140560331724544 [ERROR] InnoDB: Your database may be corrupt or you may have copied the InnoDB tablespace but not the InnoDB log files. Please refer to https://mariadb.com/kb/en/library/xtradbinnodb-recovery-modes/ for information about forcing recovery.
2018-04-09 20:34:12 140560331724544 [ERROR] InnoDB: Page [page id: space=444, page number=2899968] log sequence number 1131013290244 is in the future! Current system log sequence number 1129739289517.
2018-04-09 20:34:12 140560331724544 [ERROR] InnoDB: Your database may be corrupt or you may have copied the InnoDB tablespace but not the InnoDB log files. Please refer to https://mariadb.com/kb/en/library/xtradbinnodb-recovery-modes/ for information about forcing recovery.
2018-04-09 20:34:12 140560331724544 [ERROR] InnoDB: Page [page id: space=444, page number=2949676] log sequence number 1130648963935 is in the future! Current system log sequence number 1129739289517.
2018-04-09 20:34:12 140560331724544 [ERROR] InnoDB: Your database may be corrupt or you may have copied the InnoDB tablespace but not the InnoDB log files. Please refer to https://mariadb.com/kb/en/library/xtradbinnodb-recovery-modes/ for information about forcing recovery.
2018-04-09 20:34:12 140560331724544 [ERROR] InnoDB: Page [page id: space=307, page number=4579605] log sequence number 1131118362954 is in the future! Current system log sequence number 1129739289517.
2018-04-09 20:34:12 140560331724544 [ERROR] InnoDB: Your database may be corrupt or you may have copied the InnoDB tablespace but not the InnoDB log files. Please refer to https://mariadb.com/kb/en/library/xtradbinnodb-recovery-modes/ for information about forcing recovery.
2018-04-09 20:34:12 140560331724544 [ERROR] InnoDB: Page [page id: space=307, page number=4639036] log sequence number 1129842964079 is in the future! Current system log sequence number 1129739289517.
2018-04-09 20:34:12 140560331724544 [ERROR] InnoDB: Your database may be corrupt or you may have copied the InnoDB tablespace but not the InnoDB log files. Please refer to https://mariadb.com/kb/en/library/xtradbinnodb-recovery-modes/ for information about forcing recovery.
2018-04-09 20:34:12 140560331724544 [ERROR] InnoDB: Page [page id: space=307, page number=4679434] log sequence number 1129807107124 is in the future! Current system log sequence number 1129739289517.
2018-04-09 20:34:12 140560331724544 [ERROR] InnoDB: Your database may be corrupt or you may have copied the InnoDB tablespace but not the InnoDB log files. Please refer to https://mariadb.com/kb/en/library/xtradbinnodb-recovery-modes/ for information about forcing recovery.
180409 20:34:12 completed OK!

on the innobackup.move.log file on node02:

180409 20:34:12 innobackupex: Starting the move-back operation

IMPORTANT: Please check that the move-back run completes successfully.
At the end of a successful move-back run innobackupex
prints "completed OK!".

--innobackupex based on MariaDB server 10.2.13-MariaDB Linux (x86_64)
180409 20:34:12 [01] Moving ibdata1 to /data/mysql/ibdata1
180409 20:34:12 [01] ...done
180409 20:34:12 [01] Moving ./mysql/gtid_slave_pos.ibd to /data/mysql/mysql/gtid_slave_pos.ibd
180409 20:34:12 [01] ...done
180409 20:34:12 [01] Moving ./mysql/innodb_table_stats.ibd to /data/mysql/mysql/innodb_table_stats.ibd
180409 20:34:12 [01] ...done
180409 20:34:12 [01] Moving ./mysql/innodb_index_stats.ibd to /data/mysql/mysql/innodb_index_stats.ibd
180409 20:34:12 [01] ...done
180409 20:34:12 [01] Moving ./mysql/columns_priv.frm to /data/mysql/mysql/columns_priv.frm
180409 20:34:12 [01] ...done
...
...
180409 20:34:12 [01] Moving ./performance_schema/db.opt to /data/mysql/performance_schema/db.opt
180409 20:34:12 [01] ...done
180409 20:34:12 [01] Moving ./aria_log_control to /data/mysql/aria_log_control
180409 20:34:12 [01] ...done
180409 20:34:12 [01] Moving ./aria_log.00000001 to /data/mysql/aria_log.00000001
180409 20:34:12 [01] ...done
180409 20:34:12 [01] Moving ./ib_buffer_pool to /data/mysql/ib_buffer_pool
180409 20:34:12 [01] ...done
180409 20:34:12 [01] Moving ./xtrabackup_info to /data/mysql/xtrabackup_info
180409 20:34:12 [01] ...done
180409 20:34:12 [01] Moving ./innobackup.prepare.log to /data/mysql/innobackup.prepare.log
180409 20:34:12 [01] ...done
180409 20:34:12 [01] Moving ./innobackup.move.log to /data/mysql/innobackup.move.log
180409 20:34:12 [01] ...done
180409 20:34:12 completed OK!

on the node01 donor error.log file:

2018-04-09 17:54:03 140501533583104 [Note] WSREP: Quorum results:
version = 4,
component = PRIMARY,
conf_id = 3,
members = 1/2 (joined/total),
act_id = 0,
last_appl. = 0,
protocols = 0/8/3 (gcs/repl/appl),
group UUID = 2cab0f6d-3bea-11e8-b564-c38fa1385a69
2018-04-09 17:54:03 140501533583104 [Note] WSREP: Flow-control interval: [362, 362]
2018-04-09 17:54:03 140501533583104 [Note] WSREP: Trying to continue unpaused monitor
2018-04-09 17:54:03 140507105875712 [Note] WSREP: New cluster view: global state: 2cab0f6d-3bea-11e8-b564-c38fa1385a69:0, view# 4: Primary, number of nodes: 2, my index: 0, protocol version 3
2018-04-09 17:54:03 140507105875712 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2018-04-09 17:54:03 140507105875712 [Note] WSREP: REPL Protocols: 8 (3, 2)
2018-04-09 17:54:03 140507105875712 [Note] WSREP: Assign initial position for certification: 0, protocol version: 3
2018-04-09 17:54:03 140507017230080 [Note] WSREP: Service thread queue flushed.
2018-04-09 17:54:04 140501533583104 [Note] WSREP: Member 1.0 (node02) requested state transfer from 'any'. Selected 0.0 (node01)(SYNCED) as donor.
2018-04-09 17:54:04 140501533583104 [Note] WSREP: Shifting SYNCED -> DONOR/DESYNCED (TO: 0)
2018-04-09 17:54:04 140507105875712 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2018-04-09 17:54:04 140410794010368 [Note] WSREP: Running: 'wsrep_sst_mariabackup --role 'donor' --address '192.168.102.208:4444/xtrabackup_sst//1' --socket '/data/mysql/mysql.sock' --datadir '/data/mysql/' '' --gtid '2cab0f6d-3bea-11e8-b564-c38fa1385a69:0' --gtid-domain-id '0''
2018-04-09 17:54:04 140507105875712 [Note] WSREP: sst_donor_thread signaled with 0
WSREP_SST: [INFO] Streaming with xbstream (20180409 17:54:04.858)
WSREP_SST: [INFO] Using socat as streamer (20180409 17:54:04.864)
WSREP_SST: [INFO] Using /tmp/tmp.ITKJXDjvll as innobackupex temporary directory (20180409 17:54:04.892)
WSREP_SST: [INFO] Streaming GTID file before SST (20180409 17:54:04.907)
WSREP_SST: [INFO] Evaluating mbstream -c ${INFO_FILE} | socat -u stdio TCP:192.168.102.208:4444; RC=( ${PIPESTATUS[@]} ) (20180409 17:54:04.914)
WSREP_SST: [INFO] Sleeping before data transfer for SST (20180409 17:54:04.931)
2018-04-09 17:54:05 140506983659264 [Note] WSREP: (2caa4f44, 'tcp://0.0.0.0:4567') turning message relay requesting off
WSREP_SST: [INFO] Streaming the backup to joiner at 192.168.102.208 4444 (20180409 17:54:14.943)
WSREP_SST: [INFO] Evaluating mariabackup --innobackupex $tmpopts $INNOEXTRA --galera-info --stream=$sfmt $itmpdir 2>${DATA}/innobackup.backup.log | socat -u stdio TCP:192.168.102.208:4444; RC=( ${PIPESTATUS[@]} ) (20180409 17:54:14.950)
2018-04-09 20:34:02 140501469112064 [Note] WSREP: Provider paused at 2cab0f6d-3bea-11e8-b564-c38fa1385a69:0 (11)
2018-04-09 20:34:03 140501469112064 [Note] WSREP: resuming provider at 11
2018-04-09 20:34:03 140501469112064 [Note] WSREP: Provider resumed.
WSREP_SST: [ERROR] mariabackup finished with error: 1. Check /data/mysql//innobackup.backup.log (20180409 20:34:03.980)
WSREP_SST: [ERROR] Cleanup after exit with status:22 (20180409 20:34:03.986)
WSREP_SST: [INFO] Cleaning up temporary directories (20180409 20:34:03.994)
2018-04-09 20:34:04 140410794010368 [ERROR] WSREP: Failed to read from: wsrep_sst_mariabackup --role 'donor' --address '192.168.102.208:4444/xtrabackup_sst//1' --socket '/data/mysql/mysql.sock' --datadir '/data/mysql/' '' --gtid '2cab0f6d-3bea-11e8-b564-c38fa1385a69:0' --gtid-domain-id '0'
2018-04-09 20:34:04 140410794010368 [ERROR] WSREP: Process completed with error: wsrep_sst_mariabackup --role 'donor' --address '192.168.102.208:4444/xtrabackup_sst//1' --socket '/data/mysql/mysql.sock' --datadir '/data/mysql/' '' --gtid '2cab0f6d-3bea-11e8-b564-c38fa1385a69:0' --gtid-domai
n-id '0': 22 (Invalid argument)
2018-04-09 20:34:04 140410794010368 [ERROR] WSREP: Command did not run: wsrep_sst_mariabackup --role 'donor' --address '192.168.102.208:4444/xtrabackup_sst//1' --socket '/data/mysql/mysql.sock' --datadir '/data/mysql/' '' --gtid '2cab0f6d-3bea-11e8-b564-c38fa1385a69:0' --gtid-domain-id '0'
2018-04-09 20:34:04 140501533583104 [Warning] WSREP: 0.0 (node01): State transfer to 1.0 (node02) failed: -22 (Invalid argument)

looking at the log of xtrabackup it seen apply log works and xtrabackup_galera_info is there

 Comments   
Comment by Massimo [ 2018-04-10 ]

The SST by mariabackup has been tried twice with same result.

Comment by Vladislav Vaintroub [ 2018-04-10 ]

you're doing quite complex operations, and are complaining at prepare, but your backup seems to have failed already, and there is a log that it makes sense to share

Comment by Vladislav Vaintroub [ 2018-04-10 ]

As it says WSREP_SST: [ERROR] mariabackup finished with error: 1. Check /data/mysql//innobackup.backup.log (20180409 20:34:03.980)

Comment by Massimo [ 2018-04-10 ]

there is no complex operation at all!

wsrep_sst_method=mariabackup
wsrep_sst_auth=**

and start the node.
Where is the complex operation you are talking about? is all done by SST.

Comment by Vladislav Vaintroub [ 2018-04-10 ]

I'm talking about complaining at prepare, when backup fails. I do not understand galera-ish. So, what does it backup said when it failed

Comment by Zdravelina Sokolovska (Inactive) [ 2018-04-10 ]

hello massimo.disaro
you have WSREP_SST: [ERROR] mariabackup finished with error: 1. Check /data/mysql//innobackup.backup.log

did you check mysql privileges ?
you need
wsrep_sst_auth=Your_user_name:Your_passwd
and
those are minimum privileges required to full backups:

mysql> CREATE USER 'Your_user_name'@'localhost' IDENTIFIED BY 'Your_passwd';
mysql> GRANT RELOAD, LOCK TABLES, REPLICATION CLIENT ON . TO 'Your_user_name'@'localhost';
mysql> FLUSH PRIVILEGES;

Comment by Zdravelina Sokolovska (Inactive) [ 2018-04-10 ]

massimo.disaro , please send also the /data/mysql/innobackup.backup.log from donor Node

Comment by Jan Lindström (Inactive) [ 2018-04-11 ]

We need full error logs from donor and joiner and configuration file from both nodes.

Comment by Massimo [ 2018-04-11 ]

the USER has "ALL PRIVILEGES" . it will not explain why it could work with xtrabackup and not with mariabackup

Comment by Ranjan Ghosh [ 2018-07-31 ]

I never ever in my life have seen sth. other than RSYNC SST working. I'd really like to get this running one day, because it's quite bad when the donor is in DSYNCED state for a few minutes not handling requests. So, from time to time I tried it again and see whether the situation. Freshly upgraded to 10.2.16 I took another attempt and I get the same error. As said, my config runs perfectly well with RSYNC SST. Now, I've just added this to the config on both nodes:

wsrep_sst_method = mariabackup
 
wsrep_sst_auth = root:secretpassword

and get this in the log on the joining node:

Jul 31 22:08:33 tukan2 mysqld[10641]: 2018-07-31 22:08:33 140181901801216 [Warning] WSREP: Gap in state sequence. Need state transfer.
 
Jul 31 22:08:33 tukan2 mysqld[10641]: 2018-07-31 22:08:33 140181659166464 [Note] WSREP: Running: 'wsrep_sst_mariabackup --role 'joiner' --address '192.168.0.2' --datadir '/var/lib/mysql/'   --parent '10641'  '' '
 
Jul 31 22:08:33 tukan2 mysqld[10641]: WSREP_SST: [INFO] Logging all stderr of SST/Innobackupex to syslog (20180731 22:08:33.544)
 
Jul 31 22:08:33 tukan2 mysqld[10641]: 2018-07-31 22:08:33 140181901801216 [Note] WSREP: Prepared SST request: mariabackup|192.168.0.2:4444/xtrabackup_sst//1
 
Jul 31 22:08:33 tukan2 mysqld[10641]: 2018-07-31 22:08:33 140181901801216 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
 
Jul 31 22:08:33 tukan2 mysqld[10641]: 2018-07-31 22:08:33 140181901801216 [Note] WSREP: REPL Protocols: 8 (3, 2)
 
Jul 31 22:08:33 tukan2 mysqld[10641]: 2018-07-31 22:08:33 140181901801216 [Note] WSREP: Assign initial position for certification: 10762826351, protocol version: 3
 
Jul 31 22:08:33 tukan2 mysqld[10641]: 2018-07-31 22:08:33 140181918893824 [Note] WSREP: Service thread queue flushed.
 
Jul 31 22:08:33 tukan2 mysqld[10641]: 2018-07-31 22:08:33 140181901801216 [Warning] WSREP: Failed to prepare for incremental state transfer: Local state UUID (00000000-0000-0000-0000-000000000000) does not match group state UUID (fa8c9590-d504-11e6-b694-5639ec4c2fea): 1 (Operation not permitted)
 
Jul 31 22:08:33 tukan2 mysqld[10641]:          at galera/src/replicator_str.cpp:prepare_for_IST():482. IST will be unavailable.
 
Jul 31 22:08:33 tukan2 mysqld[10641]: 2018-07-31 22:08:33 140181667559168 [Note] WSREP: Member 1.0 (tukan2) requested state transfer from '*any*'. Selected 0.0 (tukan1)(SYNCED) as donor.
 
Jul 31 22:08:33 tukan2 mysqld[10641]: 2018-07-31 22:08:33 140181667559168 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 10762826410)
 
Jul 31 22:08:33 tukan2 mysqld[10641]: 2018-07-31 22:08:33 140181901801216 [Note] WSREP: Requesting state transfer: success, donor: 0
 
Jul 31 22:08:33 tukan2 mysqld[10641]: 2018-07-31 22:08:33 140181901801216 [Note] WSREP: GCache history reset: 00000000-0000-0000-0000-000000000000:0 -> fa8c9590-d504-11e6-b694-5639ec4c2fea:10762826351
 
Jul 31 22:08:33 tukan2 -wsrep-sst-joiner[10988]: removed '/var/lib/mysql/ibdata1'
 
Jul 31 22:08:33 tukan2 -wsrep-sst-joiner[10988]: removed '/var/lib/mysql/ib_logfile1'
 
Jul 31 22:08:33 tukan2 -wsrep-sst-joiner[10988]: removed '/var/lib/mysql/aria_log_control'
 
Jul 31 22:08:33 tukan2 -wsrep-sst-joiner[10988]: removed '/var/lib/mysql/aria_log.00000001'
 
Jul 31 22:08:35 tukan2 mysqld[10641]: 2018-07-31 22:08:35 140181675951872 [Note] WSREP: (7fa34b20, 'tcp://0.0.0.0:4567') connection to peer 7fa34b20 with addr tcp://192.168.0.2:4567 timed out, no messages seen in PT3S
 
Jul 31 22:08:35 tukan2 mysqld[10641]: 2018-07-31 22:08:35 140181675951872 [Note] WSREP: (7fa34b20, 'tcp://0.0.0.0:4567') turning message relay requesting off
 
Jul 31 22:09:49 tukan2 mysqld[10641]: 2018-07-31 22:09:49 140181667559168 [Note] WSREP: 0.0 (tukan1): State transfer to 1.0 (tukan2) complete.
 
Jul 31 22:09:49 tukan2 mysqld[10641]: 2018-07-31 22:09:49 140181667559168 [Note] WSREP: Member 0.0 (tukan1) synced with group.
 
Jul 31 22:09:49 tukan2 -wsrep-sst-joiner[12459]: Preparing the backup at /var/lib/mysql//.sst
 
Jul 31 22:09:49 tukan2 -innobackupex-apply[12462]: mariabackup: cd to /var/lib/mysql/.sst/
 
Jul 31 22:09:49 tukan2 -innobackupex-apply[12462]: 2018-07-31 22:09:49 140067121125120 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
 
Jul 31 22:09:51 tukan2 -innobackupex-apply[12462]: 2018-07-31 22:09:51 140067583875008 [Note] InnoDB: Last binlog file '/var/log/mysql/mariadb-bin.000286', position 34761799
 
Jul 31 22:09:51 tukan2 -innobackupex-apply[12462]: Last binlog file /var/log/mysql/mariadb-bin.000286, position 34761799
 
Jul 31 22:09:51 tukan2 -wsrep-sst-joiner[10988]: rm: cannot remove '/var/lib/mysql//innobackup.prepare.log': No such file or directory
 
Jul 31 22:09:51 tukan2 -wsrep-sst-joiner[10988]: rm: cannot remove '/var/lib/mysql//innobackup.move.log': No such file or directory
 
Jul 31 22:09:51 tukan2 -wsrep-sst-joiner[12506]: Moving the backup to /var/lib/mysql/
 
Jul 31 22:09:51 tukan2 -wsrep-sst-joiner[12510]: Move successful, removing /var/lib/mysql//.sst
 
Jul 31 22:09:51 tukan2 -wsrep-sst-joiner[12520]: SST magic file /var/lib/mysql//xtrabackup_galera_info not found/readable
 
Jul 31 22:09:51 tukan2 mysqld[10641]: 2018-07-31 22:09:51 140181659166464 [ERROR] WSREP: Process completed with error: wsrep_sst_mariabackup --role 'joiner' --address '192.168.0.2' --datadir '/var/lib/mysql/'   --parent '10641'  '' : 2 (No such file or directory)
 
Jul 31 22:09:51 tukan2 mysqld[10641]: 2018-07-31 22:09:51 140181659166464 [ERROR] WSREP: Failed to read uuid:seqno and wsrep_gtid_domain_id from joiner script.
 
Jul 31 22:09:51 tukan2 mysqld[10641]: 2018-07-31 22:09:51 140182566598592 [ERROR] WSREP: SST failed: 2 (No such file or directory)
 
Jul 31 22:09:51 tukan2 mysqld[10641]: 2018-07-31 22:09:51 140182566598592 [ERROR] Aborting
 
Jul 31 22:10:05 tukan2 mysqld[10641]: Error in my_thread_global_end(): 1 threads didn't exit

and this on the donor node:

Jul 31 22:08:33 tukan1 mysqld[13991]: 2018-07-31 22:08:33 140485722781440 [Note] WSREP: Service thread queue flushed.
 
Jul 31 22:08:33 tukan1 mysqld[13991]: 2018-07-31 22:08:33 140485477779200 [Note] WSREP: Member 1.0 (tukan2) requested state transfer from '*any*'. Selected 0.0 (tukan1)(SYNCED) as donor.
 
Jul 31 22:08:33 tukan1 mysqld[13991]: 2018-07-31 22:08:33 140485477779200 [Note] WSREP: Shifting SYNCED -> DONOR/DESYNCED (TO: 10762826410)
 
Jul 31 22:08:33 tukan1 mysqld[13991]: 2018-07-31 22:08:33 140480132990720 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
 
Jul 31 22:08:33 tukan1 mysqld[13991]: 2018-07-31 22:08:33 140478230025984 [Note] WSREP: Running: 'wsrep_sst_mariabackup --role 'donor' --address '192.168.0.2:4444/xtrabackup_sst//1' --socket '/var/run/mysqld/mysqld.sock' --datadir '/var/lib/mysql/'     '' --gtid 'fa8c9590-d504-11e6-b694-5639ec4c2fea:10762826410' --gtid-domain-id '0''
 
Jul 31 22:08:33 tukan1 mysqld[13991]: 2018-07-31 22:08:33 140480132990720 [Note] WSREP: sst_donor_thread signaled with 0
 
Jul 31 22:08:33 tukan1 mysqld[13991]: WSREP_SST: [INFO] Logging all stderr of SST/Innobackupex to syslog (20180731 22:08:33.879)
 
Jul 31 22:08:35 tukan1 mysqld[13991]: 2018-07-31 22:08:35 140485486171904 [Note] WSREP: (6dae08f7, 'tcp://0.0.0.0:4567') turning message relay requesting off
 
Jul 31 22:08:43 tukan1 -innobackupex-backup[19846]: 180731 22:08:43 Connecting to MySQL server host: localhost, user: root, password: set, port: not set, socket: /var/run/mysqld/mysqld.sock
 
Jul 31 22:08:43 tukan1 -innobackupex-backup[19846]: mariabackup: cd to /var/lib/mysql/
 
Jul 31 22:08:53 tukan1 -innobackupex-backup[19846]: 180731 22:08:53 [01] Streaming ./mysql/gtid_slave_pos.ibd
 
Jul 31 22:08:53 tukan1 -innobackupex-backup[19846]: 180731 22:08:53 [01] Streaming ./mysql/innodb_index_stats.ibd
 
Jul 31 22:08:53 tukan1 -innobackupex-backup[19846]: 180731 22:08:53 [01] Streaming ./mysql/innodb_table_stats.ibd
 
Jul 31 22:09:48 tukan1 mysqld[13991]: 2018-07-31 22:09:48 140480130225920 [Note] WSREP: Provider paused at fa8c9590-d504-11e6-b694-5639ec4c2fea:10762830040 (4999)
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:48 [01] Streaming ./mysql/column_stats.MYD to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:48 [01] Streaming ./mysql/column_stats.MYI to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:48 [01] Streaming ./mysql/column_stats.frm to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:48 [01] Streaming ./mysql/columns_priv.MYD to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:48 [01] Streaming ./mysql/host.frm to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:48 [01] Streaming ./mysql/func.MYI to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:48 [01] Streaming ./mysql/db.frm to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:48 [01] Streaming ./mysql/db.MYD to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:48 [01] Streaming ./mysql/plugin.frm to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:48 [01] Streaming ./mysql/event.MYI to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:48 [01] Streaming ./mysql/general_log.CSM to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:48 [01] Streaming ./mysql/general_log.CSV to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/general_log.frm to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/gtid_slave_pos.frm to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/help_category.MYD to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/help_category.MYI to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/help_category.frm to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/help_keyword.MYD to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/help_keyword.MYI to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/help_keyword.frm to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/help_relation.MYD to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/help_relation.MYI to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/help_relation.frm to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/help_topic.MYD to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/help_topic.MYI to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/help_topic.frm to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/func.MYD to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/db.MYI to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/index_stats.MYD to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/index_stats.MYI to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/index_stats.frm to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/innodb_index_stats.frm to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/innodb_table_stats.frm to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/plugin.MYI to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/proc.MYD to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/proc.MYI to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/host.MYD to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/procs_priv.frm to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/proxies_priv.MYD to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/proxies_priv.MYI to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/proxies_priv.frm to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/roles_mapping.MYD to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/roles_mapping.MYI to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/roles_mapping.frm to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/servers.MYD to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/servers.MYI to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/servers.frm to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/slow_log.CSM to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/slow_log.CSV to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/slow_log.frm to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/table_stats.MYD to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/table_stats.MYI to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/table_stats.frm to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/func.frm to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/procs_priv.MYI to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/time_zone.MYD to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/time_zone.MYI to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/time_zone.frm to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/time_zone_leap_second.MYD to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/time_zone_leap_second.MYI to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/time_zone_leap_second.frm to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/time_zone_name.MYD to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/time_zone_name.MYI to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/time_zone_name.frm to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/time_zone_transition.MYD to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/time_zone_transition.MYI to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/time_zone_transition.frm to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/time_zone_transition_type.MYD to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/time_zone_transition_type.MYI to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/time_zone_transition_type.frm to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/tables_priv.MYD to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/host.MYI to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/event.frm to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/columns_priv.MYI to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/proc.frm to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/user.MYI to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/plugin.MYD to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/procs_priv.MYD to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/tables_priv.frm to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/columns_priv.frm to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/user.frm to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/event.MYD to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/tables_priv.MYI to <STDOUT>
 
Jul 31 22:09:49 tukan1 -innobackupex-backup[19846]: 180731 22:09:49 [01] Streaming ./mysql/user.MYD to <STDOUT>
 
Jul 31 22:10:37 tukan1 mysqld[13991]: 2018-07-31 22:10:37 140480128997120 [Note] Detected table cache mutex contention at instance 1: 26% waits. Additional table cache instance activated. Number of instances after activation: 2.

Comment by Ranjan Ghosh [ 2018-07-31 ]

BTW: The joiner node only has this in /var/lib/mysql afterwards:

root@tukan2 /var/lib/mysql # ls -la
 
total 131084
 
drwxr-xr-x  2 mysql mysql        82 Jul 31 22:09 .
 
drwxr-xr-x 38 root  root       4096 Jul 31 22:01 ..
 
-rw-rw----  1 mysql mysql 134219048 Jul 31 22:09 galera.cache
 
-rw-rw----  1 mysql mysql       113 Jul 31 22:08 grastate.dat
 
-rw-rw----  1 mysql mysql         0 Jul 31 22:08 sst_in_progress

The donor node has "xtrabackup_galera_info" but no innobackup.backup.log or anything like that.
I'm using Ubuntu Bionic with MariaDB PPA packages.

Comment by Ulrich Moser (Inactive) [ 2018-09-06 ]

A trainee in my current Cluster LVC gets the same error. He uses the virtual machines downloaded from our training website.

I also am working on these VM images converted to KVM format and I have another test cluster running on Ubuntu 16.04 and on both mariabackup as SST works and also for the other attendees.

He encountered differences in the package setup (see below).
[root@mariadb1 mysql]# cat /etc/redhat-release
CentOS Linux release 7.5.1804 (Core)

[root@mariadb2 mysql]# cat /etc/redhat-release
CentOS Linux release 7.5.1804 (Core)

[root@galera3 mysql]# cat /etc/redhat-release
CentOS Linux release 7.4.1708 (Core)

[root@galera4 mysql]# cat /etc/redhat-release
CentOS Linux release 7.4.1708 (Core)

So - there are differences in the operating systems - I thought the detail said use the machines called "CentOS7_20x"

[root@mariadb1 mysql]# rpm -qa | grep -i mariadb
MariaDB-server-10.3.9-1.el7.centos.x86_64
mariadb-enterprise-repository-0.1-1.noarch
MariaDB-common-10.1.23-1.el7.centos.x86_64
MariaDB-backup-10.3.9-1.el7.centos.x86_64
MariaDB-shared-10.1.23-1.el7.centos.x86_64
MariaDB-client-10.3.9-1.el7.centos.x86_64

[root@mariadb2 mysql]# rpm -qa | grep -i mariadb
MariaDB-backup-10.3.9-1.el7.centos.x86_64
MariaDB-client-10.3.9-1.el7.centos.x86_64
MariaDB-common-10.3.9-1.el7.centos.x86_64
MariaDB-compat-10.3.9-1.el7.centos.x86_64
MariaDB-server-10.3.9-1.el7.centos.x86_64

[root@galera3 mysql]# rpm -qa | grep -i mariadb
MariaDB-compat-10.3.9-1.el7.centos.x86_64
MariaDB-server-10.3.9-1.el7.centos.x86_64
MariaDB-backup-10.3.9-1.el7.centos.x86_64
MariaDB-common-10.3.9-1.el7.centos.x86_64
MariaDB-client-10.3.9-1.el7.centos.x86_64

[root@galera4 mysql]# rpm -qa | grep -i mariadb
MariaDB-backup-10.3.9-1.el7.centos.x86_64
MariaDB-common-10.3.9-1.el7.centos.x86_64
MariaDB-client-10.3.9-1.el7.centos.x86_64
MariaDB-compat-10.3.9-1.el7.centos.x86_64
MariaDB-server-10.3.9-1.el7.centos.x86_64

Comment by Ulrich Moser (Inactive) [ 2018-09-06 ]

This is related to MDEV-12956

If there is no section [mysqld] with entry datadir = ... mariabackup fails.

Comment by Ranjan Ghosh [ 2018-09-06 ]

Thank you! Will need to check if it helps. BTW: Did I mention that the documentation is just terrible?

https://mariadb.com/kb/en/library/getting-started-with-mariadb-galera-cluster/#mariabackup

1 short paragraph of prose. "Not helpful" would be an understatement. At least there could be a small config example and it could be mentioned that you need to create a user for all of this to work. Additionally, I was missing some info on whether you can reuse the root user for this (in contrast to creating a dedicated account) and on whether this is advisable and if not, why not.

The information, that a "datadir" section must exist would also be very helpful. Honestly, I'm really amazed (and I don't mean it ironic) that people have really managed to get this working without any decent info whatsoever. Kudos to them.

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