innobackupex does not seem to read datadir correctly

Hi,

I have a cluster setup with just 2 nodes, and I am using xtrabackup-v2 as the wsrep_sst_method. Version info is:

  • mysql Ver 15.1 Distrib 10.1.10-MariaDB, for Linux (x86_64) using readline 5.1
  • xtrabackup version 2.3.3 based on MySQL server 5.6.24 Linux (x86_64) (revision id: 525ca7d)

On node 1, I can bootstrap mysql successfully. On node 2, I am running into problem with the move-back step. From the mariadb.log, I can see that the innobackupex --move-back step is failing. Under the innobackup.move.log, I am seeing a strange error: - innobackupex version 2.3.3 based on MySQL server 5.6.24 Linux (x86_64) (revision id: 525ca7d)

  • Error: Move file ib_logfile0 to ./ib_logfile0 failed: Destination file exists
    I looked into the source code of xtrabackup, and it looks to me like the script didn’t read the datadir conf var correctly. It’s supposed to move the ib_logfile0 to /var/lib/mysql/ib_logfile0 but instead it seem to read datadir as “./”.

The server.conf is located under my /etc/my.cnf.d directory. Here is the output of mysqld --print-defaults
mysqld would have been started with the following arguments:
–log-error=/var/log/mariadb.log --socket=/var/lib/mysql/mysql.sock --datadir=/var/lib/mysql --binlog_format=ROW --default_storage_engine=innodb --innodb_autoinc_lock_mode=2 --wsrep_on=ON --innodb_doublewrite=1 --wsrep_provider=/usr/lib64/galera/libgalera_smm.so --wsrep_provider_options=gmcast.listen_addr=tcp://0.0.0.0:4567; ist.recv_addr=172.20.222.62:4568 --wsrep_cluster_address=gcomm://172.20.222.61,172.20.222.62 --wsrep_sst_receive_address=172.20.222.62:4444 --wsrep_node_address=172.20.222.62:4567 --wsrep_cluster_name=satelliteDatabaseCluster --wsrep_node_name=dlo-lab62 --wsrep_sst_method=xtrabackup-v2 --wsrep_sst_auth=root:Test123 --wsrep_debug=ON --bind-address=0.0.0.0 --query_cache_size=0

