Wsrep_sst_method=xtrabackup (-v2) not working until use rsync first

MySQL & MariaDB Percona XtraBackup
,
1

I’m trying to setup a galera cluster, with MariaDB 10.2, and percona-xtrabackup-2.3.10-1.el7.x86_64.

If use wsrep_sst_method=xtrabackup or xtrabackup-v2, the second node was unable to join in the cluster, and the error message complains about “no valid checkpoint”.

However, if first bring up the cluster using wsrep_sst_method=rsync, then change it to xtrabackup, stop all nodes and bootstrap the donor again (by galera_new_cluster), the joiner is able to join in OK.

I suspect there was some data synchronized to the second node when using rsync.

  • Could you please give me some pointers about why xtrabackup doesn’t work the first time?
  • Is it a common practice to bootstrap first time with rsync?
  • Or, anything else.

Any hints will be highly appreciated, and just let me know if you need more information.

Thank you for your help.

More details:

At the first time, bootstrap the donor using xtrabackup, and the joiner is unable to join in, and the joiner’s log says:

Jan 23 04:09:14 setsv-dr.local.example.com mysqld[6924]: WSREP_SST: [ERROR] xtrabackup_checkpoints missing, failed innobackupex/SST on donor (20210123 04:09:14.948)
Jan 23 04:09:14 setsv-dr.local.example.com mysqld[6924]: WSREP_SST: [ERROR] Cleanup after exit with status:2 (20210123 04:09:14.971)

, and the donor logs say:

