[MDEV-18482] Unable to JOIN Galera Cluster with 10.3.12 and Debian Stretch - JOINER timesout Created: 2019-02-05  Updated: 2019-05-15  Resolved: 2019-02-15

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

Type: Bug Priority: Trivial
Reporter: Pat Burke Assignee: Jan Lindström (Inactive)
Resolution: Not a Bug Votes: 0
Labels: None
Environment:

Ver 15.1 Distrib 10.3.12-MariaDB, for debian-linux-gnu (x86_64) using readline 5.2
mariabackup based on MariaDB server 10.3.12-MariaDB debian-linux-gnu (x86_64)
Ver 15.1 Distrib 10.3.12-MariaDB, for debian-linux-gnu (x86_64) using readline 5.2

iptables -S
-P INPUT ACCEPT
-P FORWARD ACCEPT
-P OUTPUT ACCEPT


Issue Links:
Relates
relates to MDEV-19422 Unable to JOIN Galera Cluster with 10... Closed

 Description   

I have a 3 node cluster with serveral GB of data and am trying to add a 4th node to the cluster using mariabackup (have tried rsync as well) as the wsrep_sst_method.

I'm guessing I have a setup issue.

The configuration

Running cluster
wahoo-mariadb01 — wahoo-mariadb02 — wahoo-mariadb03

Adding wahoo-mariadb04 using wahoo-mariadb01 as the donor.

These are all base installs of Debian and MariaDB. Used the following links (also installed mariabackup)
https://downloads.mariadb.org/mariadb/repositories/#mirror=osuosl&distro=Debian&distro_release=stretch--stretch&version=10.3
https://mariadb.com/kb/en/library/mariabackup-sst-method

Everything looks good for 90 seconds (I see data going back and forth). Then after 90 seconds the JOINER (wahoo-mariadb04) gives a timeout and the DONOR (wahoo-mariadb01 throws an error - pipe closed).

The configuration on all the servers is the base my.cnf file with the following changes (obviously the node address and node name change)

(comment out bind-address=127.0.0.1)
[galera]

  1. Mandatory settings
    wsrep_on=ON
    wsrep_provider=/usr/lib/galera/libgalera_smm.so
    wsrep_cluster_address=gcomm://192.168.20.91,192.168.20.92,192.168.20.93,192.168.20.94
    binlog_format=row
    default_storage_engine=InnoDB
    innodb_autoinc_lock_mode=2
    log_bin_trust_function_creators=1
  1. Cluster node configuration
    wsrep_cluster_name=wahoo-mariadb-cluster
    wsrep_node_address=192.168.20.91
    wsrep_node_name=wahoo-mariadb01
    wsrep_sst_method=mariabackup
    wsrep_sst_auth=mariabackup:password
    wsrep_sst_donor=wahoo-mariadb01
  1. Excluded databases - one per line
    binlog-ignore-db=vts_lcr_orig
    binlog-ignore-db=vts_lcr_rates
    binlog-ignore-db=vts_rates

#

  1. Allow server to accept connections on all interfaces.
    #
    bind-address=0.0.0.0
    #
  2. Optional setting
    #wsrep_slave_threads=1
    #innodb_flush_log_at_trx_commit=0

[sst]
sst-syslog=1

------------------------------------------------------------------
The log files for the JOINER and DONOR are

JOINER

