I upgraded all servers from 10.3.x to 10.4.x. mysql1 and mysql2 were upgraded successfully however, mysql3 was accidentally upgraded to a much more recent build. All mysql servers are lxc hosted. mysql3 container has been destroyed, data removed, and rebuilt.
All servers are:
Ubuntu 18.04.06
Mariadb 10.4.26
Galara 26.4.12
This log is mysql3 attempting to join the cluster. I can confirm wsrep_cluster_status is good on both nodes, here is a sample from mysql1
mysql -e "SHOW VARIABLES LIKE 'wsrep_node_name';"
+-----------------+----------------------------------+
| Variable_name | Value |
+-----------------+----------------------------------+
| wsrep_node_name | mysql1_galera_container-51a7dea5 |
+-----------------+----------------------------------+
mysql -e "show status like 'wsrep_cluster_status';"
+----------------------+---------+
| Variable_name | Value |
+----------------------+---------+
| wsrep_cluster_status | Primary |
+----------------------+---------+
I have confirmed the permissions are correct, by reviewing and confirming the instructions in this article.
/etc/mysql/my.conf
[client]
port = 3306
socket = "/var/run/mysqld/mysqld.sock"
[mysqld_safe]
socket = "/var/run/mysqld/mysqld.sock"
nice = 0
[mysql]
default-character-set = utf8
[mysqld]
user = mysql
collation-server = utf8_general_ci
init-connect = 'SET NAMES utf8'
character-set-server = utf8
datadir = /var/lib/mysql
tmpdir = /var/lib/mysql/#tmp
ignore_db_dirs = '#tmp',lost+found
bind-address = 10.194.54.143
server-id = 2338
ssl
ssl-ca = /etc/ssl/certs/galera-ca.pem
ssl-cert = /etc/ssl/certs/galera.pem
ssl-key = /etc/mysql/ssl/galera.key
# LOGGING #
log-queries-not-using-indexes = 0
slow-query-log = 0
slow_query_log_file = /var/log/mysql/mariadb-slow.log
log-bin = /var/lib/mysql/mariadb-bin
log-bin-index = /var/lib/mysql/mariadb-bin.index
expire-logs-days = 7
log_slave_updates = 1
log_bin_trust_function_creators = 1
# MONITORING #
# extra_port = 3307
# extra_max_connections = 10
# SAFETY #
max-allowed-packet = 16M
max-connect-errors = 1000000
# NOTE = If galera_max_connections is not configured by user, the number of max
# connections is defined by ( host_vcpus * 100 ) with a capping value of 1600.
# This value is the lowest integer based on the ansible facts gathered from
# every galera node.
# Computing the connections value using the lowest denominator maintains
# cluster integrity by not attempting to over commit to a less capable machine.
# These are the computed max_connections based on the cluster data
# [200, 200, 1600]
max_connections = 1600
wait_timeout = 600
# CACHES AND LIMITS #
tmp-table-size = 32M
max-heap-table-size = 32M
query-cache-type = 0
query-cache-size = 0M
thread-cache-size = 50
open-files-limit = 164679
table-definition-cache = 4096
table-open-cache = 10240
# INNODB #
innodb-flush-method = O_DIRECT
innodb-log-file-size = 1024M
innodb-flush-log-at-trx-commit = 1
innodb-file-per-table = 1
innodb-buffer-pool-size = 4096M
# Depending on number of cores and disk sub
innodb-read-io-threads = 4
innodb-write-io-threads = 4
innodb-doublewrite = 1
innodb-log-buffer-size = 128M
# avoid statistics update when doing e.g show tables
innodb_stats_on_metadata = 0
[mysqldump]
quick
quote-names
max_allowed_packet = 16M
!includedir /etc/mysql/conf.d/
/etc/mysql/conf.d/cluster.cnf
[mysqld]
wsrep_on = ON
# Path to Galera library
wsrep_provider = /usr/lib/galera/libgalera_smm.so
wsrep_provider_options = "gcache.size = 1024M; gmcast.listen_addr = tcp://10.10.10.143:4567"
# Cluster connection URL contains the IPs of node#1, node#2 and node#3
wsrep_cluster_address = gcomm://10.10.10.216,10.10.10.48,10.10.10.143
# Address for incoming client connections.
wsrep_node_incoming_address = 10.10.10.143
# In order for Galera to work correctly binlog format should be ROW
binlog_format = ROW
# MyISAM storage engine has only experimental support
default_storage_engine = InnoDB
# This changes how InnoDB autoincrement locks are managed and is a requirement for Galera
innodb_autoinc_lock_mode = 2
# This should be the IP and DNS name for the current system on which you're editing the file.
wsrep_node_address = 10.194.54.143
wsrep_node_name = mysql3_galera_container-313ea92d
# to enable debug level logging, set this to 1
wsrep_debug = NONE
# SST method
wsrep_sst_method = mariabackup
wsrep_sst_auth = username:password
wsrep_slave_threads = 16
# Cluster name
wsrep_cluster_name = "openstack_galera_cluster"
# how many times to retry deadlocked autocommits
wsrep_retry_autocommit = 3
[mariabackup]
parallel = 4
mysql3 attempting and failing to join cluster.
Starting MariaDB 10.4.26 database server...
WSREP: Recovered position 00000000-0000-0000-0000-000000000000:-1
2023-01-18 14:08:03 0 [Note] /usr/sbin/mysqld (mysqld 10.4.26-MariaDB-1:10.4.26+maria~ubu1804-log) starting as process 233086 ...
2023-01-18 14:08:03 0 [Warning] Could not increase number of max_open_files to more than 164679 (request: 165503)
2023-01-18 14:08:03 0 [Note] WSREP: Loading provider /usr/lib/galera/libgalera_smm.so initial position: 00000000-0000-0000-0000-000000000000:-1
2023-01-18 14:08:03 0 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib/galera/libgalera_smm.so'
2023-01-18 14:08:03 0 [Note] WSREP: wsrep_load(): Galera 26.4.12(r1eac5b64) by Codership Oy <[email protected]> loaded successfully.
2023-01-18 14:08:03 0 [Note] WSREP: CRC-32C: using 64-bit x86 acceleration.
2023-01-18 14:08:03 0 [Note] WSREP: Found saved state: 00000000-0000-0000-0000-000000000000:-1, safe_to_bootstrap: 1
2023-01-18 14:08:03 0 [Note] WSREP: GCache DEBUG: opened preamble:
Version: 2
UUID: c283d05d-bcbc-11ea-9b28-2ab976fb3286
Seqno: -1 - -1
Offset: -1
Synced: 0
2023-01-18 14:08:03 0 [Note] WSREP: Recovering GCache ring buffer: version: 2, UUID: c283d05d-bcbc-11ea-9b28-2ab976fb3286, offset: -1
2023-01-18 14:08:03 0 [Note] WSREP: GCache::RingBuffer initial scan... 0.0% ( 0/1073741848 bytes) complete.
2023-01-18 14:08:03 0 [Note] WSREP: GCache::RingBuffer initial scan...100.0% (1073741848/1073741848 bytes) complete.
2023-01-18 14:08:03 0 [Note] WSREP: Recovering GCache ring buffer: Recovery failed, need to do full reset.
2023-01-18 14:08:03 0 [Note] WSREP: Passing config to GCS: base_dir = /var/lib/mysql/; base_host = 10.10.10.143; 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.keep_plaintext_size = 128M; gcache.mem_size = 0; gcache.name = galera.cache; gcache.page_size = 128M; gcache.recover = yes; gcache.size = 1024M; gcomm.thread_prio = ; gcs.fc_debug = 0; gcs.fc_factor = 1.0; gcs.fc_limit = 16; gcs.fc_master_slave = no; gcs.fc_single_primary = 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.listen_add
2023-01-18 14:08:03 0 [Note] WSREP: Start replication
2023-01-18 14:08:03 0 [Note] WSREP: Connecting with bootstrap option: 0
2023-01-18 14:08:03 0 [Note] WSREP: Setting GCS initial position to 00000000-0000-0000-0000-000000000000:-1
2023-01-18 14:08:03 0 [Note] WSREP: protonet asio version 0
2023-01-18 14:08:03 0 [Note] WSREP: Using CRC-32C for message checksums.
2023-01-18 14:08:03 0 [Note] WSREP: backend: asio
2023-01-18 14:08:03 0 [Note] WSREP: gcomm thread scheduling priority set to other:0
2023-01-18 14:08:03 0 [Note] WSREP: access file(/var/lib/mysql//gvwstate.dat) failed(No such file or directory)
2023-01-18 14:08:03 0 [Note] WSREP: restore pc from disk failed
2023-01-18 14:08:03 0 [Note] WSREP: GMCast version 0
2023-01-18 14:08:03 0 [Note] WSREP: (85fccb0c-9317, 'tcp://10.10.10.143:4567') listening at tcp://10.10.10.143:4567
2023-01-18 14:08:03 0 [Note] WSREP: (85fccb0c-9317, 'tcp://10.10.10.143:4567') multicast: , ttl: 1
2023-01-18 14:08:03 0 [Note] WSREP: EVS version 1
2023-01-18 14:08:03 0 [Note] WSREP: gcomm: connecting to group 'openstack_galera_cluster', peer '10.10.10.216:,10.10.10.48:,10.10.10.143:'
2023-01-18 14:08:03 0 [Note] WSREP: (85fccb0c-9317, 'tcp://10.10.10.143:4567') connection established to 55e12e71-a776 tcp://10.10.10.216:4567
2023-01-18 14:08:03 0 [Note] WSREP: (85fccb0c-9317, 'tcp://10.10.10.143:4567') turning message relay requesting on, nonlive peers:
2023-01-18 14:08:03 0 [Note] WSREP: (85fccb0c-9317, 'tcp://10.10.10.143:4567') connection established to 5782ef3d-ab18 tcp://10.10.10.48:4567
2023-01-18 14:08:04 0 [Note] WSREP: EVS version upgrade 0 -> 1
2023-01-18 14:08:04 0 [Note] WSREP: declaring 55e12e71-a776 at tcp://10.10.10.216:4567 stable
2023-01-18 14:08:04 0 [Note] WSREP: declaring 5782ef3d-ab18 at tcp://10.10.10.48:4567 stable
2023-01-18 14:08:04 0 [Note] WSREP: PC protocol upgrade 0 -> 1
2023-01-18 14:08:04 0 [Note] WSREP: Node 55e12e71-a776 state prim
2023-01-18 14:08:04 0 [Note] WSREP: view(view_id(PRIM,55e12e71-a776,65211) memb {
55e12e71-a776,0
5782ef3d-ab18,0
85fccb0c-9317,0
} joined {
} left {
} partitioned {
})
2023-01-18 14:08:04 0 [Note] WSREP: save pc into disk
2023-01-18 14:08:04 0 [Note] WSREP: gcomm: connected
2023-01-18 14:08:04 0 [Note] WSREP: Changing maximum packet size to 64500, resulting msg size: 32636
2023-01-18 14:08:04 0 [Note] WSREP: Shifting CLOSED -> OPEN (TO: 0)
2023-01-18 14:08:04 0 [Note] WSREP: Opened channel 'openstack_galera_cluster'
2023-01-18 14:08:04 0 [Note] WSREP: New COMPONENT: primary = yes, bootstrap = no, my_idx = 2, memb_num = 3
2023-01-18 14:08:04 0 [Note] WSREP: STATE EXCHANGE: Waiting for state UUID.
2023-01-18 14:08:04 0 [Note] WSREP: STATE EXCHANGE: sent state msg: 7b753128-9739-11ed-b165-f650c15358d1
2023-01-18 14:08:04 0 [Note] WSREP: STATE EXCHANGE: got state msg: 7b753128-9739-11ed-b165-f650c15358d1 from 0 (mysql2_galera_container-82f5f218)
2023-01-18 14:08:04 0 [Note] WSREP: STATE EXCHANGE: got state msg: 7b753128-9739-11ed-b165-f650c15358d1 from 1 (mysql1_galera_container-51a7dea5)
2023-01-18 14:08:04 1 [Note] WSREP: Starting rollbacker thread 1
2023-01-18 14:08:04 2 [Note] WSREP: Starting applier thread 2
2023-01-18 14:08:04 0 [Note] WSREP: STATE EXCHANGE: got state msg: 7b753128-9739-11ed-b165-f650c15358d1 from 2 (mysql3_galera_container-313ea92d)
2023-01-18 14:08:04 0 [Note] WSREP: Quorum results:
version = 6,
component = PRIMARY,
conf_id = 172,
members = 2/3 (joined/total),
act_id = 818657481,
last_appl. = 818657096,
protocols = 2/10/4 (gcs/repl/appl),
vote policy= 0,
group UUID = c283d05d-bcbc-11ea-9b28-2ab976fb3286
2023-01-18 14:08:04 0 [Note] WSREP: Flow-control interval: [28, 28]
2023-01-18 14:08:04 0 [Note] WSREP: Shifting OPEN -> PRIMARY (TO: 818657482)
2023-01-18 14:08:04 2 [Note] WSREP: ####### processing CC 818657482, local, ordered
2023-01-18 14:08:04 2 [Note] WSREP: Process first view: c283d05d-bcbc-11ea-9b28-2ab976fb3286 my uuid: 85fccb0c-9739-11ed-9317-422787e494fc
2023-01-18 14:08:04 2 [Note] WSREP: Server mysql3_galera_container-313ea92d connected to cluster at position c283d05d-bcbc-11ea-9b28-2ab976fb3286:818657482 with ID 85fccb0c-9739-11ed-9317-422787e494fc
2023-01-18 14:08:04 2 [Note] WSREP: Server status change disconnected -> connected
2023-01-18 14:08:04 2 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2023-01-18 14:08:04 2 [Note] WSREP: ####### My UUID: 85fccb0c-9739-11ed-9317-422787e494fc
2023-01-18 14:08:04 2 [Note] WSREP: Cert index reset to 00000000-0000-0000-0000-000000000000:-1 (proto: 10), state transfer needed: yes
2023-01-18 14:08:04 0 [Note] WSREP: Service thread queue flushed.
2023-01-18 14:08:04 2 [Note] WSREP: ####### Assign initial position for certification: 00000000-0000-0000-0000-000000000000:-1, protocol version: -1
2023-01-18 14:08:04 2 [Note] WSREP: State transfer required:
Group state: c283d05d-bcbc-11ea-9b28-2ab976fb3286:818657482
Local state: 00000000-0000-0000-0000-000000000000:-1
2023-01-18 14:08:04 2 [Note] WSREP: Server status change connected -> joiner
2023-01-18 14:08:04 2 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2023-01-18 14:08:04 0 [Note] WSREP: Joiner monitor thread started to monitor
2023-01-18 14:08:04 0 [Note] WSREP: Running: 'wsrep_sst_mariabackup --role 'joiner' --address '10.10.10.143' --datadir '/var/lib/mysql/' --parent 233086 --progress 0 --binlog '/var/lib/mysql/mariadb-bin' --binlog-index '/var/lib/mysql/mariadb-bin.index' --mysqld-args --wsrep_start_position=00000000-0000-0000-0000-000000000000:-1'
WSREP_SST: [INFO] mariabackup SST started on joiner (20230118 14:08:04.565)
WSREP_SST: [INFO] SSL configuration: CA='', CAPATH='', CERT='', KEY='', MODE='DISABLED', encrypt='0' (20230118 14:08:04.626)
WSREP_SST: [INFO] Progress reporting tool pv not found in path: /usr//bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/sbin:/usr/bin:/sbin:/bin (20230118 14:08:04.770)
WSREP_SST: [INFO] Disabling all progress/rate-limiting (20230118 14:08:04.773)
WSREP_SST: [INFO] Streaming with mbstream (20230118 14:08:04.798)
WSREP_SST: [INFO] Using socat as streamer (20230118 14:08:04.801)
WSREP_SST: [INFO] Evaluating timeout -k 310 300 socat -u TCP-LISTEN:4444,reuseaddr stdio | '/usr//bin/mbstream' -x; RC=( ${PIPESTATUS[@]} ) (20230118 14:08:04.850)
2023-01-18 14:08:05 2 [Note] WSREP: ####### IST uuid:00000000-0000-0000-0000-000000000000 f: 0, l: 818657482, STRv: 3
2023-01-18 14:08:05 2 [Note] WSREP: IST receiver addr using tcp://10.10.10.143:4568
2023-01-18 14:08:05 2 [Note] WSREP: Prepared IST receiver for 0-818657482, listening at: tcp://10.10.10.143:4568
2023-01-18 14:08:05 0 [Note] WSREP: Member 2.0 (mysql3_galera_container-313ea92d) requested state transfer from '*any*'. Selected 0.0 (mysql2_galera_container-82f5f218)(SYNCED) as donor.
2023-01-18 14:08:05 0 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 818657490)
2023-01-18 14:08:05 2 [Note] WSREP: Requesting state transfer: success, donor: 0
2023-01-18 14:08:05 2 [Note] WSREP: Resetting GCache seqno map due to different histories.
2023-01-18 14:08:05 2 [Note] WSREP: GCache history reset: c283d05d-bcbc-11ea-9b28-2ab976fb3286:0 -> c283d05d-bcbc-11ea-9b28-2ab976fb3286:818657482
WSREP_SST: [INFO] WARNING: Stale temporary SST directory: '/var/lib/mysql/.sst' from previous state transfer, removing... (20230118 14:08:05.432)
WSREP_SST: [INFO] Evaluating socat -u TCP-LISTEN:4444,reuseaddr stdio | '/usr//bin/mbstream' -x; RC=( ${PIPESTATUS[@]} ) (20230118 14:08:05.440)
WSREP_SST: [INFO] Proceeding with SST (20230118 14:08:05.448)
WSREP_SST: [INFO] Cleaning the old binary logs (20230118 14:08:05.489)
WSREP_SST: [INFO] Cleaning the existing datadir and innodb-data/log directories (20230118 14:08:05.513)
WSREP_SST: [INFO] Waiting for SST streaming to complete! (20230118 14:08:05.528)
2023-01-18 14:08:07 0 [Note] WSREP: (85fccb0c-9317, 'tcp://10.10.10.143:4567') turning message relay requesting off
Terminated
WSREP_SST: [ERROR] Cleanup after exit with status: 3 (20230118 14:08:09.898)
WSREP_SST: [ERROR] Removing /var/lib/mysql/.sst/xtrabackup_galera_info file due to signal (20230118 14:08:09.904)
WSREP_SST: [INFO] Removing the sst_in_progress file (20230118 14:08:09.908)
WSREP_SST: [INFO] Cleaning up temporary directories (20230118 14:08:09.913)
2023-01-18 14:08:09 0 [ERROR] WSREP: Process was aborted.
2023-01-18 14:08:09 0 [ERROR] WSREP: Process completed with error: wsrep_sst_mariabackup --role 'joiner' --address '10.10.10.143' --datadir '/var/lib/mysql/' --parent 233086 --progress 0 --binlog '/var/lib/mysql/mariadb-bin' --binlog-index '/var/lib/mysql/mariadb-bin.index' --mysqld-args --wsrep_start_position=00000000-0000-0000-0000-000000000000:-1: 2 (No such file or directory)
2023-01-18 14:08:09 0 [ERROR] WSREP: Failed to read uuid:seqno and wsrep_gtid_domain_id from joiner script.
2023-01-18 14:08:09 3 [Note] WSREP: SST received
2023-01-18 14:08:09 3 [Note] WSREP: SST received: 00000000-0000-0000-0000-000000000000:-1
2023-01-18 14:08:09 3 [Note] WSREP: SST succeeded for position 00000000-0000-0000-0000-000000000000:-1
2023-01-18 14:08:09 0 [Note] WSREP: Joiner monitor thread ended with total time 5 sec
2023-01-18 14:08:09 2 [ERROR] WSREP: Application received wrong state:
Received: 00000000-0000-0000-0000-000000000000
Required: c283d05d-bcbc-11ea-9b28-2ab976fb3286
2023-01-18 14:08:09 2 [ERROR] WSREP: Application state transfer failed. This is unrecoverable condition, restart required.
2023-01-18 14:08:09 2 [Note] WSREP: ReplicatorSMM::abort()
2023-01-18 14:08:09 2 [Note] WSREP: Closing send monitor...
2023-01-18 14:08:09 2 [Note] WSREP: Closed send monitor.
2023-01-18 14:08:09 2 [Note] WSREP: gcomm: terminating thread
2023-01-18 14:08:09 2 [Note] WSREP: gcomm: joining thread
2023-01-18 14:08:09 2 [Note] WSREP: gcomm: closing backend
2023-01-18 14:08:09 2 [Note] WSREP: view(view_id(NON_PRIM,55e12e71-a776,65211) memb {
85fccb0c-9317,0
} joined {
} left {
} partitioned {
55e12e71-a776,0
5782ef3d-ab18,0
})
2023-01-18 14:08:09 2 [Note] WSREP: PC protocol downgrade 1 -> 0
2023-01-18 14:08:09 2 [Note] WSREP: view((empty))
2023-01-18 14:08:09 2 [Note] WSREP: gcomm: closed
2023-01-18 14:08:09 0 [Note] WSREP: New COMPONENT: primary = no, bootstrap = no, my_idx = 0, memb_num = 1
2023-01-18 14:08:09 0 [Note] WSREP: Flow-control interval: [16, 16]
2023-01-18 14:08:09 0 [Note] WSREP: Received NON-PRIMARY.
2023-01-18 14:08:09 0 [Note] WSREP: Shifting JOINER -> OPEN (TO: 818657513)
2023-01-18 14:08:09 0 [Note] WSREP: New SELF-LEAVE.
2023-01-18 14:08:09 0 [Note] WSREP: Flow-control interval: [0, 0]
2023-01-18 14:08:09 0 [Note] WSREP: Received SELF-LEAVE. Closing connection.
2023-01-18 14:08:09 0 [Note] WSREP: Shifting OPEN -> CLOSED (TO: 818657513)
2023-01-18 14:08:09 0 [Note] WSREP: RECV thread exiting 0: Success
2023-01-18 14:08:09 2 [Note] WSREP: recv_thread() joined.
2023-01-18 14:08:09 2 [Note] WSREP: Closing replication queue.
2023-01-18 14:08:09 2 [Note] WSREP: Closing slave action queue.
2023-01-18 14:08:09 2 [Note] WSREP: /usr/sbin/mysqld: Terminated.