Jan 23 04:11:31 setsv mysqld: group UUID = a53cd166-5d68-11eb-aa0f-83c1fd168f1f
Jan 23 04:11:31 setsv mysqld: 2021-01-23  4:11:31 140325406353152 [Note] WSREP: Flow-control interval: [16, 16]
Jan 23 04:11:31 setsv mysqld: 2021-01-23  4:11:31 140325646681856 [Note] WSREP: REPL Protocols: 9 (4, 2)
Jan 23 04:11:31 setsv mysqld: 2021-01-23  4:11:31 140325646681856 [Note] WSREP: New cluster view: global state: a53cd166-5d68-11eb-aa0f-83c1fd168f1f:0, view# 35: Primary, number of nodes: 1, my index: 0, protocol version 3
Jan 23 04:11:31 setsv mysqld: 2021-01-23  4:11:31 140325646681856 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
Jan 23 04:11:31 setsv mysqld: 2021-01-23  4:11:31 140325646681856 [Note] WSREP: Assign initial position for certification: 0, protocol version: 4
Jan 23 04:11:31 setsv mysqld: 2021-01-23  4:11:31 140325655074560 [Note] WSREP: Service thread queue flushed.
Jan 23 04:11:32 setsv mysqld: WSREP_SST: [INFO] Streaming the backup to joiner at 192.168.56.71 4444 (20210123 04:11:32.454)
Jan 23 04:11:32 setsv mysqld: WSREP_SST: [INFO] Evaluating innobackupex  --no-version-check  $tmpopts $INNOEXTRA --galera-info --stream=$sfmt $itmpdir 2>${DATA}/innobackup.backup.log | socat -u stdio TCP:192.168.56.71:4444; RC=( ${PIPESTATUS[@]} ) (20210123 04:11:32.457)
Jan 23 04:11:32 setsv mysqld: 2021/01/23 04:11:32 socat[15384] E connect(6, AF=2 192.168.56.71:4444, 16): Connection refused
Jan 23 04:11:32 setsv mysqld: 2021-01-23  4:11:32 140325134952192 [Warning] Aborted connection 26 to db: 'unconnected' user: 'sst_user' host: 'localhost' (Got an error reading communication packets)
Jan 23 04:11:32 setsv mysqld: WSREP_SST: [ERROR] innobackupex finished with error: 1.  Check /var/lib/mysql//innobackup.backup.log (20210123 04:11:32.467)
Jan 23 04:11:32 setsv mysqld: WSREP_SST: [ERROR] Cleanup after exit with status:22 (20210123 04:11:32.469)
Jan 23 04:11:32 setsv mysqld: WSREP_SST: [INFO] Cleaning up temporary directories (20210123 04:11:32.471)
Jan 23 04:11:32 setsv mysqld: 2021-01-23  4:11:32 140324111660800 [ERROR] WSREP: Failed to read from: wsrep_sst_xtrabackup-v2 --role 'donor' --address '192.168.56.71:4444/xtrabackup_sst//1' --socket '/var/lib/mysql/mysql.sock' --datadir '/var/lib/mysql/' --gtid 'a53cd166-5d68-11eb-aa0f-83c1fd168f1f:0' --gtid-domain-id '0' --mysqld-args --basedir=/usr --wsrep-new-cluster --wsrep_start_position=00000000-0000-0000-0000-000000000000:-1
Jan 23 04:11:32 setsv mysqld: 2021-01-23  4:11:32 140324111660800 [ERROR] WSREP: Process completed with error: wsrep_sst_xtrabackup-v2 --role 'donor' --address '192.168.56.71:4444/xtrabackup_sst//1' --socket '/var/lib/mysql/mysql.sock' --datadir '/var/lib/mysql/' --gtid 'a53cd166-5d68-11eb-aa0f-83c1fd168f1f:0' --gtid-domain-id '0' --mysqld-args --basedir=/usr --wsrep-new-cluster --wsrep_start_position=00000000-0000-0000-0000-000000000000:-1: 22 (Invalid argument)
Jan 23 04:11:32 setsv mysqld: 2021-01-23  4:11:32 140324111660800 [ERROR] WSREP: Command did not run: wsrep_sst_xtrabackup-v2 --role 'donor' --address '192.168.56.71:4444/xtrabackup_sst//1' --socket '/var/lib/mysql/mysql.sock' --datadir '/var/lib/mysql/' --gtid 'a53cd166-5d68-11eb-aa0f-83c1fd168f1f:0' --gtid-domain-id '0' --mysqld-args --basedir=/usr --wsrep-new-cluster --wsrep_start_position=00000000-0000-0000-0000-000000000000:-1
Jan 23 04:11:32 setsv mysqld: 2021-01-23  4:11:32 140325406353152 [Warning] WSREP: Could not find peer: b8dba97a-5d6b-11eb-8d6d-ae8d4ded2a34
Jan 23 04:11:32 setsv mysqld: 2021-01-23  4:11:32 140325406353152 [Warning] WSREP: 0.0 (setsv): State transfer to -1.-1 (left the group) failed: -22 (Invalid argument)
Jan 23 04:11:32 setsv mysqld: 2021-01-23  4:11:32 140325406353152 [Note] WSREP: Shifting DONOR/DESYNCED -> JOINED (TO: 0)
Jan 23 04:11:32 setsv mysqld: 2021-01-23  4:11:32 140325406353152 [Note] WSREP: Member 0.0 (setsv) synced with group.
Jan 23 04:11:32 setsv mysqld: 2021-01-23  4:11:32 140325406353152 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 0)
Jan 23 04:11:32 setsv mysqld: 2021-01-23  4:11:32 140325646681856 [Note] WSREP: Synchronized with group, ready for connections
Jan 23 04:11:32 setsv mysqld: 2021-01-23  4:11:32 140325646681856 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
Jan 23 04:11:36 setsv mysqld: 2021-01-23  4:11:36 140325414745856 [Note] WSREP:  cleaning up b8dba97a (ssl://192.168.56.71:4567)

, file /var/lib/mysql//innobackup.backup.log says

210123 04:11:32 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!".

210123 04:11:32 Connecting to MySQL server host: localhost, user: sst_user, password: set, port: not set, socket: /var/lib/mysql/mysql.sock
Using server version 10.2.36-MariaDB
innobackupex version 2.3.10 based on MySQL server 5.6.24 Linux (x86_64) (revision id: bd0d4403f36)
xtrabackup: uses posix_fadvise().
xtrabackup: cd to /var/lib/mysql/
xtrabackup: open files limit requested 0, set to 16384
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
InnoDB: No valid checkpoint found.
InnoDB: If this error appears when you are creating an InnoDB database,
InnoDB: the problem may be that during an earlier attempt you managed
InnoDB: to create the InnoDB data files, but log file creation failed.
InnoDB: If that is the case, please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/error-creating-innodb.html
1 Like
2

I recommend upgrading to Xtrabackup 2.4 firstly. Secondly, I see this in the donor error log “Connection refused”. Make sure no iptables, no SELinux are running. Make sure your SST user has proper username/password created.

3

Thank you for your reply, @matthewb .

I’ve tried to install percona-xtrabackup-24.x86_64 2.4.21-1.el7 @tools-release-x86_64. The joiner is still unable to join in, but with a different error on the donor says “InnoDB: Unsupported redo log format.”.

On the donor, file /var/lib/mysql//innobackup.backup.log says:

xtrabackup: recognized server arguments:
xtrabackup: recognized client arguments:
210124 14:16:53 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!".

210124 14:16:53  version_check Connecting to MySQL server with DSN 'dbi:mysql:;mysql_read_default_group=xtrabackup;mysql_socket=/var/lib/mysql/mysql.sock' as 'sst_user'  (using password: YES).
210124 14:16:53  version_check Connected to MySQL server
210124 14:16:53  version_check Executing a version check against the server...
210124 14:16:53  version_check Done.
210124 14:16:53 Connecting to MySQL server host: localhost, user: sst_user, password: set, port: not set, socket: /var/lib/mysql/mysql.sock
Using server version 10.2.36-MariaDB
innobackupex version 2.4.21 based on MySQL server 5.7.32 Linux (x86_64) (revision id: 5988af5)
xtrabackup: uses posix_fadvise().
xtrabackup: cd to /var/lib/mysql/
xtrabackup: open files limit requested 0, set to 16384
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
InnoDB: Number of pools: 1
InnoDB: Unsupported redo log format. The redo log was created with MariaDB 10.2.36. Please follow the instructions at http://dev.mysql.com/doc/refman/5.7/en/upgrading-downgrading.html
1 Like
4

Hmm. Looks like your MariaDB 10.2 is older than I thought. My apologies. You’ll need to downgrade back to xtrabackup 2.3. Did you check any of the other things I mentioned?

1 Like
5

Hi, @matthewb , I’ve set the virtual machine back to the original snapshot and tested again. In this test, there is no indication about “connection refused”, although the joiner is still unable to join in.

  1. On the joiner side, the error says “Failed to prepare for incremental state transfer: … (Operation not permitted)”:
file /var/log/message:
Jan 24 15:43:59 setsv-dr mysqld: 2021-01-24 15:43:59 140266658240256 [Warning] WSREP: Failed to prepare for incremental state transfer: Local state UUID (00000000-0000-0000-0000-000000000000) does not match group state UUID (7b04f4c1-5e95-11eb-8f14-dbe525f06b3f): 1 (Operation not permitted)
  1. On the donor side, the error says “innobackupex finished with error” and “InnoDB: No valid checkpoint found.”.
1) file /var/log/message:
Jan 24 15:43:59 setsv mysqld: WSREP_SST: [ERROR] innobackupex finished with error: 1.  Check /var/lib/mysql//innobackup.backup.log (20210124 15:43:59.836)
Jan 24 15:43:59 setsv mysqld: WSREP_SST: [ERROR] Cleanup after exit with status:22 (20210124 15:43:59.838)
Jan 24 15:43:59 setsv mysqld: 2021-01-24 15:43:59 139990726027008 [ERROR] WSREP: Failed to read from: wsrep_sst_xtrabackup --role 'donor' --address '192.168.56.71:4444/xtrabackup_sst' --socket '/var/lib/mysql/mysql.sock' --datadir '/var/lib/mysql/' --gtid '7b04f4c1-5e95-11eb-8f14-dbe525f06b3f:0' --gtid-domain-id '0' --mysqld-args --basedir=/usr --wsrep-new-cluster --wsrep_start_position=00000000-0000-0000-0000-000000000000:-1
Jan 24 15:43:59 setsv mysqld: 2021-01-24 15:43:59 139990726027008 [ERROR] WSREP: Process completed with error: wsrep_sst_xtrabackup --role 'donor' --address '192.168.56.71:4444/xtrabackup_sst' --socket '/var/lib/mysql/mysql.sock' --datadir '/var/lib/mysql/' --gtid '7b04f4c1-5e95-11eb-8f14-dbe525f06b3f:0' --gtid-domain-id '0' --mysqld-args --basedir=/usr --wsrep-new-cluster --wsrep_start_position=00000000-0000-0000-0000-000000000000:-1: 22 (Invalid argument)
Jan 24 15:43:59 setsv mysqld: 2021-01-24 15:43:59 139990726027008 [ERROR] WSREP: Command did not run: wsrep_sst_xtrabackup --role 'donor' --address '192.168.56.71:4444/xtrabackup_sst' --socket '/var/lib/mysql/mysql.sock' --datadir '/var/lib/mysql/' --gtid '7b04f4c1-5e95-11eb-8f14-dbe525f06b3f:0' --gtid-domain-id '0' --mysqld-args --basedir=/usr --wsrep-new-cluster --wsrep_start_position=00000000-0000-0000-0000-000000000000:-1
Jan 24 15:43:59 setsv mysqld: 2021-01-24 15:43:59 139991623649024 [Warning] WSREP: 0.0 (setsv): State transfer to 1.0 (setsv-dr) failed: -22 (Invalid argument)
Jan 24 15:43:59 setsv mysqld: 2021-01-24 15:43:59 139991623649024 [Note] WSREP: Shifting DONOR/DESYNCED -> JOINED (TO: 0)

