We are using percona-xtradb-cluster 1:8.0.29-21-1.focal in Ubuntu-20.04 docker containers.
The etcd service is a discovery module.
On this version, synchronization between nodes works fine, during initialization, the second and third nodes are connected to the first one via SST.
We are trying to upgrade to version 1:8.0.32-24-1.focal.
The first node starts fine, but when the subsequent nodes start, an SST exception occurs.
We tried other versions of percona-xtradb-cluster, this error occurs starting from 1:8.0.31-23-1.focal.
Log:
2023-04-20T08:31:43.348413Z 0 [Warning] [MY-011069] [Server] The syntax ‘–transaction-write-set-extraction’ is deprecated and will be removed in a future release.
2023-04-20T08:31:43.349580Z 0 [Warning] [MY-010101] [Server] Insecure configuration for --secure-file-priv: Location is accessible to all OS users. Consider choosing a different directory.
2023-04-20T08:31:43.349589Z 0 [Warning] [MY-010097] [Server] Insecure configuration for --secure-log-path: Current value does not restrict location of generated files. Consider setting it to a valid, non-empty path.
2023-04-20T08:31:43.350172Z 0 [Warning] [MY-010918] [Server] ‘default_authentication_plugin’ is deprecated and will be removed in a future release. Please use authentication_policy instead.
2023-04-20T08:31:43.350198Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 8.0.31-23.1) starting as process 7499
2023-04-20T08:31:43.352402Z 0 [Note] [MY-000000] [WSREP] Server initial position: 00000000-0000-0000-0000-000000000000:-1
2023-04-20T08:31:43.352514Z 0 [Note] [MY-000000] [Galera] Loading provider /usr/lib/galera4/libgalera_smm.so initial position: 00000000-0000-0000-0000-000000000000:-1
2023-04-20T08:31:43.352532Z 0 [Note] [MY-000000] [Galera] wsrep_load(): loading provider library ‘/usr/lib/galera4/libgalera_smm.so’
2023-04-20T08:31:43.353032Z 0 [Note] [MY-000000] [Galera] wsrep_load(): Galera 4.13(2957c7e) by Codership Oy info@codership.com (modified by Percona https://percona.com/) loaded successfully.
2023-04-20T08:31:43.353055Z 0 [Note] [MY-000000] [Galera] CRC-32C: using 64-bit x86 acceleration.
2023-04-20T08:31:43.353261Z 0 [Note] [MY-000000] [Galera] Found saved state: 00000000-0000-0000-0000-000000000000:-1, safe_to_bootstrap: 1
2023-04-20T08:31:43.353351Z 0 [Note] [MY-000000] [Galera] GCache DEBUG: opened preamble:
Version: 2
UUID: 084297fa-df4e-11ed-a52f-cbc3c5236e5f
Seqno: -1 - -1
Offset: -1
Synced: 0
EncVersion: 1
Encrypted: 0
MasterKeyConst UUID: ce5db785-df51-11ed-9f71-22e55df0eee6
MasterKey UUID: 00000000-0000-0000-0000-000000000000
MasterKey ID: 0
2023-04-20T08:31:43.353368Z 0 [Note] [MY-000000] [Galera] Recovering GCache ring buffer: version: 2, UUID: 084297fa-df4e-11ed-a52f-cbc3c5236e5f, offset: -1
2023-04-20T08:31:43.353420Z 0 [Note] [MY-000000] [Galera] GCache::RingBuffer initial scan… 0.0% ( 0/134217752 bytes) complete.
2023-04-20T08:31:43.402686Z 0 [Note] [MY-000000] [Galera] GCache::RingBuffer initial scan…100.0% (134217752/134217752 bytes) complete.
2023-04-20T08:31:43.402710Z 0 [Note] [MY-000000] [Galera] Recovering GCache ring buffer: Recovery failed, need to do full reset.
2023-04-20T08:31:43.403104Z 0 [Note] [MY-000000] [Galera] Complete reset of the galera cache
2023-04-20T08:31:43.454809Z 0 [Note] [MY-000000] [Galera] Flushing memory map to disk…
2023-04-20T08:31:44.103933Z 0 [Note] [MY-000000] [Galera] Passing config to GCS: allocator.disk_pages_encryption = no; allocator.encryption_cache_page_size = 32K; allocator.encryption_cache_size = 16777216; base_dir = /var/lib/mysql/mysql_data/; base_host = 192.168.4.123; base_port = 4567; cert.log_conflicts = no; cert.optimistic_pa = 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 = 10; evs.stats_report_period = PT1M; evs.suspect_timeout = PT5S; evs.user_send_window = 4; evs.view_forget_timeout = PT24H; gcache.dir = /var/lib/mysql/mysql_data/; gcache.encryption = no; gcache.encryption_cache_page_size = 32K; gcache.encryption_cache_size = 16777216; gcache.freeze_purge_at_seqno = -1; gcache.keep_pages_count = 0; gcache.keep_pages_size = 0; gcache.mem_size = 0; gcache.name = galera.cache; gcache.page_size = 128M; gcache.recover = yes; gcache.size = 128M; gcomm.thread_prio = ; gcs.fc_debug = 0; gcs.fc_factor = 1.0; gcs.fc_limit = 100; 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.segment = 0; gmcast.version = 0; pc.announce_timeout = PT3S; pc.checksum = false; pc.ignore_quorum = false; pc.ignore_sb = false; pc.npvo = false; pc.recovery = true; pc.version = 0; pc.wait_prim = true; pc.wait_prim_timeout = PT30S; pc.weight = 1; protonet.backend = asio; protonet.version = 0; repl.causal_read_timeout = PT30S; repl.commit_order = 3; repl.key_format = FLAT8; repl.max_ws_size = 2147483647; repl.proto_max = 10; socket.checksum = 2; socket.recv_buf_size = auto; socket.send_buf_size = auto;
2023-04-20T08:31:44.132802Z 0 [Note] [MY-000000] [WSREP] refresh_provider_options: allocator.disk_pages_encryption = no; allocator.encryption_cache_page_size = 32K; allocator.encryption_cache_size = 16777216; base_dir = /var/lib/mysql/mysql_data/; base_host = 192.168.4.123; base_port = 4567; cert.log_conflicts = no; cert.optimistic_pa = 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 = 10; evs.stats_report_period = PT1M; evs.suspect_timeout = PT5S; evs.user_send_window = 4; evs.view_forget_timeout = PT24H; gcache.dir = /var/lib/mysql/mysql_data/; gcache.encryption = no; gcache.encryption_cache_page_size = 32K; gcache.encryption_cache_size = 16777216; gcache.freeze_purge_at_seqno = -1; gcache.keep_pages_count = 0; gcache.keep_pages_size = 0; gcache.mem_size = 0; gcache.name = galera.cache; gcache.page_size = 128M; gcache.recover = yes; gcache.size = 128M; gcomm.thread_prio = ; gcs.fc_debug = 0; gcs.fc_factor = 1.0; gcs.fc_limit = 100; 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.segment = 0; gmcast.version = 0; ist.recv_addr = 192.168.4.123; pc.announce_timeout = PT3S; pc.checksum = false; pc.ignore_quorum = false; pc.ignore_sb = false; pc.npvo = false; pc.recovery = true; pc.version = 0; pc.wait_prim = true; pc.wait_prim_timeout = PT30S; pc.weight = 1; protonet.backend = asio; protonet.version = 0; repl.causal_read_timeout = PT30S; repl.commit_order = 3; repl.key_format = FLAT8; repl.max_ws_size = 2147483647; repl.proto_max = 10; socket.checksum = 2; socket.recv_buf_size = auto; socket.send_buf_size = auto;
2023-04-20T08:31:44.132874Z 0 [Note] [MY-000000] [WSREP] SR storage init for: table
2023-04-20T08:31:44.132895Z 0 [Note] [MY-000000] [WSREP] wsrep_start_replication
2023-04-20T08:31:44.132909Z 0 [Note] [MY-000000] [WSREP] Starting replication
2023-04-20T08:31:44.132930Z 0 [Note] [MY-000000] [Galera] Connecting with bootstrap option: 0
2023-04-20T08:31:44.132959Z 0 [Note] [MY-000000] [Galera] Setting GCS initial position to 00000000-0000-0000-0000-000000000000:-1
2023-04-20T08:31:44.133069Z 0 [Note] [MY-000000] [Galera] protonet asio version 0
2023-04-20T08:31:44.133159Z 0 [Note] [MY-000000] [Galera] Using CRC-32C for message checksums.
2023-04-20T08:31:44.133192Z 0 [Note] [MY-000000] [Galera] backend: asio
2023-04-20T08:31:44.133309Z 0 [Note] [MY-000000] [Galera] gcomm thread scheduling priority set to other:0
2023-04-20T08:31:44.133517Z 0 [Note] [MY-000000] [Galera] Fail to access the file (/var/lib/mysql/mysql_data//gvwstate.dat) error (No such file or directory). It is possible if node is booting for first time or re-booting after a graceful shutdown
2023-04-20T08:31:44.133547Z 0 [Note] [MY-000000] [Galera] Restoring primary-component from disk failed. Either node is booting for first time or re-booting after a graceful shutdown
2023-04-20T08:31:44.133857Z 0 [Note] [MY-000000] [Galera] GMCast version 0
2023-04-20T08:31:44.134123Z 0 [Note] [MY-000000] [Galera] (c8237aa2-ae61, ‘tcp://0.0.0.0:4567’) listening at tcp://0.0.0.0:4567
2023-04-20T08:31:44.134156Z 0 [Note] [MY-000000] [Galera] (c8237aa2-ae61, ‘tcp://0.0.0.0:4567’) multicast: , ttl: 1
2023-04-20T08:31:44.134644Z 0 [Note] [MY-000000] [Galera] EVS version 1
2023-04-20T08:31:44.134805Z 0 [Note] [MY-000000] [Galera] gcomm: connecting to group ‘galera-15’, peer ‘192.168.4.196:,192.168.4.123:’
2023-04-20T08:31:44.135808Z 0 [Note] [MY-000000] [Galera] (c8237aa2-ae61, ‘tcp://0.0.0.0:4567’) Found matching local endpoint for a connection, blacklisting address tcp://192.168.4.123:4567
2023-04-20T08:31:44.136569Z 0 [Note] [MY-000000] [Galera] (c8237aa2-ae61, ‘tcp://0.0.0.0:4567’) connection established to 174d0059-bda1 tcp://192.168.4.196:4567
2023-04-20T08:31:44.136633Z 0 [Note] [MY-000000] [Galera] (c8237aa2-ae61, ‘tcp://0.0.0.0:4567’) turning message relay requesting on, nonlive peers:
2023-04-20T08:31:44.637625Z 0 [Note] [MY-000000] [Galera] EVS version upgrade 0 → 1
2023-04-20T08:31:44.637716Z 0 [Note] [MY-000000] [Galera] declaring 174d0059-bda1 at tcp://192.168.4.196:4567 stable
2023-04-20T08:31:44.637803Z 0 [Note] [MY-000000] [Galera] PC protocol upgrade 0 → 1
2023-04-20T08:31:44.638487Z 0 [Note] [MY-000000] [Galera] Node 174d0059-bda1 state primary
2023-04-20T08:31:44.641675Z 0 [Note] [MY-000000] [Galera] Current view of cluster as seen by this node
view (view_id(PRIM,174d0059-bda1,36)
memb {
174d0059-bda1,0
c8237aa2-ae61,0
}
joined {
}
left {
}
partitioned {
}
)
2023-04-20T08:31:44.641759Z 0 [Note] [MY-000000] [Galera] Save the discovered primary-component to disk
2023-04-20T08:31:45.135740Z 0 [Note] [MY-000000] [Galera] gcomm: connected
2023-04-20T08:31:45.135839Z 0 [Note] [MY-000000] [Galera] Changing maximum packet size to 64500, resulting msg size: 32636
2023-04-20T08:31:45.136054Z 0 [Note] [MY-000000] [Galera] Shifting CLOSED → OPEN (TO: 0)
2023-04-20T08:31:45.136147Z 0 [Note] [MY-000000] [Galera] Opened channel ‘galera-15’
2023-04-20T08:31:45.136327Z 0 [Note] [MY-000000] [Galera] New COMPONENT: primary = yes, bootstrap = no, my_idx = 1, memb_num = 2
2023-04-20T08:31:45.136428Z 0 [Note] [MY-000000] [Galera] STATE EXCHANGE: Waiting for state UUID.
2023-04-20T08:31:45.136511Z 0 [Note] [MY-000000] [Galera] STATE EXCHANGE: sent state msg: c870bf80-df55-11ed-9dd7-9b46dc6c2c85
2023-04-20T08:31:45.136567Z 0 [Note] [MY-000000] [Galera] STATE EXCHANGE: got state msg: c870bf80-df55-11ed-9dd7-9b46dc6c2c85 from 0 (eda25c647f81)
2023-04-20T08:31:45.136890Z 1 [Note] [MY-000000] [WSREP] wsrep running threads now: 1
2023-04-20T08:31:45.136910Z 2 [Note] [MY-000000] [WSREP] wsrep running threads now: 2
2023-04-20T08:31:45.137042Z 2 [Note] [MY-000000] [WSREP] Starting rollbacker thread 2
2023-04-20T08:31:45.137103Z 1 [Note] [MY-000000] [WSREP] Starting applier thread 1
2023-04-20T08:31:45.137472Z 0 [Note] [MY-000000] [Galera] STATE EXCHANGE: got state msg: c870bf80-df55-11ed-9dd7-9b46dc6c2c85 from 1 (826d3d3681d6)
2023-04-20T08:31:45.137547Z 0 [Note] [MY-000000] [Galera] Quorum results:
version = 6,
component = PRIMARY,
conf_id = 35,
members = 1/2 (primary/total),
act_id = 50,
last_appl. = 15,
protocols = 2/10/4 (gcs/repl/appl),
vote policy= 0,
group UUID = 084297fa-df4e-11ed-a52f-cbc3c5236e5f
2023-04-20T08:31:45.137669Z 0 [Note] [MY-000000] [Galera] Flow-control interval: [141, 141]
2023-04-20T08:31:45.137697Z 0 [Note] [MY-000000] [Galera] Shifting OPEN → PRIMARY (TO: 51)
2023-04-20T08:31:45.137855Z 1 [Note] [MY-000000] [Galera] ####### processing CC 51, local, ordered
2023-04-20T08:31:45.137932Z 1 [Note] [MY-000000] [Galera] Maybe drain monitors from -1 upto current CC event 51 upto:-1
2023-04-20T08:31:45.137970Z 1 [Note] [MY-000000] [Galera] Drain monitors from -1 up to -1
2023-04-20T08:31:45.138012Z 1 [Note] [MY-000000] [Galera] Process first view: 084297fa-df4e-11ed-a52f-cbc3c5236e5f my uuid: c8237aa2-df55-11ed-ae61-83232a724fd4
2023-04-20T08:31:45.138051Z 1 [Note] [MY-000000] [Galera] Server 826d3d3681d6 connected to cluster at position 084297fa-df4e-11ed-a52f-cbc3c5236e5f:51 with ID c8237aa2-df55-11ed-ae61-83232a724fd4
2023-04-20T08:31:45.138081Z 1 [Note] [MY-000000] [Galera] server 826d3d3681d6 state change: disconnected → connected
2023-04-20T08:31:45.138115Z 1 [Note] [MY-000000] [WSREP] Server status change disconnected → connected
2023-04-20T08:31:45.138185Z 1 [Note] [MY-000000] [WSREP] wsrep_notify_cmd is not defined, skipping notification.
2023-04-20T08:31:45.138262Z 1 [Note] [MY-000000] [Galera] ####### My UUID: c8237aa2-df55-11ed-ae61-83232a724fd4
2023-04-20T08:31:45.138300Z 1 [Note] [MY-000000] [Galera] Cert index reset to 00000000-0000-0000-0000-000000000000:-1 (proto: 10), state transfer needed: yes
2023-04-20T08:31:45.138411Z 0 [Note] [MY-000000] [Galera] Service thread queue flushed.
2023-04-20T08:31:45.138567Z 1 [Note] [MY-000000] [Galera] ####### Assign initial position for certification: 00000000-0000-0000-0000-000000000000:-1, protocol version: -1
2023-04-20T08:31:45.138644Z 1 [Note] [MY-000000] [Galera] State transfer required:
Group state: 084297fa-df4e-11ed-a52f-cbc3c5236e5f:51
Local state: 00000000-0000-0000-0000-000000000000:-1
2023-04-20T08:31:45.138687Z 1 [Note] [MY-000000] [Galera] server 826d3d3681d6 state change: connected → joiner
2023-04-20T08:31:45.138711Z 1 [Note] [MY-000000] [WSREP] Server status change connected → joiner
2023-04-20T08:31:45.138738Z 1 [Note] [MY-000000] [WSREP] wsrep_notify_cmd is not defined, skipping notification.
2023-04-20T08:31:45.139092Z 0 [Note] [MY-000000] [WSREP] Initiating SST/IST transfer on JOINER side (wsrep_sst_xtrabackup-v2 --role ‘joiner’ --address ‘192.168.4.123’ --datadir ‘/var/lib/mysql/mysql_data/’ --basedir ‘/usr/’ --plugindir ‘/usr/lib/mysql/plugin/’ --defaults-file ‘/etc/mysql/my.cnf’ --defaults-group-suffix ‘’ --parent ‘7499’ --mysqld-version ‘8.0.31-23.1’ ‘’ )
2023-04-20T08:31:45.383260Z 0 [Warning] [MY-000000] [WSREP-SST] wsrep_node_address or wsrep_sst_receive_address not set. Consider setting them if SST fails.
2023-04-20T08:31:45.560589Z 0 [Warning] [MY-000000] [WSREP-SST] Found a stale sst_in_progress file: /var/lib/mysql/mysql_data//sst_in_progress
2023-04-20T08:31:45.585677Z 0 [ERROR] [MY-000000] [WSREP] Failed to read ‘ready ’ from: wsrep_sst_xtrabackup-v2 --role ‘joiner’ --address ‘192.168.4.123’ --datadir ‘/var/lib/mysql/mysql_data/’ --basedir ‘/usr/’ --plugindir ‘/usr/lib/mysql/plugin/’ --defaults-file ‘/etc/mysql/my.cnf’ --defaults-group-suffix ‘’ --parent ‘7499’ --mysqld-version ‘8.0.31-23.1’ ‘’
Read: ‘(null)’
2023-04-20T08:31:45.585732Z 0 [ERROR] [MY-000000] [WSREP] Process completed with error: wsrep_sst_xtrabackup-v2 --role ‘joiner’ --address ‘192.168.4.123’ --datadir ‘/var/lib/mysql/mysql_data/’ --basedir ‘/usr/’ --plugindir ‘/usr/lib/mysql/plugin/’ --defaults-file ‘/etc/mysql/my.cnf’ --defaults-group-suffix ‘’ --parent ‘7499’ --mysqld-version ‘8.0.31-23.1’ ‘’ : 1 (Operation not permitted)
2023-04-20T08:31:45.585815Z 1 [ERROR] [MY-000000] [WSREP] Failed to prepare for ‘xtrabackup-v2’ SST. Unrecoverable.
2023-04-20T08:31:45.585969Z 1 [ERROR] [MY-000000] [Galera] SST request callback failed. This is unrecoverable, restart required.
2023-04-20T08:31:45.585994Z 1 [Note] [MY-000000] [Galera] ReplicatorSMM::abort()
2023-04-20T08:31:45.586014Z 1 [Note] [MY-000000] [Galera] Closing send monitor…
2023-04-20T08:31:45.586028Z 1 [Note] [MY-000000] [Galera] Closed send monitor.
2023-04-20T08:31:45.586042Z 1 [Note] [MY-000000] [Galera] gcomm: terminating thread
2023-04-20T08:31:45.586065Z 1 [Note] [MY-000000] [Galera] gcomm: joining thread
2023-04-20T08:31:45.586269Z 1 [Note] [MY-000000] [Galera] gcomm: closing backend
2023-04-20T08:31:46.589900Z 1 [Note] [MY-000000] [Galera] Current view of cluster as seen by this node
view (view_id(NON_PRIM,174d0059-bda1,36)
memb {
c8237aa2-ae61,0
}
joined {
}
left {
}
partitioned {
174d0059-bda1,0
}
)
2023-04-20T08:31:46.589951Z 1 [Note] [MY-000000] [Galera] PC protocol downgrade 1 → 0
2023-04-20T08:31:46.589963Z 1 [Note] [MY-000000] [Galera] Current view of cluster as seen by this node
view ((empty))
2023-04-20T08:31:46.590089Z 1 [Note] [MY-000000] [Galera] gcomm: closed
2023-04-20T08:31:46.590123Z 0 [Note] [MY-000000] [Galera] New COMPONENT: primary = no, bootstrap = no, my_idx = 0, memb_num = 1
2023-04-20T08:31:46.590188Z 0 [Note] [MY-000000] [Galera] Flow-control interval: [100, 100]
2023-04-20T08:31:46.590198Z 0 [Note] [MY-000000] [Galera] Received NON-PRIMARY.
2023-04-20T08:31:46.590204Z 0 [Note] [MY-000000] [Galera] Shifting PRIMARY → OPEN (TO: 51)
2023-04-20T08:31:46.590218Z 0 [Note] [MY-000000] [Galera] New SELF-LEAVE.
2023-04-20T08:31:46.590232Z 0 [Note] [MY-000000] [Galera] Flow-control interval: [0, 0]
2023-04-20T08:31:46.590238Z 0 [Note] [MY-000000] [Galera] Received SELF-LEAVE. Closing connection.
2023-04-20T08:31:46.590244Z 0 [Note] [MY-000000] [Galera] Shifting OPEN → CLOSED (TO: 51)
2023-04-20T08:31:46.590253Z 0 [Note] [MY-000000] [Galera] RECV thread exiting 0: Success
2023-04-20T08:31:46.590305Z 1 [Note] [MY-000000] [Galera] recv_thread() joined.
2023-04-20T08:31:46.590326Z 1 [Note] [MY-000000] [Galera] Closing replication queue.
2023-04-20T08:31:46.590334Z 1 [Note] [MY-000000] [Galera] Closing slave action queue.
2023-04-20T08:31:46.590344Z 1 [Note] [MY-000000] [Galera] mysqld: Terminated.
2023-04-20T08:31:46.590352Z 1 [Note] [MY-000000] [WSREP] Initiating SST cancellation
Aborted
Config:
[mysqld]
pid-file = /var/run/mysqld/mysqld.pid
socket = /var/run/mysqld/mysqld.sock
port = 3306
basedir = /usr
tmpdir = /tmp
lc-messages-dir = /usr/share/mysql
skip-external-locking
datadir=/var/lib/mysql/mysql_data
binlog_expire_logs_seconds = 864000
tls_version=TLSv1.2
pxc_encrypt_cluster_traffic = OFF
default_authentication_plugin=mysql_native_password
skip-host-cache
default_storage_engine=InnoDB
binlog_format=ROW
innodb_flush_log_at_trx_commit = 0
innodb_flush_method = O_DIRECT
innodb_file_per_table = 1
innodb_autoinc_lock_mode=2
bind_address = 0.0.0.0
wsrep_applier_threads=8
wsrep_cluster_address=gcomm://
wsrep_provider=/usr/lib/galera4/libgalera_smm.so
wsrep_cluster_name=Theistareykjarbunga
wsrep_log_conflicts
transaction_write_set_extraction = OFF
pxc_strict_mode=ENFORCING
wsrep_sst_method=xtrabackup-v2
[sst]
encrypt=0