Feb 5 08:30:48 wahoo-mariadb04 systemd[1]: Starting MariaDB 10.3.12 database server...
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3730]: WSREP: Recovered position 00000000-0000-0000-0000-000000000000:-1
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:51 0 [Note] /usr/sbin/mysqld (mysqld 10.3.12-MariaDB-1:10.3.12+maria~stretch-log) starting as process 3957 ...
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:51 0 [Note] WSREP: Read nil XID from storage engines, skipping position init
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:51 0 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib/galera/libgalera_smm.so'
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:51 0 [Note] WSREP: wsrep_load(): Galera 25.3.25(r3836) by Codership Oy <info@codership.com> loaded successfully.
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:51 0 [Note] WSREP: CRC-32C: using "slicing-by-8" algorithm.
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:51 0 [Note] WSREP: Found saved state: 00000000-0000-0000-0000-000000000000:-1, safe_to_bootstrap: 1
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:51 0 [Note] WSREP: Passing config to GCS: base_dir = /var/lib/mysql/; base_host = 192.168.20.94; base_port = 4567; cert.log_conflicts = no; cert.optimistic_pa = yes; 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
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:51 0 [Note] WSREP: GCache history reset: 70fd14be-28af-11e9-8aa7-ff8340dcc35e:0 -> 00000000-0000-0000-0000-000000000000:-1
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:51 0 [Note] WSREP: Assign initial position for certification: -1, protocol version: -1
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:51 0 [Note] WSREP: wsrep_sst_grab()
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:51 0 [Note] WSREP: Start replication
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:51 0 [Note] WSREP: Setting initial position to 00000000-0000-0000-0000-000000000000:-1
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:51 0 [Note] WSREP: protonet asio version 0
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:51 0 [Note] WSREP: Using CRC-32C for message checksums.
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:51 0 [Note] WSREP: backend: asio
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:51 0 [Note] WSREP: gcomm thread scheduling priority set to other:0
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:51 0 [Warning] WSREP: access file(/var/lib/mysql//gvwstate.dat) failed(No such file or directory)
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:51 0 [Note] WSREP: restore pc from disk failed
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:51 0 [Note] WSREP: GMCast version 0
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:51 0 [Note] WSREP: (a37ce3d6, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:51 0 [Note] WSREP: (a37ce3d6, 'tcp://0.0.0.0:4567') multicast: , ttl: 1
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:51 0 [Note] WSREP: EVS version 0
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:51 0 [Note] WSREP: gcomm: connecting to group 'wahoo-mariadb-cluster', peer '192.168.20.91:,192.168.20.92:,192.168.20.93:,192.168.20.94:'
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:51 0 [Note] WSREP: (a37ce3d6, 'tcp://0.0.0.0:4567') connection established to a37ce3d6 tcp://192.168.20.94:4567
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:51 0 [Warning] WSREP: (a37ce3d6, 'tcp://0.0.0.0:4567') address 'tcp://192.168.20.94:4567' points to own listening address, blacklisting
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:51 0 [Note] WSREP: (a37ce3d6, 'tcp://0.0.0.0:4567') connection established to 99aa2eea tcp://192.168.20.92:4567
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:51 0 [Note] WSREP: (a37ce3d6, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers:
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:51 0 [Note] WSREP: (a37ce3d6, 'tcp://0.0.0.0:4567') connection established to 812e8278 tcp://192.168.20.93:4567
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:51 0 [Note] WSREP: (a37ce3d6, 'tcp://0.0.0.0:4567') connection established to 7b0a3f9e tcp://192.168.20.91:4567
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:51 0 [Note] WSREP: declaring 7b0a3f9e at tcp://192.168.20.91:4567 stable
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:51 0 [Note] WSREP: declaring 812e8278 at tcp://192.168.20.93:4567 stable
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:51 0 [Note] WSREP: declaring 99aa2eea at tcp://192.168.20.92:4567 stable
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:51 0 [Note] WSREP: Node 7b0a3f9e state prim
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:51 0 [Note] WSREP: view(view_id(PRIM,7b0a3f9e,18) memb

{ Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: #0117b0a3f9e,0 Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: #011812e8278,0 Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: #01199aa2eea,0 Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: #011a37ce3d6,0 Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: }

joined

{ Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: }

left

{ Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: }

partitioned

{ Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: }

)
Feb 5 08:30:51 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:51 0 [Note] WSREP: save pc into disk
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:52 0 [Note] WSREP: gcomm: connected
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:52 0 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:52 0 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0)
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:52 0 [Note] WSREP: Opened channel 'wahoo-mariadb-cluster'
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:52 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 3, memb_num = 4
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:52 0 [Note] WSREP: STATE EXCHANGE: Waiting for state UUID.
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:52 0 [Note] WSREP: Waiting for SST to complete.
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:52 0 [Note] WSREP: STATE EXCHANGE: sent state msg: a3803e81-2952-11e9-8611-23c2ab774eae
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:52 0 [Note] WSREP: STATE EXCHANGE: got state msg: a3803e81-2952-11e9-8611-23c2ab774eae from 0 (wahoo-mariadb01)
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:52 0 [Note] WSREP: STATE EXCHANGE: got state msg: a3803e81-2952-11e9-8611-23c2ab774eae from 1 (wahoo-mariadb03)
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:52 0 [Note] WSREP: STATE EXCHANGE: got state msg: a3803e81-2952-11e9-8611-23c2ab774eae from 2 (wahoo-mariadb02)
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:52 0 [Note] WSREP: STATE EXCHANGE: got state msg: a3803e81-2952-11e9-8611-23c2ab774eae from 3 (wahoo-mariadb04)
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:52 0 [Note] WSREP: Quorum results:
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: #011version = 4,
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: #011component = PRIMARY,
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: #011conf_id = 17,
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: #011members = 3/4 (joined/total),
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: #011act_id = 22022,
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: #011last_appl. = -1,
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: #011protocols = 0/9/3 (gcs/repl/appl),
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: #011group UUID = 70fd14be-28af-11e9-8aa7-ff8340dcc35e
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:52 0 [Note] WSREP: Flow-control interval: [32, 32]
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:52 0 [Note] WSREP: Trying to continue unpaused monitor
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:52 0 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 22022)
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:52 2 [Note] WSREP: State transfer required:
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: #011Group state: 70fd14be-28af-11e9-8aa7-ff8340dcc35e:22022
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: #011Local state: 00000000-0000-0000-0000-000000000000:-1
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:52 2 [Note] WSREP: New cluster view: global state: 70fd14be-28af-11e9-8aa7-ff8340dcc35e:22022, view# 18: Primary, number of nodes: 4, my index: 3, protocol version 3
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:52 2 [Warning] WSREP: Gap in state sequence. Need state transfer.
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:52 0 [Note] WSREP: Running: 'wsrep_sst_mariabackup --role 'joiner' --address '192.168.20.94' --datadir '/var/lib/mysql/' --parent '3957' --binlog '/var/log/mysql/mariadb-bin' --binlog-index '/var/log/mysql/mariadb-bin.index''
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: WSREP_SST: [INFO] Logging all stderr of SST/Innobackupex to syslog (20190205 08:30:52.546)
Feb 5 08:30:52 wahoo-mariadb04 -wsrep-sst-joiner: Streaming with xbstream
Feb 5 08:30:52 wahoo-mariadb04 -wsrep-sst-joiner: Using socat as streamer
Feb 5 08:30:52 wahoo-mariadb04 -wsrep-sst-joiner: Stale sst_in_progress file: /var/lib/mysql//sst_in_progress
Feb 5 08:30:52 wahoo-mariadb04 -wsrep-sst-joiner: Evaluating timeout -k 110 100 socat -u TCP-LISTEN:4444,reuseaddr stdio | mbstream -x; RC=( ${PIPESTATUS[@]} )
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:52 2 [Note] WSREP: Prepared SST request: mariabackup|192.168.20.94:4444/xtrabackup_sst//1
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:52 2 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:52 2 [Note] WSREP: REPL Protocols: 9 (4, 2)
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:52 2 [Note] WSREP: Assign initial position for certification: 22022, protocol version: 4
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:52 0 [Note] WSREP: Service thread queue flushed.
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:52 2 [Warning] WSREP: Failed to prepare for incremental state transfer: Local state UUID (00000000-0000-0000-0000-000000000000) does not match group state UUID (70fd14be-28af-11e9-8aa7-ff8340dcc35e): 1 (Operation not permitted)
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: #011 at galera/src/replicator_str.cpp:prepare_for_IST():482. IST will be unavailable.
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:52 0 [Note] WSREP: Member 3.0 (wahoo-mariadb04) requested state transfer from 'wahoo-mariadb01'. Selected 0.0 (wahoo-mariadb01)(SYNCED) as donor.
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:52 0 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 22022)
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:52 2 [Note] WSREP: Requesting state transfer: success, donor: 0
Feb 5 08:30:52 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:52 2 [Note] WSREP: GCache history reset: 00000000-0000-0000-0000-000000000000:0 -> 70fd14be-28af-11e9-8aa7-ff8340dcc35e:22022
Feb 5 08:30:53 wahoo-mariadb04 -wsrep-sst-joiner: WARNING: Stale temporary SST directory: /var/lib/mysql//.sst from previous state transfer. Removing
Feb 5 08:30:53 wahoo-mariadb04 -wsrep-sst-joiner: Proceeding with SST
Feb 5 08:30:53 wahoo-mariadb04 -wsrep-sst-joiner: Evaluating socat -u TCP-LISTEN:4444,reuseaddr stdio | mbstream -x; RC=( ${PIPESTATUS[@]} )
Feb 5 08:30:53 wahoo-mariadb04 -wsrep-sst-joiner: Cleaning the existing datadir and innodb-data/log directories
Feb 5 08:30:53 wahoo-mariadb04 -wsrep-sst-joiner: removed '/var/lib/mysql/ib_logfile1'
Feb 5 08:30:53 wahoo-mariadb04 -wsrep-sst-joiner: removed '/var/lib/mysql/ibdata1'
Feb 5 08:30:53 wahoo-mariadb04 -wsrep-sst-joiner: removed '/var/lib/mysql/aria_log.00000001'
Feb 5 08:30:53 wahoo-mariadb04 -wsrep-sst-joiner: removed '/var/lib/mysql/aria_log_control'
Feb 5 08:30:53 wahoo-mariadb04 -wsrep-sst-joiner: Cleaning the binlog directory /var/log/mysql as well
Feb 5 08:30:53 wahoo-mariadb04 -wsrep-sst-joiner: removed '/var/log/mysql/mariadb-bin.000001'
Feb 5 08:30:53 wahoo-mariadb04 -wsrep-sst-joiner: Waiting for SST streaming to complete!
Feb 5 08:30:55 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:55 0 [Note] WSREP: (a37ce3d6, 'tcp://0.0.0.0:4567') connection to peer a37ce3d6 with addr tcp://192.168.20.94:4567 timed out, no messages seen in PT3S
Feb 5 08:30:55 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:30:55 0 [Note] WSREP: (a37ce3d6, 'tcp://0.0.0.0:4567') turning message relay requesting off
Feb 5 08:32:21 wahoo-mariadb04 systemd[1]: mariadb.service: Start operation timed out. Terminating.
Feb 5 08:32:21 wahoo-mariadb04 -wsrep-sst-joiner: Removing /var/lib/mysql//.sst/xtrabackup_galera_info file due to signal
Feb 5 08:32:21 wahoo-mariadb04 -wsrep-sst-joiner: Removing /var/lib/mysql//.sst/xtrabackup_galera_info file due to signal
Feb 5 08:32:21 wahoo-mariadb04 -wsrep-sst-joiner: Cleanup after exit with status:143
Feb 5 08:32:21 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:32:21 0 [ERROR] WSREP: Process was aborted.
Feb 5 08:32:21 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:32:21 0 [ERROR] WSREP: Process completed with error: wsrep_sst_mariabackup --role 'joiner' --address '192.168.20.94' --datadir '/var/lib/mysql/' --parent '3957' --binlog '/var/log/mysql/mariadb-bin' --binlog-index '/var/log/mysql/mariadb-bin.index': 2 (No such file or directory)
Feb 5 08:32:21 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:32:21 0 [ERROR] WSREP: Failed to read uuid:seqno and wsrep_gtid_domain_id from joiner script.
Feb 5 08:32:21 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:32:21 0 [ERROR] WSREP: SST failed: 2 (No such file or directory)
Feb 5 08:32:21 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:32:21 0 [ERROR] Aborting
Feb 5 08:32:21 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:32:21 0 [Warning] WSREP: 0.0 (wahoo-mariadb01): State transfer to 3.0 (wahoo-mariadb04) failed: -22 (Invalid argument)
Feb 5 08:32:21 wahoo-mariadb04 mysqld[3957]: 2019-02-05 8:32:21 0 [ERROR] WSREP: gcs/src/gcs_group.cpp:gcs_group_handle_join_msg():737: Will never receive state. Need to abort.
Feb 5 08:32:21 wahoo-mariadb04 systemd[1]: mariadb.service: Main process exited, code=killed, status=6/ABRT
Feb 5 08:32:21 wahoo-mariadb04 systemd[1]: Failed to start MariaDB 10.3.12 database server.
Feb 5 08:32:21 wahoo-mariadb04 systemd[1]: mariadb.service: Unit entered failed state.
Feb 5 08:32:21 wahoo-mariadb04 systemd[1]: mariadb.service: Failed with result 'timeout'.

DONOR

Feb 5 08:30:51 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:30:51 0 [Note] WSREP: (7b0a3f9e, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers: tcp://192.168.20.94:4567
Feb 5 08:30:51 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:30:51 0 [Note] WSREP: (7b0a3f9e, 'tcp://0.0.0.0:4567') connection established to a37ce3d6 tcp://192.168.20.94:4567
Feb 5 08:30:51 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:30:51 0 [Note] WSREP: declaring 812e8278 at tcp://192.168.20.93:4567 stable
Feb 5 08:30:51 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:30:51 0 [Note] WSREP: declaring 99aa2eea at tcp://192.168.20.92:4567 stable
Feb 5 08:30:51 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:30:51 0 [Note] WSREP: declaring a37ce3d6 at tcp://192.168.20.94:4567 stable
Feb 5 08:30:51 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:30:51 0 [Note] WSREP: Node 7b0a3f9e state prim
Feb 5 08:30:51 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:30:51 0 [Note] WSREP: view(view_id(PRIM,7b0a3f9e,18) memb

{ Feb 5 08:30:51 wahoo-mariadb01 mysqld[936]: #0117b0a3f9e,0 Feb 5 08:30:51 wahoo-mariadb01 mysqld[936]: #011812e8278,0 Feb 5 08:30:51 wahoo-mariadb01 mysqld[936]: #01199aa2eea,0 Feb 5 08:30:51 wahoo-mariadb01 mysqld[936]: #011a37ce3d6,0 Feb 5 08:30:51 wahoo-mariadb01 mysqld[936]: }

joined

{ Feb 5 08:30:51 wahoo-mariadb01 mysqld[936]: }

left

{ Feb 5 08:30:51 wahoo-mariadb01 mysqld[936]: }

partitioned

{ Feb 5 08:30:51 wahoo-mariadb01 mysqld[936]: }

)
Feb 5 08:30:51 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:30:51 0 [Note] WSREP: save pc into disk
Feb 5 08:30:51 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:30:51 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 4
Feb 5 08:30:51 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:30:51 0 [Note] WSREP: STATE_EXCHANGE: sent state UUID: a3803e81-2952-11e9-8611-23c2ab774eae
Feb 5 08:30:51 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:30:51 0 [Note] WSREP: STATE EXCHANGE: sent state msg: a3803e81-2952-11e9-8611-23c2ab774eae
Feb 5 08:30:51 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:30:51 0 [Note] WSREP: STATE EXCHANGE: got state msg: a3803e81-2952-11e9-8611-23c2ab774eae from 0 (wahoo-mariadb01)
Feb 5 08:30:51 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:30:51 0 [Note] WSREP: STATE EXCHANGE: got state msg: a3803e81-2952-11e9-8611-23c2ab774eae from 1 (wahoo-mariadb03)
Feb 5 08:30:51 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:30:51 0 [Note] WSREP: STATE EXCHANGE: got state msg: a3803e81-2952-11e9-8611-23c2ab774eae from 2 (wahoo-mariadb02)
Feb 5 08:30:52 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:30:52 0 [Note] WSREP: STATE EXCHANGE: got state msg: a3803e81-2952-11e9-8611-23c2ab774eae from 3 (wahoo-mariadb04)
Feb 5 08:30:52 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:30:52 0 [Note] WSREP: Quorum results:
Feb 5 08:30:52 wahoo-mariadb01 mysqld[936]: #011version = 4,
Feb 5 08:30:52 wahoo-mariadb01 mysqld[936]: #011component = PRIMARY,
Feb 5 08:30:52 wahoo-mariadb01 mysqld[936]: #011conf_id = 17,
Feb 5 08:30:52 wahoo-mariadb01 mysqld[936]: #011members = 3/4 (joined/total),
Feb 5 08:30:52 wahoo-mariadb01 mysqld[936]: #011act_id = 22022,
Feb 5 08:30:52 wahoo-mariadb01 mysqld[936]: #011last_appl. = 0,
Feb 5 08:30:52 wahoo-mariadb01 mysqld[936]: #011protocols = 0/9/3 (gcs/repl/appl),
Feb 5 08:30:52 wahoo-mariadb01 mysqld[936]: #011group UUID = 70fd14be-28af-11e9-8aa7-ff8340dcc35e
Feb 5 08:30:52 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:30:52 0 [Note] WSREP: Flow-control interval: [32, 32]
Feb 5 08:30:52 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:30:52 0 [Note] WSREP: Trying to continue unpaused monitor
Feb 5 08:30:52 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:30:52 2 [Note] WSREP: New cluster view: global state: 70fd14be-28af-11e9-8aa7-ff8340dcc35e:22022, view# 18: Primary, number of nodes: 4, my index: 0, protocol version 3
Feb 5 08:30:52 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:30:52 2 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
Feb 5 08:30:52 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:30:52 2 [Note] WSREP: REPL Protocols: 9 (4, 2)
Feb 5 08:30:52 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:30:52 2 [Note] WSREP: Assign initial position for certification: 22022, protocol version: 4
Feb 5 08:30:52 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:30:52 0 [Note] WSREP: Service thread queue flushed.
Feb 5 08:30:52 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:30:52 0 [Note] WSREP: Member 3.0 (wahoo-mariadb04) requested state transfer from 'wahoo-mariadb01'. Selected 0.0 (wahoo-mariadb01)(SYNCED) as donor.
Feb 5 08:30:52 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:30:52 0 [Note] WSREP: Shifting SYNCED -> DONOR/DESYNCED (TO: 22022)
Feb 5 08:30:52 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:30:52 2 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
Feb 5 08:30:52 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:30:52 0 [Note] WSREP: Running: 'wsrep_sst_mariabackup --role 'donor' --address '192.168.20.94:4444/xtrabackup_sst//1' --socket '/var/run/mysqld/mysqld.sock' --datadir '/var/lib/mysql/' --binlog '/var/log/mysql/mariadb-bin' --gtid '70fd14be-28af-11e9-8aa7-ff8340dcc35e:22022' --gtid-domain-id '0''
Feb 5 08:30:52 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:30:52 2 [Note] WSREP: sst_donor_thread signaled with 0
Feb 5 08:30:53 wahoo-mariadb01 mysqld[936]: WSREP_SST: [INFO] Logging all stderr of SST/Innobackupex to syslog (20190205 08:30:53.464)
Feb 5 08:30:53 wahoo-mariadb01 -wsrep-sst-donor: Streaming with xbstream
Feb 5 08:30:53 wahoo-mariadb01 -wsrep-sst-donor: Using socat as streamer
Feb 5 08:30:53 wahoo-mariadb01 -wsrep-sst-donor: Using /tmp/tmp.zb5dPPSHpJ as innobackupex temporary directory
Feb 5 08:30:53 wahoo-mariadb01 -wsrep-sst-donor: Streaming GTID file before SST
Feb 5 08:30:53 wahoo-mariadb01 -wsrep-sst-donor: Evaluating mbstream -c ${INFO_FILE} | socat -u stdio TCP:192.168.20.94:4444; RC=( ${PIPESTATUS[@]} )
Feb 5 08:30:53 wahoo-mariadb01 -wsrep-sst-donor: Sleeping before data transfer for SST
Feb 5 08:30:55 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:30:55 0 [Note] WSREP: (7b0a3f9e, 'tcp://0.0.0.0:4567') turning message relay requesting off
Feb 5 08:31:03 wahoo-mariadb01 -wsrep-sst-donor: Streaming the backup to joiner at 192.168.20.94 4444
Feb 5 08:31:03 wahoo-mariadb01 -wsrep-sst-donor: Evaluating mariabackup --innobackupex $tmpopts $INNOEXTRA --galera-info --stream=$sfmt $itmpdir 2> >(logger -p daemon.err -t -innobackupex-backup) | socat -u stdio TCP:192.168.20.94:4444; RC=( ${PIPESTATUS[@]} )
Feb 5 08:31:03 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:03 innobackupex: Starting the backup operation
Feb 5 08:31:03 wahoo-mariadb01 -innobackupex-backup:
Feb 5 08:31:03 wahoo-mariadb01 -innobackupex-backup: IMPORTANT: Please check that the backup run completes successfully.
Feb 5 08:31:03 wahoo-mariadb01 -innobackupex-backup: At the end of a successful backup run innobackupex
Feb 5 08:31:03 wahoo-mariadb01 -innobackupex-backup: prints "completed OK!".
Feb 5 08:31:03 wahoo-mariadb01 -innobackupex-backup:
Feb 5 08:31:03 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:03 Connecting to MySQL server host: localhost, user: mariabackup, password: set, port: 3306, socket: /var/run/mysqld/mysqld.sock
Feb 5 08:31:03 wahoo-mariadb01 -innobackupex-backup: Using server version 10.3.12-MariaDB-1:10.3.12+maria~stretch-log
Feb 5 08:31:03 wahoo-mariadb01 -innobackupex-backup: --innobackupex based on MariaDB server 10.3.12-MariaDB debian-linux-gnu (x86_64)
Feb 5 08:31:03 wahoo-mariadb01 -innobackupex-backup: mariabackup: uses posix_fadvise().
Feb 5 08:31:03 wahoo-mariadb01 -innobackupex-backup: mariabackup: cd to /var/lib/mysql/
Feb 5 08:31:03 wahoo-mariadb01 -innobackupex-backup: mariabackup: open files limit requested 0, set to 16364
Feb 5 08:31:03 wahoo-mariadb01 -innobackupex-backup: mariabackup: using the following InnoDB configuration:
Feb 5 08:31:03 wahoo-mariadb01 -innobackupex-backup: mariabackup: innodb_data_home_dir =
Feb 5 08:31:03 wahoo-mariadb01 -innobackupex-backup: mariabackup: innodb_data_file_path = ibdata1:12M:autoextend
Feb 5 08:31:03 wahoo-mariadb01 -innobackupex-backup: mariabackup: innodb_log_group_home_dir = ./
Feb 5 08:31:03 wahoo-mariadb01 -innobackupex-backup: 2019-02-05 08:31:03 0x7f1da7da78c0 InnoDB: Using Linux native AIO
Feb 5 08:31:03 wahoo-mariadb01 -innobackupex-backup: 2019-02-05 8:31:03 0 [Note] InnoDB: Number of pools: 1
Feb 5 08:31:03 wahoo-mariadb01 -innobackupex-backup: mariabackup: Generating a list of tablespaces
Feb 5 08:31:03 wahoo-mariadb01 -innobackupex-backup: 2019-02-05 8:31:03 0 [Warning] InnoDB: Allocated tablespace ID 243 for opensips_2_2/usr_preferences, old maximum was 0
Feb 5 08:31:06 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:06 >> log scanned up to (118330830731)
Feb 5 08:31:06 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:06 [01] Streaming ibdata1
Feb 5 08:31:07 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:07 >> log scanned up to (118330830731)
Feb 5 08:31:08 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:08 [01] ...done
Feb 5 08:31:08 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:08 >> log scanned up to (118330830731)
Feb 5 08:31:08 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:08 [01] Streaming ./opensips_2_2/usr_preferences.ibd
Feb 5 08:31:08 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:08 [01] ...done
Feb 5 08:31:08 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:08 [01] Streaming ./opensips_2_2/imc_members.ibd
Feb 5 08:31:08 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:08 [01] ...done
Feb 5 08:31:08 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:08 [01] Streaming ./opensips_2_2/inbound_carrier_flat_tfn_rates.ibd
Feb 5 08:31:08 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:08 [01] ...done
Feb 5 08:31:08 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:08 [01] Streaming ./opensips_2_2/inbound_customer_trunk_group_properites.ibd
Feb 5 08:31:08 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:08 [01] ...done
Feb 5 08:31:08 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:08 [01] Streaming ./opensips_2_2/dr_rules_international_3.ibd
Feb 5 08:31:09 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:09 >> log scanned up to (118330830731)
Feb 5 08:31:10 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:10 >> log scanned up to (118330830731)
Feb 5 08:31:11 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:11 >> log scanned up to (118330830731)
Feb 5 08:31:11 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:11 [01] ...done
Feb 5 08:31:11 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:11 [01] Streaming ./opensips_2_2/dispatcher.ibd
Feb 5 08:31:11 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:11 [01] ...done
Feb 5 08:31:11 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:11 [01] Streaming ./opensips_2_2/inbound_carrier_flat_did_rates.ibd
Feb 5 08:31:11 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:11 [01] ...done
Feb 5 08:31:11 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:11 [01] Streaming ./opensips_2_2/speed_dial.ibd
Feb 5 08:31:11 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:11 [01] ...done
Feb 5 08:31:11 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:11 [01] Streaming ./opensips_2_2/inbound_customer_flat_tfn_rates.ibd
Feb 5 08:31:11 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:11 [01] ...done
Feb 5 08:31:11 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:11 [01] Streaming ./opensips_2_2/dr_rules_cust_international_6.ibd
Feb 5 08:31:12 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:12 >> log scanned up to (118330830731)
Feb 5 08:31:13 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:13 >> log scanned up to (118330830731)
Feb 5 08:31:14 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:14 >> log scanned up to (118330830731)
Feb 5 08:31:14 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:14 [01] ...done
Feb 5 08:31:14 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:14 [01] Streaming ./opensips_2_2/dr_rules_cust_tollfree_intra_15.ibd
Feb 5 08:31:14 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:14 [01] ...done
Feb 5 08:31:14 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:14 [01] Streaming ./opensips_2_2/emergency_report.ibd
Feb 5 08:31:14 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:14 [01] ...done
Feb 5 08:31:14 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:14 [01] Streaming ./opensips_2_2/cachedb.ibd
Feb 5 08:31:14 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:14 [01] ...done
Feb 5 08:31:14 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:14 [01] Streaming ./opensips_2_2/dr_partitions.ibd
Feb 5 08:31:14 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:14 [01] ...done
Feb 5 08:31:14 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:14 [01] Streaming ./opensips_2_2/dr_rules_intra_1.ibd
Feb 5 08:31:15 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:15 >> log scanned up to (118330830731)
Feb 5 08:31:16 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:16 >> log scanned up to (118330830731)
Feb 5 08:31:17 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:17 >> log scanned up to (118330830731)
Feb 5 08:31:18 wahoo-mariadb01 -innobackupex-backup: 2019-02-05 8:31:18 0 [Note] InnoDB: Read redo log up to LSN=118330830848
Feb 5 08:31:18 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:18 >> log scanned up to (118330830731)
Feb 5 08:31:18 wahoo-mariadb01 systemd[1]: mariadb.service: Got notification message from PID 1263, but reception only permitted for main PID 936
Feb 5 08:31:19 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:19 >> log scanned up to (118330830731)
Feb 5 08:31:20 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:20 >> log scanned up to (118330830731)
Feb 5 08:31:21 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:21 >> log scanned up to (118330830731)
Feb 5 08:31:22 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:22 >> log scanned up to (118330830731)
Feb 5 08:31:23 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:23 >> log scanned up to (118330830731)
Feb 5 08:31:24 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:24 >> log scanned up to (118330830731)
Feb 5 08:31:25 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:25 >> log scanned up to (118330830731)
Feb 5 08:31:26 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:26 >> log scanned up to (118330830731)
Feb 5 08:31:27 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:27 >> log scanned up to (118330830731)
Feb 5 08:31:28 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:28 >> log scanned up to (118330830731)
Feb 5 08:31:29 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:29 >> log scanned up to (118330830731)
Feb 5 08:31:30 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:30 >> log scanned up to (118330830731)
Feb 5 08:31:31 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:31 >> log scanned up to (118330830731)
Feb 5 08:31:32 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:32 >> log scanned up to (118330830731)
Feb 5 08:31:33 wahoo-mariadb01 -innobackupex-backup: 2019-02-05 8:31:33 0 [Note] InnoDB: Read redo log up to LSN=118330830848
Feb 5 08:31:33 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:33 >> log scanned up to (118330830731)
Feb 5 08:31:33 wahoo-mariadb01 systemd[1]: mariadb.service: Got notification message from PID 1263, but reception only permitted for main PID 936
Feb 5 08:31:34 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:34 >> log scanned up to (118330830731)
Feb 5 08:31:35 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:35 >> log scanned up to (118330830731)
Feb 5 08:31:36 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:36 >> log scanned up to (118330830731)
Feb 5 08:31:37 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:37 >> log scanned up to (118330830731)
Feb 5 08:31:38 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:38 >> log scanned up to (118330830731)
Feb 5 08:31:39 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:39 >> log scanned up to (118330830731)
Feb 5 08:31:40 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:40 >> log scanned up to (118330830731)
Feb 5 08:31:41 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:41 >> log scanned up to (118330830731)
Feb 5 08:31:42 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:42 >> log scanned up to (118330830731)
Feb 5 08:31:43 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:43 >> log scanned up to (118330830731)
Feb 5 08:31:44 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:44 >> log scanned up to (118330830731)
Feb 5 08:31:45 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:45 >> log scanned up to (118330830731)
Feb 5 08:31:46 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:46 >> log scanned up to (118330830731)
Feb 5 08:31:47 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:47 >> log scanned up to (118330830731)
Feb 5 08:31:48 wahoo-mariadb01 -innobackupex-backup: 2019-02-05 8:31:48 0 [Note] InnoDB: Read redo log up to LSN=118330830848
Feb 5 08:31:48 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:48 >> log scanned up to (118330830731)
Feb 5 08:31:48 wahoo-mariadb01 systemd[1]: mariadb.service: Got notification message from PID 1263, but reception only permitted for main PID 936
Feb 5 08:31:49 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:49 >> log scanned up to (118330830731)
Feb 5 08:31:50 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:50 >> log scanned up to (118330830731)
Feb 5 08:31:51 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:51 >> log scanned up to (118330830731)
Feb 5 08:31:52 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:52 >> log scanned up to (118330830731)
Feb 5 08:31:53 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:53 >> log scanned up to (118330830731)
Feb 5 08:31:54 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:54 >> log scanned up to (118330830731)
Feb 5 08:31:55 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:55 >> log scanned up to (118330830731)
Feb 5 08:31:56 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:56 >> log scanned up to (118330830731)
Feb 5 08:31:57 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:57 >> log scanned up to (118330830731)
Feb 5 08:31:58 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:58 >> log scanned up to (118330830731)
Feb 5 08:31:59 wahoo-mariadb01 -innobackupex-backup: 190205 08:31:59 >> log scanned up to (118330830731)
Feb 5 08:32:00 wahoo-mariadb01 -innobackupex-backup: 190205 08:32:00 >> log scanned up to (118330830731)
Feb 5 08:32:01 wahoo-mariadb01 -innobackupex-backup: 190205 08:32:01 >> log scanned up to (118330830731)
Feb 5 08:32:02 wahoo-mariadb01 -innobackupex-backup: 190205 08:32:02 >> log scanned up to (118330830731)
Feb 5 08:32:03 wahoo-mariadb01 -innobackupex-backup: 2019-02-05 8:32:03 0 [Note] InnoDB: Read redo log up to LSN=118330830848
Feb 5 08:32:03 wahoo-mariadb01 -innobackupex-backup: 190205 08:32:03 >> log scanned up to (118330830731)
Feb 5 08:32:03 wahoo-mariadb01 systemd[1]: mariadb.service: Got notification message from PID 1263, but reception only permitted for main PID 936
Feb 5 08:32:04 wahoo-mariadb01 -innobackupex-backup: 190205 08:32:04 >> log scanned up to (118330830731)
Feb 5 08:32:05 wahoo-mariadb01 -innobackupex-backup: 190205 08:32:05 >> log scanned up to (118330830731)
Feb 5 08:32:06 wahoo-mariadb01 -innobackupex-backup: 190205 08:32:06 >> log scanned up to (118330830731)
Feb 5 08:32:07 wahoo-mariadb01 -innobackupex-backup: 190205 08:32:07 >> log scanned up to (118330830731)
Feb 5 08:32:08 wahoo-mariadb01 -innobackupex-backup: 190205 08:32:08 >> log scanned up to (118330830731)
Feb 5 08:32:09 wahoo-mariadb01 -innobackupex-backup: 190205 08:32:09 >> log scanned up to (118330830731)
Feb 5 08:32:10 wahoo-mariadb01 -innobackupex-backup: 190205 08:32:10 >> log scanned up to (118330830731)
Feb 5 08:32:11 wahoo-mariadb01 -innobackupex-backup: 190205 08:32:11 >> log scanned up to (118330830731)
Feb 5 08:32:12 wahoo-mariadb01 -innobackupex-backup: 190205 08:32:12 >> log scanned up to (118330830731)
Feb 5 08:32:13 wahoo-mariadb01 -innobackupex-backup: 190205 08:32:13 >> log scanned up to (118330830731)
Feb 5 08:32:14 wahoo-mariadb01 -innobackupex-backup: 190205 08:32:14 >> log scanned up to (118330830731)
Feb 5 08:32:15 wahoo-mariadb01 -innobackupex-backup: 190205 08:32:15 >> log scanned up to (118330830731)
Feb 5 08:32:16 wahoo-mariadb01 -innobackupex-backup: 190205 08:32:16 >> log scanned up to (118330830731)
Feb 5 08:32:17 wahoo-mariadb01 -innobackupex-backup: 190205 08:32:17 >> log scanned up to (118330830731)
Feb 5 08:32:18 wahoo-mariadb01 -innobackupex-backup: 2019-02-05 8:32:18 0 [Note] InnoDB: Read redo log up to LSN=118330830848
Feb 5 08:32:18 wahoo-mariadb01 -innobackupex-backup: 190205 08:32:18 >> log scanned up to (118330830731)
Feb 5 08:32:18 wahoo-mariadb01 systemd[1]: mariadb.service: Got notification message from PID 1263, but reception only permitted for main PID 936
Feb 5 08:32:19 wahoo-mariadb01 -innobackupex-backup: 190205 08:32:19 >> log scanned up to (118330830731)
Feb 5 08:32:20 wahoo-mariadb01 -innobackupex-backup: 190205 08:32:20 >> log scanned up to (118330830731)
Feb 5 08:32:21 wahoo-mariadb01 -innobackupex-backup: 190205 08:32:21 >> log scanned up to (118330830731)
Feb 5 08:32:21 wahoo-mariadb01 -wsrep-sst-donor: 2019/02/05 08:32:21 socat[1264] E write(6, 0x556dab375d30, 8192): Broken pipe
Feb 5 08:32:21 wahoo-mariadb01 innobackupex-backup: #007-innobackupex: Error writing file 'UNKNOWN' (Errcode: 32 "Broken pipe")
Feb 5 08:32:21 wahoo-mariadb01 -innobackupex-backup: xb_stream_write_data() failed.
Feb 5 08:32:21 wahoo-mariadb01 innobackupex-backup: #007-innobackupex: Error writing file 'UNKNOWN' (Errcode: 32 "Broken pipe")
Feb 5 08:32:21 wahoo-mariadb01 -innobackupex-backup: [01] mariabackup: Error: xtrabackup_copy_datafile() failed.
Feb 5 08:32:21 wahoo-mariadb01 -innobackupex-backup: [01] mariabackup: Error: failed to copy datafile.
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:32:21 12 [Warning] Aborted connection 12 to db: 'unconnected' user: 'mariabackup' host: 'localhost' (Got an error reading communication packets)
Feb 5 08:32:21 wahoo-mariadb01 -wsrep-sst-donor: mariabackup finished with error: 1. Check /var/lib/mysql//innobackup.backup.log
Feb 5 08:32:21 wahoo-mariadb01 -wsrep-sst-donor: Cleanup after exit with status:22
Feb 5 08:32:21 wahoo-mariadb01 -wsrep-sst-donor: Cleaning up temporary directories
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:32:21 0 [ERROR] WSREP: Failed to read from: wsrep_sst_mariabackup --role 'donor' --address '192.168.20.94:4444/xtrabackup_sst//1' --socket '/var/run/mysqld/mysqld.sock' --datadir '/var/lib/mysql/' --binlog '/var/log/mysql/mariadb-bin' --gtid '70fd14be-28af-11e9-8aa7-ff8340dcc35e:22022' --gtid-domain-id '0'
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:32:21 0 [ERROR] WSREP: Process completed with error: wsrep_sst_mariabackup --role 'donor' --address '192.168.20.94:4444/xtrabackup_sst//1' --socket '/var/run/mysqld/mysqld.sock' --datadir '/var/lib/mysql/' --binlog '/var/log/mysql/mariadb-bin' --gtid '70fd14be-28af-11e9-8aa7-ff8340dcc35e:22022' --gtid-domain-id '0': 22 (Invalid argument)
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:32:21 0 [ERROR] WSREP: Command did not run: wsrep_sst_mariabackup --role 'donor' --address '192.168.20.94:4444/xtrabackup_sst//1' --socket '/var/run/mysqld/mysqld.sock' --datadir '/var/lib/mysql/' --binlog '/var/log/mysql/mariadb-bin' --gtid '70fd14be-28af-11e9-8aa7-ff8340dcc35e:22022' --gtid-domain-id '0'
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:32:21 0 [Warning] WSREP: 0.0 (wahoo-mariadb01): State transfer to 3.0 (wahoo-mariadb04) failed: -22 (Invalid argument)
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:32:21 0 [Note] WSREP: Shifting DONOR/DESYNCED -> JOINED (TO: 22022)
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:32:21 0 [Note] WSREP: (7b0a3f9e, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers: tcp://192.168.20.94:4567
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:32:21 0 [Note] WSREP: declaring 812e8278 at tcp://192.168.20.93:4567 stable
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:32:21 0 [Note] WSREP: declaring 99aa2eea at tcp://192.168.20.92:4567 stable
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:32:21 0 [Note] WSREP: forgetting a37ce3d6 (tcp://192.168.20.94:4567)
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:32:21 0 [Note] WSREP: (7b0a3f9e, 'tcp://0.0.0.0:4567') turning message relay requesting off
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:32:21 0 [Note] WSREP: Node 7b0a3f9e state prim
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:32:21 0 [Note] WSREP: view(view_id(PRIM,7b0a3f9e,19) memb

{ Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: #0117b0a3f9e,0 Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: #011812e8278,0 Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: #01199aa2eea,0 Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: }

joined

{ Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: }

left

{ Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: }

partitioned

{ Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: #011a37ce3d6,0 Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: }

)
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:32:21 0 [Note] WSREP: save pc into disk
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:32:21 0 [Note] WSREP: forgetting a37ce3d6 (tcp://192.168.20.94:4567)
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:32:21 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 3
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:32:21 0 [Note] WSREP: STATE_EXCHANGE: sent state UUID: d91f07e0-2952-11e9-b7a1-e26eaf60f82c
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:32:21 0 [Warning] WSREP: SYNC message from member 0 in non-primary configuration. Ignored.
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:32:21 0 [Note] WSREP: STATE EXCHANGE: sent state msg: d91f07e0-2952-11e9-b7a1-e26eaf60f82c
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:32:21 0 [Note] WSREP: STATE EXCHANGE: got state msg: d91f07e0-2952-11e9-b7a1-e26eaf60f82c from 0 (wahoo-mariadb01)
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:32:21 0 [Note] WSREP: STATE EXCHANGE: got state msg: d91f07e0-2952-11e9-b7a1-e26eaf60f82c from 1 (wahoo-mariadb03)
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:32:21 0 [Note] WSREP: STATE EXCHANGE: got state msg: d91f07e0-2952-11e9-b7a1-e26eaf60f82c from 2 (wahoo-mariadb02)
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:32:21 0 [Note] WSREP: Quorum results:
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: #011version = 4,
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: #011component = PRIMARY,
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: #011conf_id = 18,
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: #011members = 3/3 (joined/total),
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: #011act_id = 22022,
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: #011last_appl. = 0,
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: #011protocols = 0/9/3 (gcs/repl/appl),
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: #011group UUID = 70fd14be-28af-11e9-8aa7-ff8340dcc35e
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:32:21 0 [Note] WSREP: Flow-control interval: [28, 28]
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:32:21 0 [Note] WSREP: Trying to continue unpaused monitor
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:32:21 2 [Note] WSREP: New cluster view: global state: 70fd14be-28af-11e9-8aa7-ff8340dcc35e:22022, view# 19: Primary, number of nodes: 3, my index: 0, protocol version 3
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:32:21 2 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:32:21 2 [Note] WSREP: REPL Protocols: 9 (4, 2)
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:32:21 2 [Note] WSREP: Assign initial position for certification: 22022, protocol version: 4
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:32:21 0 [Note] WSREP: Service thread queue flushed.
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:32:21 0 [Note] WSREP: Member 0.0 (wahoo-mariadb01) synced with group.
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:32:21 0 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 22022)
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:32:21 2 [Note] WSREP: Synchronized with group, ready for connections
Feb 5 08:32:21 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:32:21 2 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
Feb 5 08:32:27 wahoo-mariadb01 mysqld[936]: 2019-02-05 8:32:27 0 [Note] WSREP: cleaning up a37ce3d6 (tcp://192.168.20.94:4567)



 Comments   
Comment by Pat Burke [ 2019-02-14 ]

Looking deeper, I realized that the issue was the service start on the JOINER was timing out.

I added TimeoutSec=infinity to the bottom of the file

/etc/systemd/system/mariadb.service.d/migrated-from-my.cnf-settings.conf

The problem is resolved.

Comment by raj [ 2019-05-03 ]

Hi Pat ,

We had same issue in our testing cluster while doing SST between nodes. Could you confirm us as SST is working fine now from your end?
The version that we tried was 10.3.14 .

Thanks,

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