2) file /var/lib/mysql//innobackup.backup.log:
210124 15:44:47 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!".

210124 15:44:47  version_check Connecting to MySQL server with DSN 'dbi:mysql:;mysql_read_default_group=xtrabackup;mysql_socket=/var/lib/mysql/mysql.sock' as 'sst_user'  (using password: YES).
210124 15:44:47  version_check Connected to MySQL server
210124 15:44:47  version_check Executing a version check against the server...
210124 15:44:47  version_check Done.
210124 15:44:47 Connecting to MySQL server host: localhost, user: sst_user, password: set, port: not set, socket: /var/lib/mysql/mysql.sock
Using server version 10.2.36-MariaDB
innobackupex version 2.3.10 based on MySQL server 5.6.24 Linux (x86_64) (revision id: bd0d4403f36)
xtrabackup: uses posix_fadvise().
xtrabackup: cd to /var/lib/mysql/
xtrabackup: open files limit requested 0, set to 16384
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
InnoDB: No valid checkpoint found.
InnoDB: If this error appears when you are creating an InnoDB database,
InnoDB: the problem may be that during an earlier attempt you managed
InnoDB: to create the InnoDB data files, but log file creation failed.
InnoDB: If that is the case, please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/error-creating-innodb.html
1 Like
6

The joiner will always fail if the donor fails, so chasing any errors down on the joiner at this point is a waste of time. You are absolutely sure that a manual execution of xtrabackup on the donor runs without issue? And you are 100% sure no SELinux or appArmor involved? And you are sure all permissions mysql:mysql are correct? It is not possible for mysql to be running and have an invalid InnoDB state. So, the error “No valid checkpoint found” leads me to believe that xtrabackup simply cannot read the innodb files such as the ib_logfile0/1

1 Like