Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Cannot Reproduce
-
10.1.10, 10.0.23-galera
Description
The wsrep_sst_xtrabackup-v2 script supports 3 different types of encryption. An encryption type is chosen via the encrypt option:
- XtraBackup-based encryption (set encrypt=1 in [sst]).
- OpenSSL encryption via socat (set encrypt=2 in [sst]).
- Galera-compatible OpenSSL encryption via socat (set encrypt=3 in [sst]).
The first encryption option above uses XtraBackup's built-in encryption. This option currently fail on CentOS/RHEL 6 with the following error:
xbcrypt:xb_crypt_read_chunk: wrong chunk magic at offset 0x0.
|
This may be related to MDEV-9403.
Reproducing
The configuration file that is used on both joiner and donor is:
[mariadb-10.0]
|
binlog_format=ROW
|
default_storage_engine=InnoDB
|
innodb_autoinc_lock_mode=2
|
wsrep_provider=/usr/lib64/galera/libgalera_smm.so
|
wsrep_cluster_address="gcomm://172.31.33.135,172.31.32.117,172.31.32.116"
|
wsrep_sst_auth="sst:password"
|
wsrep_sst_method=xtrabackup-v2
|
To generate the encryption key, let's follow the directions shown here. For example:
$ openssl rand -base64 24
|
d8PtcnuenpRb1IGgPISDgmRrhLxwTKsE
|
Then we can fill in the [sst] section of the configuration file for the donor and joiner:
encrypt=1
|
encrypt-key="d8PtcnuenpRb1IGgPISDgmRrhLxwTKsE"
|
encrypt-algo="AES256"
|
When the joiner attempts to SST, it fails. The joiner's log:
160119 18:41:30 [Note] WSREP: Running: 'wsrep_sst_xtrabackup-v2 --role 'joiner' --address '172.31.32.116' --datadir '/var/lib/mysql/' --defaults-file '/etc/my.cnf' --defaults-group-suffix '' --parent '2422' '' '
|
WSREP_SST: [INFO] Streaming with xbstream (20160119 18:41:30.472)
|
WSREP_SST: [INFO] Using socat as streamer (20160119 18:41:30.473)
|
WSREP_SST: [INFO] Stale sst_in_progress file: /var/lib/mysql//sst_in_progress (20160119 18:41:30.476)
|
WSREP_SST: [INFO] Xtrabackup based encryption enabled in my.cnf - Supported only from Xtrabackup 2.1.4 (20160119 18:41:30.490)
|
WSREP_SST: [INFO] Evaluating timeout -s9 100 socat -u TCP-LISTEN:4444,reuseaddr stdio | xbcrypt --encrypt-algo=AES256 --encrypt-key=d8PtcnuenpRb1IGgPISDgmRrhLxwTKsE -d | xbstream -x; RC=( ${PIPESTATUS[@]} ) (20160119 18:41:30.496)
|
160119 18:41:30 [Note] WSREP: Prepared SST request: xtrabackup-v2|172.31.32.116:4444/xtrabackup_sst//1
|
160119 18:41:30 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
|
160119 18:41:30 [Note] WSREP: REPL Protocols: 7 (3, 2)
|
160119 18:41:30 [Note] WSREP: Service thread queue flushed.
|
160119 18:41:30 [Note] WSREP: Assign initial position for certification: 5, protocol version: 3
|
160119 18:41:30 [Note] WSREP: Service thread queue flushed.
|
160119 18:41:30 [Warning] WSREP: Failed to prepare for incremental state transfer: Local state UUID (00000000-0000-0000-0000-000000000000) does not match group state UUID (fbeb045d-b94f-11e5-8504-4ae80b892690): 1 (Operation not permitted)
|
at galera/src/replicator_str.cpp:prepare_for_IST():456. IST will be unavailable.
|
160119 18:41:30 [Note] WSREP: Member 1.0 (ip-172-31-32-116.us-west-2.compute.internal) requested state transfer from '*any*'. Selected 0.0 (ip-172-31-32-117.us-west-2.compute.internal)(SYNCED) as donor.
|
160119 18:41:30 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 5)
|
160119 18:41:30 [Note] WSREP: Requesting state transfer: success, donor: 0
|
WSREP_SST: [INFO] WARNING: Stale temporary SST directory: /var/lib/mysql//.sst from previous state transfer (20160119 18:41:30.835)
|
WSREP_SST: [INFO] Proceeding with SST (20160119 18:41:30.837)
|
WSREP_SST: [INFO] Evaluating socat -u TCP-LISTEN:4444,reuseaddr stdio | xbcrypt --encrypt-algo=AES256 --encrypt-key=d8PtcnuenpRb1IGgPISDgmRrhLxwTKsE -d | xbstream -x; RC=( ${PIPESTATUS[@]} ) (20160119 18:41:30.839)
|
WSREP_SST: [INFO] Cleaning the existing datadir and innodb-data/log directories (20160119 18:41:30.840)
|
removed `/var/lib/mysql/aria_log_control'
|
removed `/var/lib/mysql/aria_log.00000001'
|
removed `/var/lib/mysql/mysql.sock'
|
removed `/var/lib/mysql/ib_logfile0'
|
removed `/var/lib/mysql/ibdata1'
|
removed `/var/lib/mysql/ib_logfile1'
|
WSREP_SST: [INFO] Waiting for SST streaming to complete! (20160119 18:41:30.860)
|
160119 18:41:32 [Note] WSREP: (299ea548, 'tcp://0.0.0.0:4567') turning message relay requesting off
|
xbcrypt:xb_crypt_read_chunk: wrong chunk magic at offset 0x0.
|
2016/01/19 18:41:41 socat[2688] E write(1, 0xfc7410, 8192): Broken pipe
|
WSREP_SST: [ERROR] Error while getting data from donor node: exit codes: 1 0 0 (20160119 18:41:41.433)
|
WSREP_SST: [ERROR] Cleanup after exit with status:32 (20160119 18:41:41.434)
|
160119 18:41:41 [ERROR] WSREP: Process completed with error: wsrep_sst_xtrabackup-v2 --role 'joiner' --address '172.31.32.116' --datadir '/var/lib/mysql/' --defaults-file '/etc/my.cnf' --defaults-group-suffix '' --parent '2422' '' : 32 (Broken pipe)
|
160119 18:41:41 [ERROR] WSREP: Failed to read uuid:seqno from joiner script.
|
160119 18:41:41 [ERROR] WSREP: SST failed: 32 (Broken pipe)
|
160119 18:41:41 [ERROR] Aborting
|
The donor's log:
160119 18:28:50 [Note] WSREP: Running: 'wsrep_sst_xtrabackup-v2 --role 'donor' --address '172.31.32.116:4444/xtrabackup_sst//1' --socket '/var/lib/mysql/mysql.sock' --datadir '/var/lib/mysql/' --defaults-file '/etc/my.cnf' --defaults-group-suffix '' '' --gtid 'fbeb045d-b94f-11e5-8504-4ae80b892690:5''
|
160119 18:28:50 [Note] WSREP: sst_donor_thread signaled with 0
|
WSREP_SST: [INFO] Streaming with xbstream (20160119 18:28:50.776)
|
WSREP_SST: [INFO] Using socat as streamer (20160119 18:28:50.778)
|
WSREP_SST: [INFO] Using /tmp/tmp.G7JKmrB9YZ as xtrabackup temporary directory (20160119 18:28:50.787)
|
WSREP_SST: [INFO] Using /tmp/tmp.T2xAk6fxFZ as innobackupex temporary directory (20160119 18:28:50.789)
|
WSREP_SST: [INFO] Xtrabackup based encryption enabled in my.cnf - Supported only from Xtrabackup 2.1.4 (20160119 18:28:50.791)
|
WSREP_SST: [INFO] Streaming GTID file before SST (20160119 18:28:50.792)
|
WSREP_SST: [INFO] Evaluating xbstream -c ${INFO_FILE} | xbcrypt --encrypt-algo=AES256 --encrypt-key=92FABFA2213999936FD6B0EA04291157 | socat -u stdio TCP:172.31.32.116:4444 ; RC=( ${PIPESTATUS[@]} ) (20160119 18:28:50.794)
|
WSREP_SST: [INFO] Sleeping before data transfer for SST (20160119 18:28:50.805)
|
160119 18:28:52 [Note] WSREP: (5ef55a82, 'tcp://0.0.0.0:4567') turning message relay requesting off
|
WSREP_SST: [INFO] Streaming the backup to joiner at 172.31.32.116 4444 (20160119 18:29:00.807)
|
WSREP_SST: [INFO] Evaluating innobackupex --defaults-file=/etc/my.cnf --defaults-group=mysqld --no-version-check $tmpopts $INNOEXTRA --galera-info --stream=$sfmt $itmpdir 2>${DATA}/innobackup.backup.log | socat -u stdio TCP:172.31.32.116:4444; RC=( ${PIPESTATUS[@]} ) (20160119 18:29:00.809)
|
2016/01/19 18:29:01 socat[2317] E write(3, 0x1c61200, 8192): Broken pipe
|
WSREP_SST: [ERROR] innobackupex finished with error: 1. Check /var/lib/mysql//innobackup.backup.log (20160119 18:29:01.461)
|
WSREP_SST: [ERROR] Cleanup after exit with status:22 (20160119 18:29:01.462)
|
WSREP_SST: [INFO] Cleaning up temporary directories (20160119 18:29:01.464)
|
160119 18:29:01 [ERROR] WSREP: Failed to read from: wsrep_sst_xtrabackup-v2 --role 'donor' --address '172.31.32.116:4444/xtrabackup_sst//1' --socket '/var/lib/mysql/mysql.sock' --datadir '/var/lib/mysql/' --defaults-file '/etc/my.cnf' --defaults-group-suffix '' '' --gtid 'fbeb045d-b94f-11e5-8504-4ae80b892690:5'
|
160119 18:29:01 [ERROR] WSREP: Process completed with error: wsrep_sst_xtrabackup-v2 --role 'donor' --address '172.31.32.116:4444/xtrabackup_sst//1' --socket '/var/lib/mysql/mysql.sock' --datadir '/var/lib/mysql/' --defaults-file '/etc/my.cnf' --defaults-group-suffix '' '' --gtid 'fbeb045d-b94f-11e5-8504-4ae80b892690:5': 22 (Invalid argument)
|
160119 18:29:01 [ERROR] WSREP: Command did not run: wsrep_sst_xtrabackup-v2 --role 'donor' --address '172.31.32.116:4444/xtrabackup_sst//1' --socket '/var/lib/mysql/mysql.sock' --datadir '/var/lib/mysql/' --defaults-file '/etc/my.cnf' --defaults-group-suffix '' '' --gtid 'fbeb045d-b94f-11e5-8504-4ae80b892690:5'
|
160119 18:29:01 [Warning] WSREP: 0.0 (ip-172-31-32-117.us-west-2.compute.internal): State transfer to 1.0 (ip-172-31-32-116.us-west-2.compute.internal) failed: -22 (Invalid argument)
|
And /var/lib/mysql/innobackup.backup.log on the donor contains:
160119 18:41:40 innobackupex: Starting the backup operation
|
|
IMPORTANT: Please check that the backup run completes successfully.
|
At the end of a successful backup run innobackupex
|
prints "completed OK!".
|
|
160119 18:41:40 Connecting to MySQL server host: localhost, user: sst, password: not set, port: 0, socket: /var/lib/mysql/mysql.sock
|
Using server version 10.0.23-MariaDB-wsrep
|
innobackupex version 2.3.3 based on MySQL server 5.6.24 Linux (x86_64) (revision id: 525ca7d)
|
xtrabackup: uses posix_fadvise().
|
xtrabackup: cd to /var/lib/mysql/
|
xtrabackup: open files limit requested 0, set to 1024
|
xtrabackup: using the following InnoDB configuration:
|
xtrabackup: innodb_data_home_dir = ./
|
xtrabackup: innodb_data_file_path = ibdata1:12M:autoextend
|
xtrabackup: innodb_log_group_home_dir = ./
|
xtrabackup: innodb_log_files_in_group = 2
|
xtrabackup: innodb_log_file_size = 50331648
|
160119 18:41:40 >> log scanned up to (1619735)
|
xtrabackup: Generating a list of tablespaces
|
160119 18:41:40 [01] Encrypting and streaming ./ibdata1
|
^Ginnobackupex: Error writing file 'UNOPENED' (Errcode: 32 - Broken pipe)
|
xb_stream_write_data() failed.
|
encrypt: write to the destination file failed.
|
^Ginnobackupex: Error writing file 'UNOPENED' (Errcode: 32 - Broken pipe)
|
[01] xtrabackup: Error: xtrabackup_copy_datafile() failed.
|
[01] xtrabackup: Error: failed to copy datafile.
|
Attachments
Issue Links
- relates to
-
MDEV-18050 Port encrypt=4 from xtrabackup-v2 to mariabackup for SSTs
- Closed
-
MDEV-14010 merge issue in wsrep_sst_xtrabackup-v2
- Closed