=========== mariadb.log
WSREP_SST: [INFO] Streaming with xbstream (20160104 10:57:13.854)
WSREP_SST: [INFO] Using socat as streamer (20160104 10:57:13.855)
WSREP_SST: [INFO] Evaluating timeout -s9 100 socat -u TCP-LISTEN:4444,reuseaddr stdio | xbstream -x; RC=( ${PIPESTATUS[@]} ) (20160104 10:57:13.879)
2016-01-04 10:57:14 140293202687744 [Note] WSREP: Prepared SST request: xtrabackup-v2|172.20.222.62:4444/xtrabackup_sst//1
2016-01-04 10:57:14 140293202687744 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2016-01-04 10:57:14 140293202687744 [Note] WSREP: REPL Protocols: 7 (3, 2)
2016-01-04 10:57:14 140292979345152 [Note] WSREP: Service thread queue flushed.
2016-01-04 10:57:14 140293202687744 [Note] WSREP: Assign initial position for certification: 352, protocol version: 3
2016-01-04 10:57:14 140292979345152 [Note] WSREP: Service thread queue flushed.
2016-01-04 10:57:14 140293202687744 [Warning] WSREP: Failed to prepare for incremental state transfer: Local state UUID (00000000-0000-0000-0000-000000000000) does not match group state UUID (805ae278-b2ac-11e5-8a4f-8b035dfc5817): 1 (Operation not permitted)
at galera/src/replicator_str.cpp:prepare_for_IST():456. IST will be unavailable.
2016-01-04 10:57:14 140292910999296 [Note] WSREP: Member 1.0 (dlo-lab62) requested state transfer from ‘any’. Selected 0.0 (dlo-lab61)(SYNCED) as donor.
2016-01-04 10:57:14 140292910999296 [Note] WSREP: Shifting PRIMARY → JOINER (TO: 352)
2016-01-04 10:57:14 140293202687744 [Note] WSREP: Requesting state transfer: success, donor: 0
WSREP_SST: [INFO] Proceeding with SST (20160104 10:57:14.263)
WSREP_SST: [INFO] Evaluating socat -u TCP-LISTEN:4444,reuseaddr stdio | xbstream -x; RC=( ${PIPESTATUS[@]} ) (20160104 10:57:14.264)
WSREP_SST: [INFO] Cleaning the existing datadir and innodb-data/log directories (20160104 10:57:14.266)
removed /var/lib/mysql/mysql.sock' removed /var/lib/mysql/ib_logfile1’
removed /var/lib/mysql/aria_log.00000001' removed /var/lib/mysql/aria_log_control’
removed /var/lib/mysql/ibdata1' removed /var/lib/mysql/ib_logfile0’
WSREP_SST: [INFO] Waiting for SST streaming to complete! (20160104 10:57:14.298)
2016-01-04 10:57:16 140292921489152 [Note] WSREP: (f6dbe707, ‘tcp://0.0.0.0:4567’) turning message relay requesting off
2016-01-04 10:57:28 140292910999296 [Note] WSREP: 0.0 (dlo-lab61): State transfer to 1.0 (dlo-lab62) complete.
2016-01-04 10:57:28 140292910999296 [Note] WSREP: Member 0.0 (dlo-lab61) synced with group.
WSREP_SST: [INFO] Preparing the backup at /var/lib/mysql//.sst (20160104 10:57:30.218)
WSREP_SST: [INFO] Evaluating innobackupex --no-version-check --apply-log $rebuildcmd ${DATA} &>${DATA}/innobackup.prepare.log (20160104 10:57:30.224)
rm: cannot remove /var/lib/mysql//innobackup.prepare.log': No such file or directory rm: cannot remove /var/lib/mysql//innobackup.move.log’: No such file or directory
WSREP_SST: [INFO] Moving the backup to /var/lib/mysql/ (20160104 10:57:33.948)
WSREP_SST: [INFO] DATA is /var/lib/mysql//.sst (20160104 10:57:33.950)
WSREP_SST: [INFO] Evaluating innobackupex --defaults-file=/etc/my.cnf --no-version-check --move-back --force-non-empty-directories ${DATA} &> ${DATA}/innobackup.move.log (20160104 10:57:33.951)
WSREP_SST: [ERROR] Cleanup after exit with status:1 (20160104 10:57:33.958)
2016-01-04 10:57:33 140292879546112 [ERROR] WSREP: Process completed with error: wsrep_sst_xtrabackup-v2 --role ‘joiner’ --address ‘172.20.222.62:4444’ --datadir ‘/var/lib/mysql/’ --defaults-file ‘/etc/my.cnf’ --parent ‘3840’ ‘’ : 1 (Operation not permitted)
2016-01-04 10:57:33 140292879546112 [ERROR] WSREP: Failed to read uuid:seqno and wsrep_gtid_domain_id from joiner script.
2016-01-04 10:57:33 140293202995232 [ERROR] WSREP: SST failed: 1 (Operation not permitted)
2016-01-04 10:57:33 140293202995232 [ERROR] Aborting

Error in my_thread_global_end(): 1 threads didn’t exit

=========== innobackup.move.log
160104 10:57:33 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 version 2.3.3 based on MySQL server 5.6.24 Linux (x86_64) (revision id: 525ca7d)
Error: Move file ib_logfile0 to ./ib_logfile0 failed: Destination file exists
18:57:33 UTC - xtrabackup got signal 11 ;
This could be because you hit a bug or data is corrupted.
This error can also be caused by malfunctioning hardware.
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.

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 = 0 thread_stack 0x10000
innobackupex(my_print_stacktrace+0x2e) [0x93827e]
innobackupex(handle_fatal_signal+0x273) [0x81b483]
/lib64/libpthread.so.0(+0xf790) [0x7fded4a86790]
/lib64/libc.so.6(cfree+0x1c) [0x7fded30eb93c]
innobackupex(copy_back()+0x377) [0x5a1767]
innobackupex(main+0xacb) [0x591f9b]
/lib64/libc.so.6(__libc_start_main+0xfd) [0x7fded308ed5d]
innobackupex() [0x585ea9]

=============== server.conf

Ansible managed: /Users/hvo/Workspaces/Eclipse_Helios/csw-cssm-engine/ha/deployment/ansible/roles/mariadb-prep/templates/mariadb_server.cnf modified on 2016-01-03 21:37:29 by hvo on HVO-M-M09J

These groups are read by MariaDB server.

Use it for options that only the server (but not clients) should see

this is read by the standalone daemon and embedded servers

[server]
log-error=/var/log/mariadb.log

this is only for the mysqld standalone daemon

[mysqld]
socket=/var/lib/mysql/mysql.sock
datadir=/var/lib/mysql

* Galera-related settings

[galera]
binlog_format=ROW
default_storage_engine=innodb
innodb_autoinc_lock_mode=2
wsrep_on=ON
innodb_doublewrite=1
wsrep_provider=/usr/lib64/galera/libgalera_smm.so

wsrep_provider_options=gmcast.listen_addr=tcp://0.0.0.0:4567; ist.recv_addr=172.20.222.62:4568

for IPv6 i need to insert a bracket around the address in the gcomm setting. look for it.

wsrep_cluster_address=“gcomm://172.20.222.61,172.20.222.62”

wsrep_sst_receive_address=172.20.222.62:4444
wsrep_node_address=172.20.222.62:4567

wsrep_cluster_name=satelliteDatabaseCluster
wsrep_node_name=dlo-lab62
wsrep_sst_method=xtrabackup-v2
wsrep_sst_auth=root:Test123
wsrep_debug=ON

bind-address=0.0.0.0

this is only for embedded server

[embedded]

This group is only read by MariaDB-5.5 servers.

If you use the same .cnf file for MariaDB of different versions,

use this group for options that older servers don’t understand

[mysqld-10.1]

These two groups are only read by MariaDB servers, not by MySQL.

If you use the same .cnf file for MySQL and MariaDB,

you can put MariaDB-only options here

[mariadb]
query_cache_size=0

[mariadb-10.1]

Thank you for your help,

Huey

Ahh found the problem: permission of the config file server.cnf was wrong (600). Changed it to 644 and the Percora scripts can now read the config values fine. I wish the tool would spit out some errors somewhere saying it can’t read this file that file. That would be helpful I think.