Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Not a Bug
-
10.3.5
-
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]
|
Attachments
Activity
Field | Original Value | New Value |
---|---|---|
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: {code} [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=pentacent-galera wsrep_sst_auth="root:$ROOT_PASSWORD" [sst] encrypt=4 {code} {{my.cnf}} on second node: {code} [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=pentacent-galera wsrep_sst_auth="root:$ROOT_PASSWORD" [sst] encrypt=4 {code} Log on first node after starting second node: {code} 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) {code} {{innobackup.backup.log}} on first node: {code} 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 {code} Log from start to crash of second node: {code} 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 'pentacent-galera', 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 'pentacent-galera' 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] {code} |
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: {code} [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 {code} {{my.cnf}} on second node: {code} [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 {code} Log on first node after starting second node: {code} 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) {code} {{innobackup.backup.log}} on first node: {code} 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 {code} Log from start to crash of second node: {code} 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] {code} |
Fix Version/s | 10.3 [ 22126 ] | |
Assignee | Sachin Setiya [ sachin.setiya.007 ] |
Assignee | Sachin Setiya [ sachin.setiya.007 ] | Jan Lindström [ jplindst ] |
Fix Version/s | N/A [ 14700 ] | |
Fix Version/s | 10.3 [ 22126 ] | |
Resolution | Not a Bug [ 6 ] | |
Status | Open [ 1 ] | Closed [ 6 ] |
Workflow | MariaDB v3 [ 86368 ] | MariaDB v4 [ 154090 ] |
xtrabackup does not work with MariaDB 10.3, you should use MariaBackup.