[MDEV-15774] MariaDB crashes when trying to sync with xtrabackup-v2 Created: 2018-04-04  Updated: 2018-08-07  Resolved: 2018-08-07

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

Type: Bug Priority: Major
Reporter: Philipp Assignee: Jan Lindström (Inactive)
Resolution: Not a Bug Votes: 0
Labels: crash, galera, xtrabackup
Environment:

Official MariaDB 10.3.5 Docker image



 Description   

A second node trying to join a bootstrapped node with Galera and xtrabackup-v2 crashes the second node.
If wsrep_sst_method=rsync is used on the second node, synchronization is successful.

my.cnf of first node:

[mysqld]
bind-address=0.0.0.0
binlog_format=ROW
default_storage_engine=InnoDB
innodb_autoinc_lock_mode=2
 
ssl-key=/opt/cert/server-key.pem
ssl-cert=/opt/cert/server-cert.pem
ssl-ca=/opt/cert/ca.pem
 
wsrep_on=ON
wsrep_provider=/usr/lib/galera/libgalera_smm.so
wsrep_cluster_address=gcomm://$NODE_1_IP,$NODE_2_IP
wsrep_node_address=$NODE_1_IP
wsrep_sst_method=xtrabackup-v2
wsrep_cluster_name=$CLUSTER_NAME
wsrep_sst_auth="root:$ROOT_PASSWORD"
 
[sst]
encrypt=4

my.cnf on second node:

[mysqld]
bind-address=0.0.0.0
binlog_format=ROW
default_storage_engine=InnoDB
innodb_autoinc_lock_mode=2
 
ssl-key=/opt/cert/server-key.pem
ssl-cert=/opt/cert/server-cert.pem
ssl-ca=/opt/cert/ca.pem
 
wsrep_on=ON
wsrep_provider=/usr/lib/galera/libgalera_smm.so
wsrep_cluster_address=gcomm://$NODE_1_IP,$NODE_2_IP
wsrep_node_address=$NODE_2_IP
wsrep_sst_method=xtrabackup-v2
wsrep_cluster_name=$CLUSTER_NAME
wsrep_sst_auth="root:$ROOT_PASSWORD"
 
[sst]
encrypt=4

Log on first node after starting second node:

2018-04-04 10:09:17 0 [Note] WSREP: (1ad38338, 'tcp://0.0.0.0:4567') connection established to 3c222bce tcp://$NODE_2_IP:4567
2018-04-04 10:09:17 0 [Note] WSREP: (1ad38338, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers: 
2018-04-04 10:09:18 0 [Note] WSREP: declaring 3c222bce at tcp://$NODE_2_IP:4567 stable
2018-04-04 10:09:18 0 [Note] WSREP: Node 1ad38338 state prim
2018-04-04 10:09:18 0 [Note] WSREP: view(view_id(PRIM,1ad38338,2) memb {
	1ad38338,0
	3c222bce,0
} joined {
} left {
} partitioned {
})
2018-04-04 10:09:18 0 [Note] WSREP: save pc into disk
2018-04-04 10:09:18 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 2
2018-04-04 10:09:18 0 [Note] WSREP: STATE_EXCHANGE: sent state UUID: 3c753758-37f0-11e8-b61a-67335338ccc2
2018-04-04 10:09:18 0 [Note] WSREP: STATE EXCHANGE: sent state msg: 3c753758-37f0-11e8-b61a-67335338ccc2
2018-04-04 10:09:18 0 [Note] WSREP: STATE EXCHANGE: got state msg: 3c753758-37f0-11e8-b61a-67335338ccc2 from 0 (1b0926f95d5d)
2018-04-04 10:09:18 0 [Note] WSREP: STATE EXCHANGE: got state msg: 3c753758-37f0-11e8-b61a-67335338ccc2 from 1 (a9feca5cc7fb)
2018-04-04 10:09:18 0 [Note] WSREP: Quorum results:
	version    = 4,
	component  = PRIMARY,
	conf_id    = 1,
	members    = 1/2 (joined/total),
	act_id     = 6,
	last_appl. = 0,
	protocols  = 0/8/3 (gcs/repl/appl),
	group UUID = 185e44d4-37f0-11e8-a1c3-17b30f5cc4f7
2018-04-04 10:09:18 0 [Note] WSREP: Flow-control interval: [23, 23]
2018-04-04 10:09:18 0 [Note] WSREP: Trying to continue unpaused monitor
2018-04-04 10:09:18 1 [Note] WSREP: New cluster view: global state: 185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6, view# 2: Primary, number of nodes: 2, my index: 0, protocol version 3
2018-04-04 10:09:18 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2018-04-04 10:09:18 1 [Note] WSREP: REPL Protocols: 8 (3, 2)
2018-04-04 10:09:18 1 [Note] WSREP: Assign initial position for certification: 6, protocol version: 3
2018-04-04 10:09:18 0 [Note] WSREP: Service thread queue flushed.
2018-04-04 10:09:20 0 [Note] WSREP: (1ad38338, 'tcp://0.0.0.0:4567') turning message relay requesting off
2018-04-04 10:09:25 0 [Note] WSREP: Member 1.0 (a9feca5cc7fb) requested state transfer from '*any*'. Selected 0.0 (1b0926f95d5d)(SYNCED) as donor.
2018-04-04 10:09:25 0 [Note] WSREP: Shifting SYNCED -> DONOR/DESYNCED (TO: 6)
2018-04-04 10:09:25 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2018-04-04 10:09:25 0 [Note] WSREP: Running: 'wsrep_sst_xtrabackup-v2 --role 'donor' --address '$NODE_2_IP:4444/xtrabackup_sst//$NODE_2_IP' --socket '/var/run/mysqld/mysqld.sock' --datadir '/var/lib/mysql/'     '' --gtid '185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6' --gtid-domain-id '0''
2018-04-04 10:09:25 1 [Note] WSREP: sst_donor_thread signaled with 0
WSREP_SST: [INFO] Streaming with xbstream (20180404 10:09:26.334)
WSREP_SST: [INFO] Using socat as streamer (20180404 10:09:26.348)
WSREP_SST: [INFO] Using openssl based encryption with socat: with key, crt, and ca (20180404 10:09:26.382)
WSREP_SST: [INFO] Encrypting with CERT: /opt/cert/server-cert.pem, KEY: /opt/cert/server-key.pem, CA: /opt/cert/ca.pem (20180404 10:09:26.416)
WSREP_SST: [INFO] Using /tmp/tmp.V90pQr8bGX as innobackupex temporary directory (20180404 10:09:26.470)
WSREP_SST: [INFO] Streaming GTID file before SST (20180404 10:09:26.495)
WSREP_SST: [INFO] Evaluating xbstream -c ${INFO_FILE} | socat -u stdio openssl-connect:$NODE_2_IP:4444,cert=/opt/cert/server-cert.pem,key=/opt/cert/server-key.pem,cafile=/opt/cert/ca.pem,verify=1; RC=( ${PIPESTATUS[@]} ) (20180404 10:09:26.507)
WSREP_SST: [INFO] Sleeping before data transfer for SST (20180404 10:09:26.690)
WSREP_SST: [INFO] Streaming the backup to joiner at $NODE_2_IP 4444 (20180404 10:09:36.702)
WSREP_SST: [INFO] Evaluating innobackupex    --no-version-check  $tmpopts $INNOEXTRA --galera-info --stream=$sfmt $itmpdir 2>${DATA}/innobackup.backup.log | socat -u stdio openssl-connect:$NODE_2_IP:4444,cert=/opt/cert/server-cert.pem,key=/opt/cert/server-key.pem,cafile=/opt/cert/ca.pem,verify=1; RC=( ${PIPESTATUS[@]} ) (20180404 10:09:36.717)
2018-04-04 10:09:36 10 [Warning] Aborted connection 10 to db: 'unconnected' user: 'root' host: 'localhost' (Got an error reading communication packets)
WSREP_SST: [ERROR] innobackupex finished with error: 1.  Check /var/lib/mysql//innobackup.backup.log (20180404 10:09:36.922)
WSREP_SST: [ERROR] Cleanup after exit with status:22 (20180404 10:09:36.936)
WSREP_SST: [INFO] Cleaning up temporary directories (20180404 10:09:36.944)
2018-04-04 10:09:36 0 [ERROR] WSREP: Failed to read from: wsrep_sst_xtrabackup-v2 --role 'donor' --address '$NODE_2_IP:4444/xtrabackup_sst//$NODE_2_IP' --socket '/var/run/mysqld/mysqld.sock' --datadir '/var/lib/mysql/'     '' --gtid '185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6' --gtid-domain-id '0'
2018-04-04 10:09:36 0 [ERROR] WSREP: Process completed with error: wsrep_sst_xtrabackup-v2 --role 'donor' --address '$NODE_2_IP:4444/xtrabackup_sst//$NODE_2_IP' --socket '/var/run/mysqld/mysqld.sock' --datadir '/var/lib/mysql/'     '' --gtid '185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6' --gtid-domain-id '0': 22 (Invalid argument)
2018-04-04 10:09:36 0 [ERROR] WSREP: Command did not run: wsrep_sst_xtrabackup-v2 --role 'donor' --address '$NODE_2_IP:4444/xtrabackup_sst//$NODE_2_IP' --socket '/var/run/mysqld/mysqld.sock' --datadir '/var/lib/mysql/'     '' --gtid '185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6' --gtid-domain-id '0'
2018-04-04 10:09:36 0 [Warning] WSREP: 0.0 (1b0926f95d5d): State transfer to 1.0 (a9feca5cc7fb) failed: -22 (Invalid argument)
2018-04-04 10:09:36 0 [Note] WSREP: Shifting DONOR/DESYNCED -> JOINED (TO: 6)
2018-04-04 10:09:36 0 [Note] WSREP: Member 0.0 (1b0926f95d5d) synced with group.
2018-04-04 10:09:36 0 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 6)
2018-04-04 10:09:36 1 [Note] WSREP: Synchronized with group, ready for connections
2018-04-04 10:09:36 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2018-04-04 10:09:37 0 [Note] WSREP: forgetting 3c222bce (tcp://$NODE_2_IP:4567)
2018-04-04 10:09:37 0 [Note] WSREP: Node 1ad38338 state prim
2018-04-04 10:09:37 0 [Note] WSREP: view(view_id(PRIM,1ad38338,3) memb {
	1ad38338,0
} joined {
} left {
} partitioned {
	3c222bce,0
})
2018-04-04 10:09:37 0 [Note] WSREP: save pc into disk
2018-04-04 10:09:37 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 1
2018-04-04 10:09:37 0 [Note] WSREP: forgetting 3c222bce (tcp://$NODE_2_IP:4567)
2018-04-04 10:09:37 0 [Note] WSREP: STATE_EXCHANGE: sent state UUID: 48516712-37f0-11e8-a527-1e78bdeed6e0
2018-04-04 10:09:37 0 [Note] WSREP: STATE EXCHANGE: sent state msg: 48516712-37f0-11e8-a527-1e78bdeed6e0
2018-04-04 10:09:37 0 [Note] WSREP: STATE EXCHANGE: got state msg: 48516712-37f0-11e8-a527-1e78bdeed6e0 from 0 (1b0926f95d5d)
2018-04-04 10:09:37 0 [Note] WSREP: Quorum results:
	version    = 4,
	component  = PRIMARY,
	conf_id    = 2,
	members    = 1/1 (joined/total),
	act_id     = 6,
	last_appl. = 0,
	protocols  = 0/8/3 (gcs/repl/appl),
	group UUID = 185e44d4-37f0-11e8-a1c3-17b30f5cc4f7
2018-04-04 10:09:37 0 [Note] WSREP: Flow-control interval: [16, 16]
2018-04-04 10:09:37 0 [Note] WSREP: Trying to continue unpaused monitor
2018-04-04 10:09:37 1 [Note] WSREP: New cluster view: global state: 185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6, view# 3: Primary, number of nodes: 1, my index: 0, protocol version 3
2018-04-04 10:09:37 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2018-04-04 10:09:37 1 [Note] WSREP: REPL Protocols: 8 (3, 2)
2018-04-04 10:09:37 1 [Note] WSREP: Assign initial position for certification: 6, protocol version: 3
2018-04-04 10:09:37 0 [Note] WSREP: Service thread queue flushed.
2018-04-04 10:09:41 0 [Note] WSREP: (1ad38338, 'tcp://0.0.0.0:4567') connection established to 3c222bce tcp://$NODE_2_IP:4567
2018-04-04 10:09:41 0 [Warning] WSREP: discarding established (time wait) 3c222bce (tcp://$NODE_2_IP:4567) 
2018-04-04 10:09:43 0 [Note] WSREP:  cleaning up 3c222bce (tcp://$NODE_2_IP:4567)

innobackup.backup.log on first node:

180404 10:09:36 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!".
 
180404 10:09:36 Connecting to MySQL server host: localhost, user: root, password: set, port: 3306, socket: /var/run/mysqld/mysqld.sock
Using server version 10.3.5-MariaDB-10.3.5+maria~jessie
innobackupex version 2.4.10 based on MySQL server 5.7.19 Linux (x86_64) (revision id: 3198bce)
xtrabackup: uses posix_fadvise().
xtrabackup: cd to /var/lib/mysql
xtrabackup: open files limit requested 0, set to 1048576
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
xtrabackup: using O_DIRECT
InnoDB: Number of pools: 1
InnoDB: Unsupported redo log format. The redo log was created with MariaDB 10.3.5. Please follow the instructions at http://dev.mysql.com/doc/refman/5.7/en/upgrading-downgrading.html

Log from start to crash of second node:

2018-04-04 10:09:17 0 [Note] mysqld (mysqld 10.3.5-MariaDB-10.3.5+maria~jessie) starting as process 1 ...
2018-04-04 10:09:17 0 [Note] WSREP: Read nil XID from storage engines, skipping position init
2018-04-04 10:09:17 0 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib/galera/libgalera_smm.so'
2018-04-04 10:09:17 0 [Note] WSREP: wsrep_load(): Galera 25.3.23(r3789) by Codership Oy <info@codership.com> loaded successfully.
2018-04-04 10:09:17 0 [Note] WSREP: CRC-32C: using hardware acceleration.
2018-04-04 10:09:17 0 [Warning] WSREP: Could not open state file for reading: '/var/lib/mysql//grastate.dat'
2018-04-04 10:09:17 0 [Note] WSREP: Found saved state: 00000000-0000-0000-0000-000000000000:-1, safe_to_bootstrap: 1
2018-04-04 10:09:17 0 [Note] WSREP: Passing config to GCS: base_dir = /var/lib/mysql/; base_host = $NODE_2_IP; base_port = 4567; cert.log_conflicts = no; debug = no; evs.auto_evict = 0; evs.delay_margin = PT1S; evs.delayed_keep_period = PT30S; evs.inactive_check_period = PT0.5S; evs.inactive_timeout = PT15S; evs.join_retrans_period = PT1S; evs.max_install_timeouts = 3; evs.send_window = 4; evs.stats_report_period = PT1M; evs.suspect_timeout = PT5S; evs.user_send_window = 2; evs.view_forget_timeout = PT24H; gcache.dir = /var/lib/mysql/; gcache.keep_pages_size = 0; gcache.mem_size = 0; gcache.name = /var/lib/mysql//galera.cache; gcache.page_size = 128M; gcache.recover = no; gcache.size = 128M; gcomm.thread_prio = ; gcs.fc_debug = 0; gcs.fc_factor = 1.0; gcs.fc_limit = 16; gcs.fc_master_slave = no; gcs.max_packet_size = 64500; gcs.max_throttle = 0.25; gcs.recv_q_hard_limit = 9223372036854775807; gcs.recv_q_soft_limit = 0.25; gcs.sync_donor = no; gmcast.segment = 0; gmcast.version = 0; pc.announce_timeout = PT3S; pc.checksum = false; pc
2018-04-04 10:09:17 0 [Note] WSREP: GCache history reset: 00000000-0000-0000-0000-000000000000:0 -> 00000000-0000-0000-0000-000000000000:-1
2018-04-04 10:09:17 0 [Note] WSREP: Assign initial position for certification: -1, protocol version: -1
2018-04-04 10:09:17 0 [Note] WSREP: wsrep_sst_grab()
2018-04-04 10:09:17 0 [Note] WSREP: Start replication
2018-04-04 10:09:17 0 [Note] WSREP: Setting initial position to 00000000-0000-0000-0000-000000000000:-1
2018-04-04 10:09:17 0 [Note] WSREP: protonet asio version 0
2018-04-04 10:09:17 0 [Note] WSREP: Using CRC-32C for message checksums.
2018-04-04 10:09:17 0 [Note] WSREP: backend: asio
2018-04-04 10:09:17 0 [Note] WSREP: gcomm thread scheduling priority set to other:0 
2018-04-04 10:09:17 0 [Warning] WSREP: access file(/var/lib/mysql//gvwstate.dat) failed(No such file or directory)
2018-04-04 10:09:17 0 [Note] WSREP: restore pc from disk failed
2018-04-04 10:09:17 0 [Note] WSREP: GMCast version 0
2018-04-04 10:09:17 0 [Note] WSREP: (3c222bce, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567
2018-04-04 10:09:17 0 [Note] WSREP: (3c222bce, 'tcp://0.0.0.0:4567') multicast: , ttl: 1
2018-04-04 10:09:17 0 [Note] WSREP: EVS version 0
2018-04-04 10:09:17 0 [Note] WSREP: gcomm: connecting to group '$CLUSTER_NAME', peer '$NODE_1_IP:,$NODE_2_IP:'
2018-04-04 10:09:17 0 [Note] WSREP: (3c222bce, 'tcp://0.0.0.0:4567') connection established to 3c222bce tcp://172.17.0.1:4567
2018-04-04 10:09:17 0 [Note] WSREP: (3c222bce, 'tcp://0.0.0.0:4567') connection established to 1ad38338 tcp://$NODE_1_IP:4567
2018-04-04 10:09:17 0 [Note] WSREP: (3c222bce, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers: 
2018-04-04 10:09:18 0 [Note] WSREP: declaring 1ad38338 at tcp://$NODE_1_IP:4567 stable
2018-04-04 10:09:18 0 [Note] WSREP: Node 1ad38338 state prim
2018-04-04 10:09:18 0 [Note] WSREP: view(view_id(PRIM,1ad38338,2) memb {
	1ad38338,0
	3c222bce,0
} joined {
} left {
} partitioned {
})
2018-04-04 10:09:18 0 [Note] WSREP: save pc into disk
2018-04-04 10:09:18 0 [Note] WSREP: discarding pending addr without UUID: tcp://$NODE_2_IP:4567
2018-04-04 10:09:18 0 [Note] WSREP: discarding pending addr proto entry 0x55c3215e0480
2018-04-04 10:09:18 0 [Note] WSREP: gcomm: connected
2018-04-04 10:09:18 0 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636
2018-04-04 10:09:18 0 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0)
2018-04-04 10:09:18 0 [Note] WSREP: Opened channel '$CLUSTER_NAME'
2018-04-04 10:09:18 0 [Note] WSREP: Waiting for SST to complete.
2018-04-04 10:09:18 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 1, memb_num = 2
2018-04-04 10:09:18 0 [Note] WSREP: STATE EXCHANGE: Waiting for state UUID.
2018-04-04 10:09:18 0 [Note] WSREP: STATE EXCHANGE: sent state msg: 3c753758-37f0-11e8-b61a-67335338ccc2
2018-04-04 10:09:18 0 [Note] WSREP: STATE EXCHANGE: got state msg: 3c753758-37f0-11e8-b61a-67335338ccc2 from 0 (1b0926f95d5d)
2018-04-04 10:09:18 0 [Note] WSREP: STATE EXCHANGE: got state msg: 3c753758-37f0-11e8-b61a-67335338ccc2 from 1 (a9feca5cc7fb)
2018-04-04 10:09:18 0 [Note] WSREP: Quorum results:
	version    = 4,
	component  = PRIMARY,
	conf_id    = 1,
	members    = 1/2 (joined/total),
	act_id     = 6,
	last_appl. = -1,
	protocols  = 0/8/3 (gcs/repl/appl),
	group UUID = 185e44d4-37f0-11e8-a1c3-17b30f5cc4f7
2018-04-04 10:09:18 0 [Note] WSREP: Flow-control interval: [23, 23]
2018-04-04 10:09:18 0 [Note] WSREP: Trying to continue unpaused monitor
2018-04-04 10:09:18 0 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 6)
2018-04-04 10:09:18 1 [Note] WSREP: State transfer required: 
	Group state: 185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6
	Local state: 00000000-0000-0000-0000-000000000000:-1
2018-04-04 10:09:18 1 [Note] WSREP: New cluster view: global state: 185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6, view# 2: Primary, number of nodes: 2, my index: 1, protocol version 3
2018-04-04 10:09:18 1 [Warning] WSREP: Gap in state sequence. Need state transfer.
2018-04-04 10:09:18 0 [Note] WSREP: Running: 'wsrep_sst_xtrabackup-v2 --role 'joiner' --address '$NODE_2_IP' --datadir '/var/lib/mysql/'   --parent '1'  '' '
WSREP_SST: [INFO] Streaming with xbstream (20180404 10:09:19.950)
WSREP_SST: [INFO] Using socat as streamer (20180404 10:09:19.964)
WSREP_SST: [INFO] Using openssl based encryption with socat: with key, crt, and ca (20180404 10:09:20.064)
WSREP_SST: [INFO] Decrypting with CERT: /opt/cert/server-cert.pem, KEY: /opt/cert/server-key.pem, CA: /opt/cert/ca.pem (20180404 10:09:20.180)
WSREP_SST: [INFO] Evaluating timeout -k 110 100 socat -u openssl-listen:4444,reuseaddr,cert=/opt/cert/server-cert.pem,key=/opt/cert/server-key.pem,cafile=/opt/cert/ca.pem,verify=1,dhparam=/var/lib/mysql//dhparams.pem stdio | xbstream -x; RC=( ${PIPESTATUS[@]} ) (20180404 10:09:20.435)
2018-04-04 10:09:21 0 [Note] WSREP: (3c222bce, 'tcp://0.0.0.0:4567') turning message relay requesting off
2018-04-04 10:09:25 1 [Note] WSREP: Prepared SST request: xtrabackup-v2|$NODE_2_IP:4444/xtrabackup_sst//$NODE_2_IP
2018-04-04 10:09:25 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2018-04-04 10:09:25 1 [Note] WSREP: REPL Protocols: 8 (3, 2)
2018-04-04 10:09:25 1 [Note] WSREP: Assign initial position for certification: 6, protocol version: 3
2018-04-04 10:09:25 0 [Note] WSREP: Service thread queue flushed.
2018-04-04 10:09:25 1 [Warning] WSREP: Failed to prepare for incremental state transfer: Local state UUID (00000000-0000-0000-0000-000000000000) does not match group state UUID (185e44d4-37f0-11e8-a1c3-17b30f5cc4f7): 1 (Operation not permitted)
	 at galera/src/replicator_str.cpp:prepare_for_IST():482. IST will be unavailable.
2018-04-04 10:09:25 0 [Note] WSREP: Member 1.0 (a9feca5cc7fb) requested state transfer from '*any*'. Selected 0.0 (1b0926f95d5d)(SYNCED) as donor.
2018-04-04 10:09:25 0 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 6)
2018-04-04 10:09:25 1 [Note] WSREP: Requesting state transfer: success, donor: 0
2018-04-04 10:09:25 1 [Note] WSREP: GCache history reset: 00000000-0000-0000-0000-000000000000:0 -> 185e44d4-37f0-11e8-a1c3-17b30f5cc4f7:6
WSREP_SST: [INFO] Proceeding with SST (20180404 10:09:26.699)
WSREP_SST: [INFO] Cleaning the existing datadir and innodb-data/log directories (20180404 10:09:26.731)
WSREP_SST: [INFO] Evaluating socat -u openssl-listen:4444,reuseaddr,cert=/opt/cert/server-cert.pem,key=/opt/cert/server-key.pem,cafile=/opt/cert/ca.pem,verify=1,dhparam=/var/lib/mysql//dhparams.pem stdio | xbstream -x; RC=( ${PIPESTATUS[@]} ) (20180404 10:09:26.734)
removed directory: '/var/lib/mysql/mysql'
WSREP_SST: [INFO] Waiting for SST streaming to complete! (20180404 10:09:26.870)
WSREP_SST: [ERROR] xtrabackup_checkpoints missing, failed innobackupex/SST on donor (20180404 10:09:36.919)
2018-04-04 10:09:36 0 [Warning] WSREP: 0.0 (1b0926f95d5d): State transfer to 1.0 (a9feca5cc7fb) failed: -22 (Invalid argument)
2018-04-04 10:09:36 0 [ERROR] WSREP: gcs/src/gcs_group.cpp:gcs_group_handle_join_msg():737: Will never receive state. Need to abort.
2018-04-04 10:09:36 0 [Note] WSREP: gcomm: terminating thread
2018-04-04 10:09:36 0 [Note] WSREP: gcomm: joining thread
2018-04-04 10:09:36 0 [Note] WSREP: gcomm: closing backend
WSREP_SST: [ERROR] Cleanup after exit with status:2 (20180404 10:09:36.969)
2018-04-04 10:09:37 0 [ERROR] WSREP: Process completed with error: wsrep_sst_xtrabackup-v2 --role 'joiner' --address '$NODE_2_IP' --datadir '/var/lib/mysql/'   --parent '1'  '' : 2 (No such file or directory)
2018-04-04 10:09:37 0 [ERROR] WSREP: Failed to read uuid:seqno and wsrep_gtid_domain_id from joiner script.
2018-04-04 10:09:37 0 [ERROR] WSREP: SST failed: 2 (No such file or directory)
2018-04-04 10:09:37 0 [ERROR] Aborting
 
180404 10:09:41 [ERROR] mysqld got signal 11 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
 
To report this bug, see https://mariadb.com/kb/en/reporting-bugs
 
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.
 
Server version: 10.3.5-MariaDB-10.3.5+maria~jessie
key_buffer_size=0
read_buffer_size=2097152
max_used_connections=0
max_threads=102
thread_count=2
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 628936 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
 
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 = 0x0 thread_stack 0x49000
mysqld(my_print_stacktrace+0x2e)[0x55c31fe779ee]
mysqld(handle_fatal_signal+0x347)[0x55c31f907da7]



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

xtrabackup does not work with MariaDB 10.3, you should use MariaBackup.

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