PXC8.0 Bootstrap doesn't work with clean install

Hello!

OS: Ubuntu 22.04.4 LTS
Package version:

percona-release/unknown,now 1.0-27.generic all [installed]
percona-toolkit/unknown,now 3.6.0-1.jammy amd64 [installed]
percona-xtrabackup-80/unknown,now 8.0.35-30-1.jammy amd64 [installed]
percona-xtradb-cluster-client/unknown,now 1:8.0.33-25-1.jammy amd64 [installed, can be updated to: 1:8.0.36-28-1.jammy]
percona-xtradb-cluster-common/unknown,now 1:8.0.33-25-1.jammy amd64 [installed, can be updated to: 1:8.0.36-28-1.jammy]
percona-xtradb-cluster-server/unknown,now 1:8.0.33-25-1.jammy amd64 [installed, can be upgraded to: 1:8.0.36-28-1.jammy]
percona-xtradb-cluster/unknown,now 1:8.0.33-25-1.jammy amd64 [installed, can be updated to: 1:8.0.36-28-1.jammy]

Installed on 3 nodes, services stopped.
Nodes are configured on all nodes:

# Ansible managed

#check_point
# Template my.cnf for PXC
# Edit to your requirements.
[client]
socket                          = /var/run/mysqld/mysqld.sock

[mysqld]
datadir                         = /var/lib/mysql
log-error                       = /var/log/mysql/error.log
pid-file                        = /var/run/mysqld/mysqld.pid
server-id                       = 103
socket                          = /var/run/mysqld/mysqld.sock

authentication_policy           = mysql_native_password

# Binary log expiration period is 604800 seconds, which equals 7 days
binlog_expire_logs_seconds      = 28800

######## wsrep ###############
# Path to Galera library
wsrep_provider                  = /usr/lib/galera4/libgalera_smm.so

# Cluster connection URL contains IPs of nodes
#If no IP is found, this implies that a new cluster needs to be created,
#in order to do that you need to bootstrap this node
wsrep_cluster_address           = gcomm://10.9.2.103,10.9.2.104,10.9.2.105
# In order for Galera to work correctly binlog format should be ROW
binlog_format                   = ROW

# Slave thread to use
wsrep_applier_threads           = 16

wsrep_log_conflicts

# This changes how InnoDB autoincrement locks are managed and is a requirement for Galera
innodb_autoinc_lock_mode        = 2

# Node IP address
wsrep_node_address              = 10.9.2.103
# Cluster name
wsrep_cluster_name              = pxc-cluster

#If wsrep_node_name is not specified,  then system hostname will be used
#wsrep_node_name=pxc-cluster-node-1

#pxc_strict_mode allowed values: DISABLED,PERMISSIVE,ENFORCING,MASTER
pxc_strict_mode                 = ENFORCING

# SST method
wsrep_sst_method                = xtrabackup-v2
#encrypt
pxc-encrypt-cluster-traffic     = OFF

pxc_maint_mode                  = DISABLED
pxc_maint_transition_period     = 10
wsrep_applier_FK_checks         = ON
wsrep_applier_UK_checks         = OFF
wsrep_auto_increment_control    = ON
wsrep_certify_nonPK             = ON
wsrep_debug                     = NONE
wsrep_dirty_reads               = OFF
wsrep_load_data_splitting       = ON
wsrep_max_ws_rows               = 800000
wsrep_max_ws_size               = 2147483648
wsrep_provider_options          = "pc.weight=1;gmcast.segment=1;socket.ssl_compression=no;gcache.keep_pages_size=4;gcache.page_size=32M;gcache.size=1024M;evs.send_window=512;evs.user_send_window=512;evs.use_aggregate = true;gcs.fc_factor = 0.9;gcs.fc_limit = 5000;gcs.fc_single_primary = no;gcs.max_packet_size = 131072;gcs.fc_debug = 0;evs.inactive_check_period = PT1S;evs.inactive_timeout = PT20S;evs.suspect_timeout = PT5S;evs.stats_report_period = PT1M;"
wsrep_recover                   = OFF
wsrep_replicate_myisam          = OFF
wsrep_restart_replica           = OFF
wsrep_retry_autocommit          = 3
wsrep_sst_receive_address       = AUTO
wsrep_sync_wait                 = 0

##################INNODB and other options#####################
connect_timeout                 = 60
group_concat_max_len            = 2048
innodb_adaptive_flushing_lwm    = 20
innodb_adaptive_hash_index      = OFF
innodb_buffer_pool_instances    = 16
innodb_buffer_pool_size         = 1G
innodb_flush_log_at_trx_commit  = 2
innodb_flush_method             = O_DIRECT
innodb_io_capacity              = 2000
innodb_io_capacity_max          = 5000
innodb_log_file_size            = 5G
interactive_timeout             = 1200
log_bin_trust_function_creators = 1
log_error_verbosity             = 3
long_query_time                 = 1
max_allowed_packet              = 512M
max_connect_errors              = 99999999999999
max_connections                 = 3000
max_prepared_stmt_count         = 131072
range_optimizer_max_mem_size    = 44040191
skip_name_resolve               = 1
slow_query_log                  = ON
slow_query_log_file             = /var/log/mysql/mysql-slow.log
sql_mode                        = 'NO_ENGINE_SUBSTITUTION'
sync_binlog                     = 2
table_open_cache                = 8192
thread_cache_size               = 256
userstat                        = ON
wait_timeout                    = 1200

[sst]
streamfmt                       = xbstream
#compressor='zstd -1 -T2'
#decompressor='zstd -d -T2'

[xtrabackup]
parallel                        = 16
rebuild-threads                 = 16

On nodes 2 and 3, the server-id and wsrep_node_address change.

On the first node when running bootstrap:
systemctl start mysql@bootstrap.service
Always crashes with the error:

root@test-vm-1:~# systemctl start mysql@bootstrap.service
Job for mysql@bootstrap.service failed because the control process exited with error code.
See "systemctl status mysql@bootstrap.service" and "journalctl -xeu mysql@bootstrap.service" for details.
root@test-vm-1:~# systemctl status mysql@bootstrap.service
× mysql@bootstrap.service - Percona XtraDB Cluster with config /etc/default/mysql.bootstrap
     Loaded: loaded (/lib/systemd/system/mysql@.service; disabled; vendor preset: enabled)
     Active: failed (Result: exit-code) since Tue 2024-06-18 07:39:29 UTC; 26s ago
    Process: 8214 ExecStartPre=/usr/bin/mysql-systemd start-pre (code=exited, status=1/FAILURE)
    Process: 8252 ExecStopPost=/usr/bin/mysql-systemd stop-post (code=exited, status=0/SUCCESS)
        CPU: 103ms

Jun 18 07:39:29 test-vm-1 systemd[1]: Starting Percona XtraDB Cluster with config /etc/default/mysql.bootstrap...
Jun 18 07:39:29 test-vm-1 systemd[1]: mysql@bootstrap.service: Control process exited, code=exited, status=1/FAILURE
Jun 18 07:39:29 test-vm-1 mysql-systemd[8252]: WARNING: mysql pid file /var/run/mysqld/mysqld.pid empty or not readable
Jun 18 07:39:29 test-vm-1 mysql-systemd[8252]: WARNING: mysql may be already dead
Jun 18 07:39:29 test-vm-1 systemd[1]: mysql@bootstrap.service: Failed with result 'exit-code'.
Jun 18 07:39:29 test-vm-1 systemd[1]: Failed to start Percona XtraDB Cluster with config /etc/default/mysql.bootstrap.
Jun 18 07:39:29 test-vm-1 systemd[1]: Starting Percona XtraDB Cluster with config /etc/default/mysql.bootstrap...
░░ Subject: The mysql@bootstrap.service unit starts running
░░ Defined-By: systemd
░░ Support: http://www.ubuntu.com/support
░░
░░ The process of launching the mysql@bootstrap.service unit has begun.
Jun 18 07:39:29 test-vm-1 systemd[1]: mysql@bootstrap.service: Control process exited, code=exited, status=1/FAILURE
░░ Subject: Unit process exited
░░ Defined-By: systemd
░░ Support: http://www.ubuntu.com/support
░░
░░ An ExecStartPre= process belonging to unit mysql@bootstrap.service has exited.
░░
░░ The process' exit code is 'exited' and its exit status is 1.
Jun 18 07:39:29 test-vm-1 mysql-systemd[8252]: WARNING: mysql pid file /var/run/mysqld/mysqld.pid empty or not readable
Jun 18 07:39:29 test-vm-1 mysql-systemd[8252]: WARNING: mysql may be already dead
Jun 18 07:39:29 test-vm-1 systemd[1]: mysql@bootstrap.service: Failed with result 'exit-code'.
░░ Subject: Unit failed
░░ Defined-By: systemd
░░ Support: http://www.ubuntu.com/support
░░
░░ The unit mysql@bootstrap.service has entered the 'failed' state with result 'exit-code'.
Jun 18 07:39:29 test-vm-1 systemd[1]: Failed to start Percona XtraDB Cluster with config /etc/default/mysql.bootstrap.
░░ Subject: Error in unit mysql@bootstrap.service
░░ Defined-By: systemd
░░ Support: http://www.ubuntu.com/support
░░
░░ The mysql@bootstrap.service unit failed.
░░
░░ Result: failed.

The error log is empty.
There were no problems before, but this time I can’t start the node.

Tell me, what’s wrong?

Hello @shigaev.s

The error log is empty.

It’s falling at StartPre stage,
Process: 8214 ExecStartPre=/usr/bin/mysql-systemd start-pre (code=exited, status=1/FAILURE)

Try starting cluster node manually using below command and it should print the actual error causing issue.
mysqld --defaults-file=/etc/my.cnf --wsrep-new-cluster

Thanks for the answer!

I tried to run it like this:

root@test-vm-1:~# mysqld --defaults-file=/etc/my.cnf --wsrep-new-cluster
mysqld: [ERROR] Failed to open required defaults file: /etc/my.cnf
mysqld: [ERROR] Fatal error in defaults handling. Program aborted!
root@test-vm-1:~# mysqld --defaults-file=/etc/mysql/mysql.cnf --wsrep-new-cluster
2024-06-18T09:34:28.937546Z 0 [Warning] [MY-000081] [Server] option 'wsrep_max_ws_size': unsigned value 2147483648 adjusted to 2147483647.
2024-06-18T09:34:28.941138Z 0 [Warning] [MY-010101] [Server] Insecure configuration for --secure-file-priv: Location is accessible to all OS users. Consider choosing a different directory.
2024-06-18T09:34:28.941147Z 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.
2024-06-18T09:34:28.941645Z 0 [Note] [MY-013932] [Server] BuildID[sha1]=3f6331e0284addef5a5d82661c36cc7b6a6dc15a
2024-06-18T09:34:28.941651Z 0 [Note] [MY-010949] [Server] Basedir set to /usr/.
2024-06-18T09:34:28.941657Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 8.0.33-25.1) starting as process 8326
2024-06-18T09:34:28.943995Z 0 [ERROR] [MY-010123] [Server] Fatal error: Please read "Security" section of the manual to find out how to run mysqld as root!
2024-06-18T09:34:28.944068Z 0 [ERROR] [MY-010119] [Server] Aborting
2024-06-18T09:34:28.944192Z 0 [Note] [MY-010120] [Server] Binlog end
2024-06-18T09:34:28.944361Z 0 [System] [MY-010910] [Server] /usr/sbin/mysqld: Shutdown complete (mysqld 8.0.33-25.1)  Percona XtraDB Cluster (GPL), Release rel25, Revision 0c56202, WSREP version 26.1.4.3.

If you run it with the user specified, it is Aborted:

root@test-vm-1:~# mysqld --defaults-file=/etc/mysql/mysql.cnf -u root --wsrep-new-cluster
Aborted

Attached is error.log.
error.log (15.5 KB)

Try running this,
/usr/bin/mysql-systemd start-pre

2024-06-18T09:50:43.421604Z 0 [Warning] [MY-000081] [Server] option 'wsrep_max_ws_size': unsigned value 2147483648 adjusted to 2147483647.
2024-06-18T09:50:43.421683Z 0 [Note] [MY-010096] [Server] Ignoring --secure-file-priv value as server is running with --initialize(-insecure).
2024-06-18T09:50:43.421686Z 0 [Note] [MY-010096] [Server] Ignoring --secure-log-path value as server is running with --initialize(-insecure).
2024-06-18T09:50:43.421692Z 0 [Warning] [MY-000000] [WSREP] Node is running in bootstrap/initialize mode. Disabling pxc_strict_mode checks
2024-06-18T09:50:43.422037Z 0 [Note] [MY-013932] [Server] BuildID[sha1]=3f6331e0284addef5a5d82661c36cc7b6a6dc15a
2024-06-18T09:50:43.422041Z 0 [Note] [MY-010949] [Server] Basedir set to /usr/.
2024-06-18T09:50:43.422060Z 0 [System] [MY-013169] [Server] /usr/sbin/mysqld (mysqld 8.0.33-25.1) initializing of server in progress as process 8428
2024-06-18T09:50:43.423527Z 0 [ERROR] [MY-010457] [Server] --initialize specified but the data directory has files in it. Aborting.
2024-06-18T09:50:43.423550Z 0 [ERROR] [MY-013236] [Server] The designated data directory /var/lib/mysql/ is unusable. You can remove all files that the server added to it.
2024-06-18T09:50:43.423614Z 0 [ERROR] [MY-010119] [Server] Aborting
2024-06-18T09:50:43.423648Z 0 [Note] [MY-010120] [Server] Binlog end
2024-06-18T09:50:43.423718Z 0 [System] [MY-010910] [Server] /usr/sbin/mysqld: Shutdown complete (mysqld 8.0.33-25.1)  Percona XtraDB Cluster (GPL), Release rel25, Revision 0c56202, WSREP version 26.1.4.3.

I also attached the log in the message above.

Cleared the entire directory:
rm -rf /var/lib/mysql/*

Launched:

root@test-vm-1:~# mysqld --defaults-file=/etc/mysql/mysql.cnf --user=root --wsrep-new-cluster
Aborted

Log:

2024-06-18T09:54:55.683148Z 0 [Warning] [MY-000081] [Server] option 'wsrep_max_ws_size': unsigned value 2147483648 adjusted to 2147483647.
2024-06-18T09:54:55.686448Z 0 [Warning] [MY-010101] [Server] Insecure configuration for --secure-file-priv: Location is accessible to all OS users. Consider choosing a different directory.
2024-06-18T09:54:55.686455Z 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.
2024-06-18T09:54:55.686946Z 0 [Note] [MY-013932] [Server] BuildID[sha1]=3f6331e0284addef5a5d82661c36cc7b6a6dc15a
2024-06-18T09:54:55.686951Z 0 [Note] [MY-010949] [Server] Basedir set to /usr/.
2024-06-18T09:54:55.686957Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 8.0.33-25.1) starting as process 8529
2024-06-18T09:54:55.689624Z 0 [Note] [MY-000000] [Galera] Loading provider /usr/lib/galera4/libgalera_smm.so initial position: 00000000-0000-0000-0000-000000000000:-1
2024-06-18T09:54:55.689652Z 0 [Note] [MY-000000] [Galera] wsrep_load(): loading provider library '/usr/lib/galera4/libgalera_smm.so'
2024-06-18T09:54:55.690282Z 0 [Note] [MY-000000] [Galera] wsrep_load(): Galera 4.15(6983fb2) by Codership Oy <info@codership.com> (modified by Percona <https://percona.com/>) loaded successfully.
2024-06-18T09:54:55.690323Z 0 [Note] [MY-000000] [Galera] CRC-32C: using 64-bit x86 acceleration.
2024-06-18T09:54:55.690531Z 0 [Warning] [MY-000000] [Galera] Parameter 'socket.ssl_compression' is deprecated and will be removed in future versions
2024-06-18T09:54:55.690570Z 0 [Warning] [MY-000000] [Galera] Could not open state file for reading: '/var/lib/mysql//grastate.dat'
2024-06-18T09:54:55.690576Z 0 [Warning] [MY-000000] [Galera] No persistent state found. Bootstraping with default state
2024-06-18T09:54:55.690608Z 0 [Note] [MY-000000] [Galera] Found saved state: 00000000-0000-0000-0000-000000000000:-1, safe_to_bootstrap: 1
2024-06-18T09:54:55.691468Z 0 [Note] [MY-000000] [Galera] Generated new GCache ID: d0e6825c-2d58-11ef-b33c-3265f4b88a58
2024-06-18T09:54:55.691495Z 0 [Note] [MY-000000] [Galera] GCache DEBUG: opened preamble:
Version: 0
UUID: 00000000-0000-0000-0000-000000000000
Seqno: -1 - -1
Offset: -1
Synced: 0
EncVersion: 0
Encrypted: 0
MasterKeyConst UUID: d0e6825c-2d58-11ef-b33c-3265f4b88a58
MasterKey UUID: 00000000-0000-0000-0000-000000000000
MasterKey ID: 0
2024-06-18T09:54:55.691504Z 0 [Note] [MY-000000] [Galera] Skipped GCache ring buffer recovery: could not determine history UUID.
2024-06-18T09:54:55.913290Z 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/; base_host = 10.9.2.103; 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 = PT1S; evs.inactive_timeout = PT20S; evs.join_retrans_period = PT1S; evs.max_install_timeouts = 3; evs.send_window = 512; evs.stats_report_period = PT1M; evs.suspect_timeout = PT5S; evs.use_aggregate = true; evs.user_send_window = 512; evs.view_forget_timeout = PT24H; gcache.dir = /var/lib/mysql/; 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 = 4; gcache.mem_size = 0; gcache.name = galera.cache; gcache.page_size = 32M; gcache.recover = yes; gcache.size = 1024M; gcomm.thread_prio = ; gcs.fc_auto_evict_threshold = 0.75; gcs.fc_auto_evict_window = 0; gcs.fc_debug = 0; gcs.fc_factor = 0.9; gcs.fc_limit = 5000; gcs.fc_master_slave = no; gcs.fc_single_primary = no; gcs.max_packet_size = 131072; gcs.max_throttle = 0.25; gcs.recv_q_hard_limit = 9223372036854775807; gcs.recv_q_soft_limit = 0.25; gcs.sync_donor = no; gmcast.segment = 1; 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.wait_restored_prim_timeout = PT0S; 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; socket.ssl_compression = no; 
2024-06-18T09:54:55.941740Z 0 [Note] [MY-000000] [WSREP] Starting replication
2024-06-18T09:54:55.941784Z 0 [Note] [MY-000000] [Galera] Connecting with bootstrap option: 1
2024-06-18T09:54:55.941796Z 0 [Note] [MY-000000] [Galera] Setting GCS initial position to 00000000-0000-0000-0000-000000000000:-1
2024-06-18T09:54:55.941848Z 0 [Note] [MY-000000] [Galera] protonet asio version 0
2024-06-18T09:54:55.941895Z 0 [Note] [MY-000000] [Galera] Using CRC-32C for message checksums.
2024-06-18T09:54:55.941916Z 0 [Note] [MY-000000] [Galera] backend: asio
2024-06-18T09:54:55.941991Z 0 [Note] [MY-000000] [Galera] gcomm thread scheduling priority set to other:0 
2024-06-18T09:54:55.942067Z 0 [Note] [MY-000000] [Galera] Fail to access the file (/var/lib/mysql//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
2024-06-18T09:54:55.942076Z 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
2024-06-18T09:54:55.942214Z 0 [Note] [MY-000000] [Galera] GMCast version 0
2024-06-18T09:54:55.942328Z 0 [Note] [MY-000000] [Galera] (d10cc1e1-b10e, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567
2024-06-18T09:54:55.942335Z 0 [Note] [MY-000000] [Galera] (d10cc1e1-b10e, 'tcp://0.0.0.0:4567') multicast: , ttl: 1
2024-06-18T09:54:55.942570Z 0 [Note] [MY-000000] [Galera] EVS version 1
2024-06-18T09:54:55.942623Z 0 [Note] [MY-000000] [Galera] gcomm: bootstrapping new group 'pxc-cluster'
2024-06-18T09:54:55.942647Z 0 [Note] [MY-000000] [Galera] start_prim is enabled, turn off pc_recovery
2024-06-18T09:54:55.943067Z 0 [Note] [MY-000000] [Galera] EVS version upgrade 0 -> 1
2024-06-18T09:54:55.943086Z 0 [Note] [MY-000000] [Galera] PC protocol upgrade 0 -> 1
2024-06-18T09:54:55.943141Z 0 [Note] [MY-000000] [Galera] Node d10cc1e1-b10e state primary
2024-06-18T09:54:55.943181Z 0 [Note] [MY-000000] [Galera] Current view of cluster as seen by this node
view (view_id(PRIM,d10cc1e1-b10e,1)
memb {
        d10cc1e1-b10e,1
        }
joined {
        }
left {
        }
partitioned {
        }
)
2024-06-18T09:54:55.943196Z 0 [Note] [MY-000000] [Galera] Save the discovered primary-component to disk
2024-06-18T09:54:56.074085Z 0 [Note] [MY-000000] [Galera] discarding pending addr without UUID: tcp://10.9.2.103:4567
2024-06-18T09:54:56.074130Z 0 [Note] [MY-000000] [Galera] discarding pending addr proto entry 0x5557712e5ee0
2024-06-18T09:54:56.074196Z 0 [Note] [MY-000000] [Galera] discarding pending addr without UUID: tcp://10.9.2.104:4567
2024-06-18T09:54:56.074202Z 0 [Note] [MY-000000] [Galera] discarding pending addr proto entry 0x5557712e06a0
2024-06-18T09:54:56.074251Z 0 [Note] [MY-000000] [Galera] discarding pending addr without UUID: tcp://10.9.2.105:4567
2024-06-18T09:54:56.074257Z 0 [Note] [MY-000000] [Galera] discarding pending addr proto entry 0x555771282030
2024-06-18T09:54:56.074302Z 0 [Note] [MY-000000] [Galera] gcomm: connected
2024-06-18T09:54:56.074323Z 0 [Note] [MY-000000] [Galera] Changing maximum packet size to 131072, resulting msg size: 32636
2024-06-18T09:54:56.074428Z 0 [Note] [MY-000000] [Galera] Shifting CLOSED -> OPEN (TO: 0)
2024-06-18T09:54:56.074436Z 0 [Note] [MY-000000] [Galera] Opened channel 'pxc-cluster'
2024-06-18T09:54:56.074645Z 0 [Note] [MY-000000] [Galera] New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 1
2024-06-18T09:54:56.074784Z 0 [Note] [MY-000000] [Galera] Starting new group from scratch: d121003e-2d58-11ef-866f-5f21780be5d6
2024-06-18T09:54:56.074780Z 1 [Note] [MY-000000] [WSREP] Starting rollbacker thread 1
2024-06-18T09:54:56.074832Z 2 [Note] [MY-000000] [WSREP] Starting applier thread 2
2024-06-18T09:54:56.074843Z 0 [Note] [MY-000000] [Galera] STATE_EXCHANGE: sent state UUID: d12101a4-2d58-11ef-8d1f-63327d45410d
2024-06-18T09:54:56.074882Z 0 [Note] [MY-000000] [Galera] STATE EXCHANGE: sent state msg: d12101a4-2d58-11ef-8d1f-63327d45410d
2024-06-18T09:54:56.074895Z 0 [Note] [MY-000000] [Galera] STATE EXCHANGE: got state msg: d12101a4-2d58-11ef-8d1f-63327d45410d from 0 (test-vm-1)
2024-06-18T09:54:56.074907Z 0 [Note] [MY-000000] [Galera] Quorum results:
        version    = 6,
        component  = PRIMARY,
        conf_id    = 0,
        members    = 1/1 (primary/total),
        act_id     = 0,
        last_appl. = 0,
        protocols  = 2/10/4 (gcs/repl/appl),
        vote policy= 0,
        group UUID = d121003e-2d58-11ef-866f-5f21780be5d6
2024-06-18T09:54:56.074939Z 0 [Note] [MY-000000] [Galera] Flow-control interval: [4500, 5000]
2024-06-18T09:54:56.074945Z 0 [Note] [MY-000000] [Galera] Restored state OPEN -> JOINED (1)
2024-06-18T09:54:56.074967Z 0 [Note] [MY-000000] [Galera] Member 0.1 (test-vm-1) synced with group.
2024-06-18T09:54:56.074973Z 0 [Note] [MY-000000] [Galera] Shifting JOINED -> SYNCED (TO: 1)
2024-06-18T09:54:56.074990Z 2 [Note] [MY-000000] [Galera] ####### processing CC 1, local, ordered
2024-06-18T09:54:56.075004Z 2 [Note] [MY-000000] [Galera] Maybe drain monitors from -1 upto current CC event 1 upto:-1
2024-06-18T09:54:56.075009Z 2 [Note] [MY-000000] [Galera] Drain monitors from -1 up to -1
2024-06-18T09:54:56.075018Z 2 [Note] [MY-000000] [Galera] Process first view: d121003e-2d58-11ef-866f-5f21780be5d6 my uuid: d10cc1e1-2d58-11ef-b10e-6a6cd106f186
2024-06-18T09:54:56.075029Z 2 [Note] [MY-000000] [Galera] Server test-vm-1 connected to cluster at position d121003e-2d58-11ef-866f-5f21780be5d6:1 with ID d10cc1e1-2d58-11ef-b10e-6a6cd106f186
2024-06-18T09:54:56.075036Z 2 [Note] [MY-000000] [WSREP] Server status change disconnected -> connected
2024-06-18T09:54:56.075062Z 2 [Note] [MY-000000] [WSREP] wsrep_notify_cmd is not defined, skipping notification.
2024-06-18T09:54:56.075080Z 2 [Note] [MY-000000] [Galera] ####### My UUID: d10cc1e1-2d58-11ef-b10e-6a6cd106f186
2024-06-18T09:54:56.075088Z 2 [Note] [MY-000000] [Galera] Cert index reset to 00000000-0000-0000-0000-000000000000:-1 (proto: 10), state transfer needed: no
2024-06-18T09:54:56.075134Z 0 [Note] [MY-000000] [Galera] Service thread queue flushed.
2024-06-18T09:54:56.075174Z 2 [Note] [MY-000000] [Galera] ####### Assign initial position for certification: 00000000-0000-0000-0000-000000000000:-1, protocol version: -1
2024-06-18T09:54:56.075181Z 2 [Note] [MY-000000] [Galera] REPL Protocols: 10 (5)
2024-06-18T09:54:56.075187Z 2 [Note] [MY-000000] [Galera] ####### Adjusting cert position: -1 -> 1
2024-06-18T09:54:56.075206Z 0 [Note] [MY-000000] [Galera] Service thread queue flushed.
2024-06-18T09:54:56.171856Z 2 [Note] [MY-000000] [Galera] GCache history reset: 00000000-0000-0000-0000-000000000000:0 -> d121003e-2d58-11ef-866f-5f21780be5d6:0
2024-06-18T09:54:56.191108Z 2 [Note] [MY-000000] [Galera] ================================================
View:
  id: d121003e-2d58-11ef-866f-5f21780be5d6:1
  status: primary
  protocol_version: 4
  capabilities: MULTI-MASTER, CERTIFICATION, PARALLEL_APPLYING, REPLAY, ISOLATION, PAUSE, CAUSAL_READ, INCREMENTAL_WS, UNORDERED, PREORDERED, STREAMING, NBO
  final: no
  own_index: 0
  members(1):
        0: d10cc1e1-2d58-11ef-b10e-6a6cd106f186, test-vm-1
=================================================
2024-06-18T09:54:56.191197Z 2 [Note] [MY-000000] [WSREP] Server status change connected -> joiner
2024-06-18T09:54:56.191205Z 2 [Note] [MY-000000] [WSREP] wsrep_notify_cmd is not defined, skipping notification.
2024-06-18T09:54:56.191223Z 2 [Note] [MY-000000] [WSREP] Server status change joiner -> initializing
2024-06-18T09:54:56.191227Z 2 [Note] [MY-000000] [WSREP] wsrep_notify_cmd is not defined, skipping notification.
2024-06-18T09:54:56.196586Z 0 [Warning] [MY-010075] [Server] No existing UUID has been found, so we assume that this is the first time that this server has been started. Generating a new UUID: d1339387-2d58-11ef-8445-bc2411c64f02.
2024-06-18T09:54:56.277001Z 0 [Note] [MY-012366] [InnoDB] Using Linux native AIO
2024-06-18T09:54:56.277061Z 0 [Warning] [MY-013907] [InnoDB] Deprecated configuration parameters innodb_log_file_size and/or innodb_log_files_in_group have been used to compute innodb_redo_log_capacity=10737418240. Please use innodb_redo_log_capacity instead.
2024-06-18T09:54:56.277209Z 0 [Note] [MY-010747] [Server] Plugin 'FEDERATED' is disabled.
2024-06-18T09:54:56.277280Z 0 [Note] [MY-010747] [Server] Plugin 'ndbcluster' is disabled.
2024-06-18T09:54:56.277291Z 0 [Note] [MY-010747] [Server] Plugin 'ndbinfo' is disabled.
2024-06-18T09:54:56.277296Z 0 [Note] [MY-010747] [Server] Plugin 'ndb_transid_mysql_connection_map' is disabled.
2024-06-18T09:54:56.278584Z 3 [ERROR] [MY-011011] [Server] Failed to find valid data directory.
2024-06-18T09:54:56.278776Z 0 [ERROR] [MY-010020] [Server] Data Dictionary initialization failed.
2024-06-18T09:54:56.278808Z 0 [ERROR] [MY-010119] [Server] Aborting
2024-06-18T09:54:56.278816Z 0 [Note] [MY-000000] [WSREP] Initiating SST cancellation
2024-06-18T09:54:56.278823Z 0 [Note] [MY-000000] [Server] Giving 2 client threads a chance to die gracefully
2024-06-18T09:54:58.278983Z 0 [Note] [MY-000000] [WSREP] Server status change initializing -> disconnecting
2024-06-18T09:54:58.279045Z 1 [Note] [MY-000000] [WSREP] rollbacker thread exiting 1
2024-06-18T09:54:58.279094Z 0 [Note] [MY-000000] [WSREP] wsrep_notify_cmd is not defined, skipping notification.
2024-06-18T09:54:58.279147Z 0 [Note] [MY-000000] [Galera] Closing send monitor...
2024-06-18T09:54:58.279158Z 0 [Note] [MY-000000] [Galera] Closed send monitor.
2024-06-18T09:54:58.279168Z 0 [Note] [MY-000000] [Galera] gcomm: terminating thread
2024-06-18T09:54:58.279190Z 0 [Note] [MY-000000] [Galera] gcomm: joining thread
2024-06-18T09:54:58.279276Z 2 [ERROR] [MY-000000] [Galera] Exception: State wait was interrupted
2024-06-18T09:54:58.279360Z 2 [ERROR] [MY-000000] [Galera] View callback failed. This is unrecoverable, restart required. (FATAL)
         at /mnt/jenkins/workspace/pxc80-autobuild-RELEASE/test/percona-xtradb-cluster-8.0.33-25/percona-xtradb-cluster-galera/galera/src/replicator_smm.cpp:submit_view_info():2628
2024-06-18T09:54:58.279374Z 2 [Note] [MY-000000] [Galera] ReplicatorSMM::abort()
2024-06-18T09:54:58.279389Z 2 [Note] [MY-000000] [Galera] mysqld: Terminated.

@shigaev.s

This is the latest error

2024-06-18T09:54:56.278584Z 3 [ERROR] [MY-011011] [Server] Failed to find valid data directory.
2024-06-18T09:54:56.278776Z 0 [ERROR] [MY-010020] [Server] Data Dictionary initialization failed.
2024-06-18T09:54:56.278808Z 0 [ERROR] [MY-010119] [Server] Aborting

Make sure the MySQL config file has the correct data directory path and that the directory exists. After this, Clean the data directory and try bootstrapping again using the below command.

systemctl start mysql@bootstrap.service

The configuration file /etc/mysql/mysql.conf.d/mysqld.cnf states correctly:

[mysqld]
datadir                         = /var/lib/mysql
log-error                       = /var/log/mysql/error.log
pid-file                        = /var/run/mysqld/mysqld.pid
server-id                       = 103
socket                          = /var/run/mysqld/mysqld.sock

authentication_policy           = mysql_native_password

The directory exists:

root@test-vm-1:~# ls -l /var/lib/ | grep mysql
drwxr-x---  2 mysql     mysql     4096 июн 18 09:59 mysql
drwxr-xr-x  2 mysql     mysql     4096 июл 27  2023 mysql-files
drwxr-x---  2 mysql     mysql     4096 июн 17 11:23 mysql-keyring

--defaults-file=/etc/mysql/mysql.cnf was the config file in the earlier command, and I see you have /etc/mysql/mysql.conf.d/mysqld.cnf , Please use the correct config file.

The configuration file used in the command is:

mysqld --defaults-file=/etc/mysql/mysql.cnf -u root --wsrep-new-cluster

/etc/mysql/mysql.cnf:

#
# The Percona Server 8.0 configuration file.
#
# For explanations see
# http://dev.mysql.com/doc/mysql/en/server-system-variables.html
#
#
# * IMPORTANT: Additional settings that can override those from this file!
#   The files must end with '.cnf', otherwise they'll be ignored.
#
!includedir /etc/mysql/mysql.conf.d/
!includedir /etc/mysql/conf.d/

Which in turn includes the configuration /etc/mysql/mysql.conf.d/mysqld.cnf.
There are no other configurations.

Ok then, Clean the data directory and try bootstrapping again using the below command.

systemctl start mysql@bootstrap.service

if it fails again, Clean the data directory and try bootstrapping manually to see actual error,
(Make sure you use mysql user, as data directory has ‘mysql’ user ownership.)
mysqld --defaults-file=/etc/mysql/mysql.cnf --user=mysql --wsrep-new-cluster

Ok.

Clean data directory:

root@test-vm-1:~# rm -rf /var/lib/mysql/*
root@test-vm-1:~# ls -l /var/lib/mysql
total 0

bootstrap:

root@test-vm-1:~# systemctl start mysql@bootstrap.service
Job for mysql@bootstrap.service failed because the control process exited with error code.
See "systemctl status mysql@bootstrap.service" and "journalctl -xeu mysql@bootstrap.service" for details.

root@test-vm-1:~# systemctl status mysql@bootstrap.service
× mysql@bootstrap.service - Percona XtraDB Cluster with config /etc/default/mysql.bootstrap
     Loaded: loaded (/lib/systemd/system/mysql@.service; disabled; vendor preset: enabled)
     Active: failed (Result: exit-code) since Tue 2024-06-18 11:14:53 UTC; 12s ago
    Process: 9261 ExecStartPre=/usr/bin/mysql-systemd start-pre (code=exited, status=1/FAILURE)
    Process: 9299 ExecStopPost=/usr/bin/mysql-systemd stop-post (code=exited, status=0/SUCCESS)
        CPU: 89ms

июн 18 11:14:53 test-vm-1 systemd[1]: Starting Percona XtraDB Cluster with config /etc/default/mysql.bootstrap...
июн 18 11:14:53 test-vm-1 systemd[1]: mysql@bootstrap.service: Control process exited, code=exited, status=1/FAILURE
июн 18 11:14:53 test-vm-1 mysql-systemd[9299]:  WARNING: mysql pid file /var/run/mysqld/mysqld.pid empty or not readable
июн 18 11:14:53 test-vm-1 mysql-systemd[9299]:  WARNING: mysql may be already dead
июн 18 11:14:53 test-vm-1 systemd[1]: mysql@bootstrap.service: Failed with result 'exit-code'.
июн 18 11:14:53 test-vm-1 systemd[1]: Failed to start Percona XtraDB Cluster with config /etc/default/mysql.bootstrap.

datadir:

root@test-vm-1:~# ls -l /var/lib/mysql
total 0

Manual launch:

root@test-vm-1:~# mysqld --defaults-file=/etc/mysql/mysql.cnf --user=mysql --wsrep-new-cluster

No console output.
datadir:

root@test-vm-1:~# ls -l /var/lib/mysql
total 0

The log is also empty.

Interestingly, none of the 3 nodes can be bootstrap.

Here’s what else we managed to do.
Renamed the configuration file:

mv /etc/mysql/mysql.conf.d/mysqld.cnf /etc/mysql/mysql.conf.d/mysqld.cnf.back

Started the service:

systemctl start mysql

Then I stop the service:

systemctl stop mysql

The directory contains some data:

root@test-vm-1:~# ls -l /var/lib/mysql                                                                                                           
total 79304                                                                                                                                      
-rw-r----- 1 mysql mysql       56 июн 18 12:51  auto.cnf                                                                                         
-rw-r----- 1 mysql mysql      180 июн 18 12:51  binlog.000001                                                                                    
-rw-r----- 1 mysql mysql       16 июн 18 12:51  binlog.index                                                                                     
-rw------- 1 mysql mysql     1705 июн 18 12:51  ca-key.pem                                                                                       
-rw-r--r-- 1 mysql mysql     1120 июн 18 12:51  ca.pem                                                                                           
-rw-r--r-- 1 mysql mysql     1120 июн 18 12:51  client-cert.pem                                                                                  
-rw------- 1 mysql mysql     1705 июн 18 12:51  client-key.pem                                                                                   
-rw-r----- 1 mysql mysql   196608 июн 18 12:51 '#ib_16384_0.dblwr'                                                                               
-rw-r----- 1 mysql mysql  8585216 июн 18 12:51 '#ib_16384_1.dblwr'                                                                               
-rw-r----- 1 mysql mysql     3324 июн 18 12:51  ib_buffer_pool                                                                                   
-rw-r----- 1 mysql mysql 12582912 июн 18 12:51  ibdata1                                                                                          
drwxr-x--- 2 mysql mysql     4096 июн 18 12:51 '#innodb_redo'                                                                                    
drwxr-x--- 2 mysql mysql     4096 июн 18 12:51 '#innodb_temp'                                                                                    
drwxr-x--- 2 mysql mysql     4096 июн 18 12:51  mysql                                                                                            
-rw-r----- 1 mysql mysql 26214400 июн 18 12:51  mysql.ibd                                                                                        
drwxr-x--- 2 mysql mysql     4096 июн 18 12:51  performance_schema                                                                               
-rw------- 1 mysql mysql     1705 июн 18 12:51  private_key.pem                                                                                  
-rw-r--r-- 1 mysql mysql      452 июн 18 12:51  public_key.pem                                                                                   
-rw-r--r-- 1 mysql mysql     1120 июн 18 12:51  server-cert.pem                                                                                  
-rw------- 1 mysql mysql     1705 июн 18 12:51  server-key.pem                                                                                   
drwxr-x--- 2 mysql mysql     4096 июн 18 12:51  sys                                                                                              
-rw-r----- 1 mysql mysql 16777216 июн 18 12:51  undo_001                                                                                         
-rw-r----- 1 mysql mysql 16777216 июн 18 12:51  undo_002

I return the configuration file:

mv /etc/mysql/mysql.conf.d/mysqld.cnf.back /etc/mysql/mysql.conf.d/mysqld.cnf

Bootstrap:

sudo -u mysql mysqld --defaults-file=/etc/mysql/mysql.cnf --wsrep-new-cluster

status:

root@test-vm-1:~# systemctl status mysql@bootstrap.service 
× mysql@bootstrap.service - Percona XtraDB Cluster with config /etc/default/mysql.bootstrap
     Loaded: loaded (/lib/systemd/system/mysql@.service; disabled; vendor preset: enabled)
     Active: failed (Result: exit-code) since Tue 2024-06-18 12:54:47 UTC; 5min ago
    Process: 11878 ExecStartPre=/usr/bin/mysql-systemd start-pre (code=exited, status=0/SUCCESS)
    Process: 11915 ExecStartPre=/bin/sh -c systemctl unset-environment _WSREP_START_POSITION (code=exited, status=0/SUCCESS)
    Process: 11917 ExecStartPre=/bin/sh -c VAR=`bash /usr/bin/mysql-systemd galera-recovery`; [ $? -eq 0 ] && systemctl set-environment _WSREP_S>
    Process: 12042 ExecStart=/usr/sbin/mysqld $EXTRA_ARGS $_WSREP_START_POSITION (code=exited, status=1/FAILURE)
    Process: 12043 ExecStopPost=/usr/bin/mysql-systemd stop-post (code=exited, status=0/SUCCESS)
   Main PID: 12042 (code=exited, status=1/FAILURE)
     Status: "Server shutdown complete"
      Error: 9 (Bad file descriptor)
        CPU: 1.515s

июн 18 12:54:43 test-vm-1 systemd[1]: Starting Percona XtraDB Cluster with config /etc/default/mysql.bootstrap...
июн 18 12:54:47 test-vm-1 systemd[1]: mysql@bootstrap.service: Main process exited, code=exited, status=1/FAILURE
июн 18 12:54:47 test-vm-1 mysql-systemd[12043]:  WARNING: mysql pid file /var/run/mysqld/mysqld.pid empty or not readable
июн 18 12:54:47 test-vm-1 mysql-systemd[12043]:  WARNING: mysql may be already dead
июн 18 12:54:47 test-vm-1 systemd[1]: mysql@bootstrap.service: Failed with result 'exit-code'.
июн 18 12:54:47 test-vm-1 systemd[1]: Failed to start Percona XtraDB Cluster with config /etc/default/mysql.bootstrap.
июн 18 12:54:47 test-vm-1 systemd[1]: mysql@bootstrap.service: Consumed 1.515s CPU time.

Logs:

...
2024-06-18T12:36:29.163907Z 1 [Note] [MY-000000] [Galera] ================================================
View:
  id: 62a80f1e-2d6f-11ef-9e38-5795e4c66d11:1
  status: primary
  protocol_version: 4
  capabilities: MULTI-MASTER, CERTIFICATION, PARALLEL_APPLYING, REPLAY, ISOLATION, PAUSE, CAUSAL_READ, INCREMENTAL_WS, UNORDERED, PREORDERED, STREAMING, NBO
  final: no
  own_index: 0
  members(1):
        0: 62a75415-2d6f-11ef-9dc8-67caa526e352, test-vm-1
=================================================
2024-06-18T12:36:29.163927Z 1 [Note] [MY-000000] [WSREP] Server status change connected -> joiner
2024-06-18T12:36:29.163934Z 1 [Note] [MY-000000] [WSREP] wsrep_notify_cmd is not defined, skipping notification.
2024-06-18T12:36:29.163945Z 1 [Note] [MY-000000] [WSREP] Server status change joiner -> initializing
2024-06-18T12:36:29.163949Z 1 [Note] [MY-000000] [WSREP] wsrep_notify_cmd is not defined, skipping notification.
2024-06-18T12:36:29.166083Z 0 [Note] [MY-012366] [InnoDB] Using Linux native AIO
2024-06-18T12:36:29.166116Z 0 [Warning] [MY-013907] [InnoDB] Deprecated configuration parameters innodb_log_file_size and/or innodb_log_files_in_group have been used to compute innodb_redo_log_capacity=10737418240. Please use innodb_redo_log_capacity instead.
2024-06-18T12:36:29.166248Z 0 [Note] [MY-010747] [Server] Plugin 'FEDERATED' is disabled.
2024-06-18T12:36:29.166302Z 0 [Note] [MY-010747] [Server] Plugin 'ndbcluster' is disabled.
2024-06-18T12:36:29.166315Z 0 [Note] [MY-010747] [Server] Plugin 'ndbinfo' is disabled.
2024-06-18T12:36:29.166320Z 0 [Note] [MY-010747] [Server] Plugin 'ndb_transid_mysql_connection_map' is disabled.
2024-06-18T12:36:29.167479Z 3 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2024-06-18T12:36:29.167501Z 3 [Note] [MY-013546] [InnoDB] Atomic write enabled
2024-06-18T12:36:29.167526Z 3 [Note] [MY-012932] [InnoDB] PUNCH HOLE support available
2024-06-18T12:36:29.167538Z 3 [Note] [MY-012944] [InnoDB] Uses event mutexes
2024-06-18T12:36:29.167543Z 3 [Note] [MY-012945] [InnoDB] GCC builtin __atomic_thread_fence() is used for memory barrier
2024-06-18T12:36:29.167556Z 3 [Note] [MY-012948] [InnoDB] Compressed tables use zlib 1.2.13
2024-06-18T12:36:29.170901Z 3 [Note] [MY-012951] [InnoDB] Using hardware accelerated crc32 and polynomial multiplication.
2024-06-18T12:36:29.171309Z 3 [Note] [MY-012203] [InnoDB] Directories to scan './'
2024-06-18T12:36:29.171344Z 3 [Note] [MY-012204] [InnoDB] Scanning './'
2024-06-18T12:36:29.175176Z 3 [Note] [MY-012208] [InnoDB] Completed space ID check of 7 files.
2024-06-18T12:36:29.175995Z 3 [Note] [MY-012955] [InnoDB] Initializing buffer pool, total size = 1.000000G, instances = 16, chunk size =64.000000M 
2024-06-18T12:36:29.246662Z 3 [Note] [MY-012957] [InnoDB] Completed initialization of buffer pool
2024-06-18T12:36:29.258551Z 0 [Note] [MY-011825] [InnoDB] lru_manager worker priority: -20
2024-06-18T12:36:29.258591Z 0 [Note] [MY-011825] [InnoDB] lru_manager worker priority: -20
2024-06-18T12:36:29.258628Z 0 [Note] [MY-011951] [InnoDB] page_cleaner coordinator priority: -20
2024-06-18T12:36:29.258812Z 0 [Note] [MY-011954] [InnoDB] page_cleaner worker priority: -20
2024-06-18T12:36:29.258891Z 0 [Note] [MY-011954] [InnoDB] page_cleaner worker priority: -20
2024-06-18T12:36:29.258922Z 0 [Note] [MY-011954] [InnoDB] page_cleaner worker priority: -20
2024-06-18T12:36:29.258979Z 0 [Note] [MY-011825] [InnoDB] lru_manager worker priority: -20
2024-06-18T12:36:29.259079Z 0 [Note] [MY-011825] [InnoDB] lru_manager worker priority: -20
2024-06-18T12:36:29.259212Z 0 [Note] [MY-011825] [InnoDB] lru_manager worker priority: -20
2024-06-18T12:36:29.259292Z 0 [Note] [MY-011825] [InnoDB] lru_manager worker priority: -20
2024-06-18T12:36:29.259434Z 0 [Note] [MY-011825] [InnoDB] lru_manager worker priority: -20
2024-06-18T12:36:29.259471Z 0 [Note] [MY-011825] [InnoDB] lru_manager worker priority: -20
2024-06-18T12:36:29.259521Z 0 [Note] [MY-011825] [InnoDB] lru_manager worker priority: -20
2024-06-18T12:36:29.259565Z 0 [Note] [MY-011825] [InnoDB] lru_manager worker priority: -20
2024-06-18T12:36:29.259689Z 0 [Note] [MY-011825] [InnoDB] lru_manager worker priority: -20
2024-06-18T12:36:29.259741Z 0 [Note] [MY-011825] [InnoDB] lru_manager worker priority: -20
2024-06-18T12:36:29.259797Z 0 [Note] [MY-011825] [InnoDB] lru_manager worker priority: -20
2024-06-18T12:36:29.259847Z 0 [Note] [MY-011825] [InnoDB] lru_manager worker priority: -20
2024-06-18T12:36:29.259880Z 0 [Note] [MY-011825] [InnoDB] lru_manager worker priority: -20
2024-06-18T12:36:29.259932Z 0 [Note] [MY-011825] [InnoDB] lru_manager worker priority: -20
2024-06-18T12:36:29.261465Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_0.dblwr' for doublewrite
2024-06-18T12:36:29.263234Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_1.dblwr' for doublewrite
2024-06-18T12:36:29.265804Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_2.dblwr' for doublewrite
2024-06-18T12:36:29.266652Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_3.dblwr' for doublewrite
2024-06-18T12:36:29.268820Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_4.dblwr' for doublewrite
2024-06-18T12:36:29.269533Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_5.dblwr' for doublewrite
2024-06-18T12:36:29.271744Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_6.dblwr' for doublewrite
2024-06-18T12:36:29.272359Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_7.dblwr' for doublewrite
2024-06-18T12:36:29.274431Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_8.dblwr' for doublewrite
2024-06-18T12:36:29.274837Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_9.dblwr' for doublewrite
2024-06-18T12:36:29.277038Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_10.dblwr' for doublewrite
2024-06-18T12:36:29.277722Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_11.dblwr' for doublewrite
2024-06-18T12:36:29.279705Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_12.dblwr' for doublewrite
2024-06-18T12:36:29.280444Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_13.dblwr' for doublewrite
2024-06-18T12:36:29.282474Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_14.dblwr' for doublewrite
2024-06-18T12:36:29.283109Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_15.dblwr' for doublewrite
2024-06-18T12:36:29.285064Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_16.dblwr' for doublewrite
2024-06-18T12:36:29.285852Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_17.dblwr' for doublewrite
2024-06-18T12:36:29.287886Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_18.dblwr' for doublewrite
2024-06-18T12:36:29.288595Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_19.dblwr' for doublewrite
2024-06-18T12:36:29.290527Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_20.dblwr' for doublewrite
2024-06-18T12:36:29.291332Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_21.dblwr' for doublewrite
2024-06-18T12:36:29.293252Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_22.dblwr' for doublewrite
2024-06-18T12:36:29.293945Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_23.dblwr' for doublewrite
2024-06-18T12:36:29.295812Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_24.dblwr' for doublewrite
2024-06-18T12:36:29.296356Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_25.dblwr' for doublewrite
2024-06-18T12:36:29.298237Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_26.dblwr' for doublewrite
2024-06-18T12:36:29.298502Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_27.dblwr' for doublewrite
2024-06-18T12:36:29.300352Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_28.dblwr' for doublewrite
2024-06-18T12:36:29.300570Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_29.dblwr' for doublewrite
2024-06-18T12:36:29.302563Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_30.dblwr' for doublewrite
2024-06-18T12:36:29.302795Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_31.dblwr' for doublewrite
2024-06-18T12:36:29.304970Z 3 [Note] [MY-013566] [InnoDB] Double write buffer files: 32
2024-06-18T12:36:29.304986Z 3 [Note] [MY-013565] [InnoDB] Double write buffer pages per instance: 4
2024-06-18T12:36:29.305006Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_0.dblwr' for doublewrite
2024-06-18T12:36:29.305021Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_1.dblwr' for doublewrite
2024-06-18T12:36:29.305033Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_2.dblwr' for doublewrite
2024-06-18T12:36:29.305047Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_3.dblwr' for doublewrite
2024-06-18T12:36:29.305059Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_4.dblwr' for doublewrite
2024-06-18T12:36:29.305073Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_5.dblwr' for doublewrite
2024-06-18T12:36:29.305085Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_6.dblwr' for doublewrite
2024-06-18T12:36:29.305097Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_7.dblwr' for doublewrite
2024-06-18T12:36:29.305108Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_8.dblwr' for doublewrite
2024-06-18T12:36:29.305119Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_9.dblwr' for doublewrite
2024-06-18T12:36:29.305132Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_10.dblwr' for doublewrite
2024-06-18T12:36:29.305157Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_11.dblwr' for doublewrite
2024-06-18T12:36:29.305170Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_12.dblwr' for doublewrite
2024-06-18T12:36:29.305194Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_13.dblwr' for doublewrite
2024-06-18T12:36:29.305206Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_14.dblwr' for doublewrite
2024-06-18T12:36:29.305218Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_15.dblwr' for doublewrite
2024-06-18T12:36:29.305231Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_16.dblwr' for doublewrite
2024-06-18T12:36:29.305243Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_17.dblwr' for doublewrite
2024-06-18T12:36:29.305255Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_18.dblwr' for doublewrite
2024-06-18T12:36:29.305267Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_19.dblwr' for doublewrite
2024-06-18T12:36:29.305278Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_20.dblwr' for doublewrite
2024-06-18T12:36:29.305305Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_21.dblwr' for doublewrite
2024-06-18T12:36:29.305317Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_22.dblwr' for doublewrite
2024-06-18T12:36:29.305328Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_23.dblwr' for doublewrite
2024-06-18T12:36:29.305339Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_24.dblwr' for doublewrite
2024-06-18T12:36:29.305350Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_25.dblwr' for doublewrite
2024-06-18T12:36:29.305361Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_26.dblwr' for doublewrite
2024-06-18T12:36:29.305373Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_27.dblwr' for doublewrite
2024-06-18T12:36:29.305383Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_28.dblwr' for doublewrite
2024-06-18T12:36:29.305394Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_29.dblwr' for doublewrite
2024-06-18T12:36:29.305405Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_30.dblwr' for doublewrite
2024-06-18T12:36:29.305416Z 3 [Note] [MY-013532] [InnoDB] Using './#ib_16384_31.dblwr' for doublewrite
2024-06-18T12:36:29.375217Z 3 [Note] [MY-013883] [InnoDB] The latest found checkpoint is at lsn = 19738353 in redo log file ./#innodb_redo/#ib_redo6.
2024-06-18T12:36:29.375416Z 3 [Note] [MY-013086] [InnoDB] Starting to parse redo log at lsn = 19738171, whereas checkpoint_lsn = 19738353 and start_lsn = 19738112
2024-06-18T12:36:29.387853Z 3 [Note] [MY-013083] [InnoDB] Log background threads are being started...
2024-06-18T12:36:29.388920Z 3 [Note] [MY-012532] [InnoDB] Applying a batch of 0 redo log records ...
2024-06-18T12:36:29.388943Z 3 [Note] [MY-012535] [InnoDB] Apply batch completed!
2024-06-18T12:36:29.389643Z 3 [Note] [MY-013252] [InnoDB] Using undo tablespace './undo_001'.
2024-06-18T12:36:29.390634Z 3 [Note] [MY-013252] [InnoDB] Using undo tablespace './undo_002'.
2024-06-18T12:36:29.391596Z 3 [Note] [MY-012910] [InnoDB] Opened 2 existing undo tablespaces.
2024-06-18T12:36:29.391652Z 3 [Note] [MY-011980] [InnoDB] GTID recovery trx_no: 3602
2024-06-18T12:36:29.429492Z 3 [Note] [MY-013776] [InnoDB] Parallel initialization of rseg complete
2024-06-18T12:36:29.429541Z 3 [Note] [MY-013777] [InnoDB] Time taken to initialize rseg using 4 thread: 37893 ms.
2024-06-18T12:36:29.429629Z 3 [Note] [MY-012923] [InnoDB] Creating shared tablespace for temporary tables
2024-06-18T12:36:29.429692Z 3 [Note] [MY-012265] [InnoDB] Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2024-06-18T12:36:29.434531Z 3 [Note] [MY-012266] [InnoDB] File './ibtmp1' size is now 12 MB.
2024-06-18T12:36:29.434664Z 3 [Note] [MY-013627] [InnoDB] Scanning temp tablespace dir:'./#innodb_temp/'
2024-06-18T12:36:29.471866Z 3 [Note] [MY-013018] [InnoDB] Created 128 and tracked 128 new rollback segment(s) in the temporary tablespace. 128 are now active.
2024-06-18T12:36:29.472605Z 3 [Note] [MY-012976] [InnoDB] Percona XtraDB (http://www.percona.com) 8.0.33-25 started; log sequence number 19738363
2024-06-18T12:36:29.473693Z 3 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
2024-06-18T12:36:29.487299Z 3 [Note] [MY-011089] [Server] Data dictionary restarting version '80023'.
2024-06-18T12:36:29.610780Z 3 [Note] [MY-012357] [InnoDB] Reading DD tablespace files
2024-06-18T12:36:29.611536Z 3 [Note] [MY-012356] [InnoDB] Scanned 9 tablespaces. Validated 9.
2024-06-18T12:36:29.627476Z 3 [Note] [MY-000000] [WSREP] wsrep_init_schema_and_SR (nil)
2024-06-18T12:36:29.637544Z 3 [System] [MY-000000] [WSREP] PXC upgrade completed successfully
2024-06-18T12:36:29.637611Z 3 [Note] [MY-010006] [Server] Using data dictionary with version '80023'.
2024-06-18T12:36:29.646674Z 0 [Note] [MY-011332] [Server] Plugin mysqlx reported: 'IPv6 is available'
2024-06-18T12:36:29.646828Z 0 [Note] [MY-011323] [Server] Plugin mysqlx reported: 'X Plugin ready for connections. bind-address: '::' port: 33060'
2024-06-18T12:36:29.646851Z 0 [Note] [MY-011323] [Server] Plugin mysqlx reported: 'X Plugin ready for connections. socket: '/var/run/mysqld/mysqlx.sock''
2024-06-18T12:36:29.684412Z 0 [Note] [MY-010856] [Server] Failed to open the crashed binlog file when source server is recovering it.
2024-06-18T12:36:29.708190Z 0 [Note] [MY-013911] [Server] Crash recovery finished in binlog engine. No attempts to commit, rollback or prepare any transactions.
2024-06-18T12:36:29.708233Z 0 [Note] [MY-013911] [Server] Crash recovery finished in InnoDB engine. No attempts to commit, rollback or prepare any transactions.
2024-06-18T12:36:29.712133Z 0 [Note] [MY-012487] [InnoDB] DDL log recovery : begin
2024-06-18T12:36:29.712610Z 0 [Note] [MY-012488] [InnoDB] DDL log recovery : end
2024-06-18T12:36:29.712880Z 0 [Note] [MY-011946] [InnoDB] Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
2024-06-18T12:36:29.713725Z 0 [Note] [MY-011946] [InnoDB] Buffer pool(s) load completed at 240618 12:36:29
2024-06-18T12:36:29.746488Z 0 [Note] [MY-010182] [Server] Found ca.pem, server-cert.pem and server-key.pem in data directory. Trying to enable SSL support using them.
2024-06-18T12:36:29.748789Z 0 [Note] [MY-010304] [Server] Skipping generation of SSL certificates as certificate files are present in data directory.
2024-06-18T12:36:29.751593Z 0 [Warning] [MY-010068] [Server] CA certificate ca.pem is self signed.
2024-06-18T12:36:29.751622Z 0 [System] [MY-013602] [Server] Channel mysql_main configured to support TLS. Encrypted connections are now supported for this channel.
2024-06-18T12:36:29.751899Z 0 [Note] [MY-010308] [Server] Skipping generation of RSA key pair through --sha256_password_auto_generate_rsa_keys as key files are present in data directory.
2024-06-18T12:36:29.752175Z 0 [Note] [MY-010308] [Server] Skipping generation of RSA key pair through --caching_sha2_password_auto_generate_rsa_keys as key files are present in data directory.
2024-06-18T12:36:29.755144Z 0 [Note] [MY-010252] [Server] Server hostname (bind-address): '*'; port: 3306
2024-06-18T12:36:29.755202Z 0 [Note] [MY-010253] [Server] IPv6 is available.
2024-06-18T12:36:29.755213Z 0 [Note] [MY-010264] [Server]   - '::' resolves to '::';
2024-06-18T12:36:29.755230Z 0 [Note] [MY-010251] [Server] Server socket created on IP: '::'.
2024-06-18T12:36:29.791926Z 0 [Note] [MY-011025] [Repl] Failed to start replica threads for channel ''.
2024-06-18T12:36:29.796120Z 0 [Note] [MY-000000] [WSREP] Initialized wsrep sidno 2
2024-06-18T12:36:29.796158Z 0 [Note] [MY-000000] [Galera] Server initialized
2024-06-18T12:36:29.796145Z 7 [Note] [MY-010051] [Server] Event Scheduler: scheduler thread started with id 7
2024-06-18T12:36:29.796176Z 0 [Note] [MY-000000] [WSREP] Server status change initializing -> initialized
2024-06-18T12:36:29.796319Z 0 [Note] [MY-000000] [WSREP] wsrep_notify_cmd is not defined, skipping notification.
2024-06-18T12:36:29.796422Z 1 [Note] [MY-000000] [Galera] Bootstrapping a new cluster, setting initial position to 00000000-0000-0000-0000-000000000000:-1
2024-06-18T12:36:29.803184Z 11 [Note] [MY-000000] [WSREP] Starting applier thread 11
2024-06-18T12:36:29.803256Z 10 [Note] [MY-000000] [WSREP] Starting applier thread 10
2024-06-18T12:36:29.803461Z 13 [Note] [MY-000000] [WSREP] Starting applier thread 13
2024-06-18T12:36:29.803415Z 14 [Note] [MY-000000] [WSREP] Starting applier thread 14
2024-06-18T12:36:29.803451Z 12 [Note] [MY-000000] [WSREP] Starting applier thread 12
2024-06-18T12:36:29.803717Z 15 [Note] [MY-000000] [WSREP] Starting applier thread 15
2024-06-18T12:36:29.803779Z 16 [Note] [MY-000000] [WSREP] Starting applier thread 16
2024-06-18T12:36:29.804364Z 18 [Note] [MY-000000] [WSREP] Starting applier thread 18
2024-06-18T12:36:29.804633Z 0 [Note] [MY-011240] [Server] Plugin mysqlx reported: 'Using SSL configuration from MySQL Server'
2024-06-18T12:36:29.804336Z 17 [Note] [MY-000000] [WSREP] Starting applier thread 17
2024-06-18T12:36:29.804981Z 19 [Note] [MY-000000] [WSREP] Starting applier thread 19
2024-06-18T12:36:29.805147Z 23 [Note] [MY-000000] [WSREP] Starting applier thread 23
2024-06-18T12:36:29.805092Z 21 [Note] [MY-000000] [WSREP] Starting applier thread 21
2024-06-18T12:36:29.805205Z 22 [Note] [MY-000000] [WSREP] Starting applier thread 22
2024-06-18T12:36:29.805298Z 20 [Note] [MY-000000] [WSREP] Starting applier thread 20
2024-06-18T12:36:29.806435Z 24 [Note] [MY-000000] [WSREP] Starting applier thread 24
2024-06-18T12:36:29.807251Z 0 [Note] [MY-011243] [Server] Plugin mysqlx reported: 'Using OpenSSL for TLS connections'
2024-06-18T12:36:29.807379Z 0 [System] [MY-011323] [Server] X Plugin ready for connections. Bind-address: '::' port: 33060, socket: /var/run/mysqld/mysqlx.sock
2024-06-18T12:36:29.807469Z 0 [System] [MY-010931] [Server] /usr/sbin/mysqld: ready for connections. Version: '8.0.33-25.1'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  Percona XtraDB Cluster (GPL), Release rel25, Revision 0c56202, WSREP version 26.1.4.3.
2024-06-18T12:36:29.810102Z 9 [Note] [MY-000000] [WSREP] Cluster table is empty, not recovering transactions
2024-06-18T12:36:29.810221Z 1 [Note] [MY-000000] [WSREP] Server status change initialized -> joined
2024-06-18T12:36:29.810232Z 1 [Note] [MY-000000] [WSREP] wsrep_notify_cmd is not defined, skipping notification.
2024-06-18T12:36:29.810255Z 1 [Note] [MY-000000] [WSREP] wsrep_notify_cmd is not defined, skipping notification.
2024-06-18T12:36:29.820529Z 1 [Note] [MY-000000] [Galera] Recording CC from group: 1
2024-06-18T12:36:29.820567Z 1 [Note] [MY-000000] [Galera] Lowest cert index boundary for CC from group: 1
2024-06-18T12:36:29.820575Z 1 [Note] [MY-000000] [Galera] Min available from gcache for CC from group: 1
2024-06-18T12:36:29.820643Z 1 [Note] [MY-000000] [Galera] Server test-vm-1 synced with group
2024-06-18T12:36:29.820652Z 1 [Note] [MY-000000] [WSREP] Server status change joined -> synced
2024-06-18T12:36:29.820658Z 1 [Note] [MY-000000] [WSREP] Synchronized with group, ready for connections
2024-06-18T12:36:29.820664Z 1 [Note] [MY-000000] [WSREP] wsrep_notify_cmd is not defined, skipping notification.
Log of wsrep recovery (--wsrep-recover):
 INFO: WSREP: Running position recovery with --log_error='/var/lib/mysql/wsrep_recovery_verbose.nueBT3' --pid-file='/var/lib/mysql/test-vm-1-recover.pid'
 INFO: WSREP: Recovered position 00000000-0000-0000-0000-000000000000:-1
Log of wsrep recovery (--wsrep-recover):
 INFO: WSREP: Running position recovery with --log_error='/var/lib/mysql/wsrep_recovery_verbose.PZLEW6' --pid-file='/var/lib/mysql/test-vm-1-recover.pid'
 INFO: WSREP: Recovered position 00000000-0000-0000-0000-000000000000:-1

At the same time, the data directory by location increased:

root@test-vm-1:~# du --max-depth=1 -h /var/lib/mysql
11G     /var/lib/mysql/#innodb_redo
4,0K    /var/lib/mysql/#innodb_temp
116K    /var/lib/mysql/sys
1,7M    /var/lib/mysql/performance_schema
372K    /var/lib/mysql/mysql
11G     /var/lib/mysql
...
rw-r----- 1 mysql mysql       56 июн 18 12:51  auto.cnf
-rw-r----- 1 mysql mysql      180 июн 18 12:51  binlog.000001
-rw-r----- 1 mysql mysql       16 июн 18 12:51  binlog.index
-rw------- 1 mysql mysql     1705 июн 18 12:51  ca-key.pem
-rw-r--r-- 1 mysql mysql     1120 июн 18 12:51  ca.pem
-rw-r--r-- 1 mysql mysql     1120 июн 18 12:51  client-cert.pem
-rw------- 1 mysql mysql     1705 июн 18 12:51  client-key.pem
-rw-r----- 1 mysql mysql    65536 июн 18 12:55 '#ib_16384_0.dblwr'
-rw-r----- 1 mysql mysql    65536 июн 18 12:55 '#ib_16384_10.dblwr'
-rw-r----- 1 mysql mysql   589824 июн 18 12:54 '#ib_16384_11.dblwr'
-rw-r----- 1 mysql mysql    65536 июн 18 12:55 '#ib_16384_12.dblwr'
-rw-r----- 1 mysql mysql   589824 июн 18 12:54 '#ib_16384_13.dblwr'
-rw-r----- 1 mysql mysql    65536 июн 18 12:55 '#ib_16384_14.dblwr'
-rw-r----- 1 mysql mysql   589824 июн 18 12:54 '#ib_16384_15.dblwr'
-rw-r----- 1 mysql mysql    65536 июн 18 12:55 '#ib_16384_16.dblwr'
-rw-r----- 1 mysql mysql   589824 июн 18 12:54 '#ib_16384_17.dblwr'
-rw-r----- 1 mysql mysql    65536 июн 18 12:55 '#ib_16384_18.dblwr'
-rw-r----- 1 mysql mysql   589824 июн 18 12:54 '#ib_16384_19.dblwr'
-rw-r----- 1 mysql mysql   589824 июн 18 12:54 '#ib_16384_1.dblwr'
-rw-r----- 1 mysql mysql    65536 июн 18 12:55 '#ib_16384_20.dblwr'
-rw-r----- 1 mysql mysql   589824 июн 18 12:54 '#ib_16384_21.dblwr'
-rw-r----- 1 mysql mysql    65536 июн 18 12:55 '#ib_16384_22.dblwr'
-rw-r----- 1 mysql mysql   589824 июн 18 12:54 '#ib_16384_23.dblwr'
-rw-r----- 1 mysql mysql    65536 июн 18 12:55 '#ib_16384_24.dblwr'
-rw-r----- 1 mysql mysql   589824 июн 18 12:54 '#ib_16384_25.dblwr'
-rw-r----- 1 mysql mysql    65536 июн 18 12:54 '#ib_16384_26.dblwr'
-rw-r----- 1 mysql mysql   589824 июн 18 12:54 '#ib_16384_27.dblwr'
-rw-r----- 1 mysql mysql    65536 июн 18 12:54 '#ib_16384_28.dblwr'
-rw-r----- 1 mysql mysql   589824 июн 18 12:54 '#ib_16384_29.dblwr'
-rw-r----- 1 mysql mysql    65536 июн 18 12:55 '#ib_16384_2.dblwr'
-rw-r----- 1 mysql mysql    65536 июн 18 12:54 '#ib_16384_30.dblwr'
-rw-r----- 1 mysql mysql   589824 июн 18 12:54 '#ib_16384_31.dblwr'
-rw-r----- 1 mysql mysql   589824 июн 18 12:54 '#ib_16384_3.dblwr'
-rw-r----- 1 mysql mysql    65536 июн 18 12:55 '#ib_16384_4.dblwr'
-rw-r----- 1 mysql mysql   589824 июн 18 12:54 '#ib_16384_5.dblwr'
-rw-r----- 1 mysql mysql    65536 июн 18 12:55 '#ib_16384_6.dblwr'
-rw-r----- 1 mysql mysql   589824 июн 18 12:54 '#ib_16384_7.dblwr'
-rw-r----- 1 mysql mysql    65536 июн 18 12:55 '#ib_16384_8.dblwr'
-rw-r----- 1 mysql mysql   589824 июн 18 12:54 '#ib_16384_9.dblwr'
-rw-r----- 1 mysql mysql     3324 июн 18 12:51  ib_buffer_pool
-rw-r----- 1 mysql mysql 12582912 июн 18 12:55  ibdata1
drwxr-x--- 2 mysql mysql     4096 июн 18 12:55 '#innodb_redo'
drwxr-x--- 2 mysql mysql     4096 июн 18 12:55 '#innodb_temp'
drwxr-x--- 2 mysql mysql     4096 июн 18 12:51  mysql
-rw-r----- 1 mysql mysql 26214400 июн 18 12:55  mysql.ibd
drwxr-x--- 2 mysql mysql     4096 июн 18 12:51  performance_schema
-rw------- 1 mysql mysql     1705 июн 18 12:51  private_key.pem
-rw-r--r-- 1 mysql mysql      452 июн 18 12:51  public_key.pem
-rw-r--r-- 1 mysql mysql     1120 июн 18 12:51  server-cert.pem
-rw------- 1 mysql mysql     1705 июн 18 12:51  server-key.pem
drwxr-x--- 2 mysql mysql     4096 июн 18 12:51  sys
-rw-r----- 1 mysql mysql 16777216 июн 18 12:55  undo_001
-rw-r----- 1 mysql mysql 16777216 июн 18 12:55  undo_002

Let me add that the configuration file itself is valid.
Works in stage and production.
The problem arose precisely with a clean installation and the inability to bootstrap and launch the cluster.

Any thoughts on launching and bootstrap?
I’ll try to purge, install it again and check.

We managed to run the bootstrap from the launch example: Configure a cluster on Debian or Ubuntu - Percona XtraDB Cluster

But with the configuration from the first message it refuses to start at all.
Those. Some of the parameters have an effect, but it has not yet been possible to determine which ones. Unfortunately, there are no logs or error messages.

Launched with configuration validation:

root@test-vm-1:~# sudo -u mysql mysqld --defaults-file=/etc/mysql/mysql.cnf --validate-config --wsrep-new-cluster
2024-06-20T12:06:47.704460Z 0 [Note] [MY-013667] [Server] Error-log destination "stderr" is not a file. Can not restore error log messages from previous run.
2024-06-20T12:06:47.701357Z 0 [Warning] [MY-000081] [Server] option 'wsrep_max_ws_size': unsigned value 2147483648 adjusted to 2147483647.
2024-06-20T12:06:47.701590Z 0 [Warning] [MY-010101] [Server] Insecure configuration for --secure-file-priv: Location is accessible to all OS users. Consider choosing a different directory.
2024-06-20T12:06:47.701595Z 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.
2024-06-20T12:06:47.704786Z 0 [Note] [MY-000000] [Galera] Loading provider /usr/lib/libgalera_smm.so initial position: 00000000-0000-0000-0000-000000000000:-1
2024-06-20T12:06:47.704818Z 0 [Note] [MY-000000] [Galera] wsrep_load(): loading provider library '/usr/lib/libgalera_smm.so'
2024-06-20T12:06:47.705509Z 0 [Note] [MY-000000] [Galera] wsrep_load(): Galera 4.15(6983fb2) by Codership Oy <info@codership.com> (modified by Percona <https://percona.com/>) loaded successfully.
2024-06-20T12:06:47.705555Z 0 [Note] [MY-000000] [Galera] CRC-32C: using 64-bit x86 acceleration.
2024-06-20T12:06:47.705759Z 0 [Warning] [MY-000000] [Galera] Parameter 'socket.ssl_compression' is deprecated and will be removed in future versions
2024-06-20T12:06:47.705817Z 0 [Warning] [MY-000000] [Galera] Could not open state file for reading: '/var/lib/mysql//grastate.dat'
2024-06-20T12:06:47.705828Z 0 [Warning] [MY-000000] [Galera] No persistent state found. Bootstraping with default state
2024-06-20T12:06:47.705874Z 0 [Note] [MY-000000] [Galera] Found saved state: 00000000-0000-0000-0000-000000000000:-1, safe_to_bootstrap: 1
2024-06-20T12:06:47.706655Z 0 [Note] [MY-000000] [Galera] Generated new GCache ID: 91a7b7cf-2efd-11ef-a022-a2bfcfd53b2a
2024-06-20T12:06:47.706677Z 0 [Note] [MY-000000] [Galera] GCache DEBUG: opened preamble:
Version: 0
UUID: 00000000-0000-0000-0000-000000000000
Seqno: -1 - -1
Offset: -1
Synced: 0
EncVersion: 0
Encrypted: 0
MasterKeyConst UUID: 91a7b7cf-2efd-11ef-a022-a2bfcfd53b2a
MasterKey UUID: 00000000-0000-0000-0000-000000000000
MasterKey ID: 0
2024-06-20T12:06:47.706695Z 0 [Note] [MY-000000] [Galera] Skipped GCache ring buffer recovery: could not determine history UUID.
2024-06-20T12:06:47.713036Z 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/; base_host = 10.9.2.103; 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 = PT1S; evs.inactive_timeout = PT20S; evs.join_retrans_period = PT1S; evs.max_install_timeouts = 3; evs.send_window = 512; evs.stats_report_period = PT1M; evs.suspect_timeout = PT5S; evs.use_aggregate = true; evs.user_send_window = 512; evs.view_forget_timeout = PT24H; gcache.dir = /var/lib/mysql/; 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 = 4; gcache.mem_size = 0; gcache.name = galera.cache; gcache.page_size = 32M; gcache.recover = yes; gcache.size = 1024M; gcomm.thread_prio = ; gcs.fc_auto_evict_threshold = 0.75; gcs.fc_auto_evict_window = 0; gcs.fc_debug = 0; gcs.fc_factor = 0.9; gcs.fc_limit = 5000; gcs.fc_master_slave = no; gcs.fc_single_primary = no; gcs.max_packet_size = 131072; gcs.max_throttle = 0.25; gcs.recv_q_hard_limit = 9223372036854775807; gcs.recv_q_soft_limit = 0.25; gcs.sync_donor = no; gmcast.segment = 1; 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.wait_restored_prim_timeout = PT0S; 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; socket.ssl_compression = no; 
2024-06-20T12:06:47.731307Z 0 [Note] [MY-000000] [WSREP] Starting replication
2024-06-20T12:06:47.731368Z 0 [Note] [MY-000000] [Galera] Connecting with bootstrap option: 1
2024-06-20T12:06:47.731380Z 0 [Note] [MY-000000] [Galera] Setting GCS initial position to 00000000-0000-0000-0000-000000000000:-1
2024-06-20T12:06:47.731460Z 0 [Note] [MY-000000] [Galera] protonet asio version 0
2024-06-20T12:06:47.731514Z 0 [Note] [MY-000000] [Galera] Using CRC-32C for message checksums.
2024-06-20T12:06:47.731527Z 0 [Note] [MY-000000] [Galera] backend: asio
2024-06-20T12:06:47.731610Z 0 [Note] [MY-000000] [Galera] gcomm thread scheduling priority set to other:0 
2024-06-20T12:06:47.731693Z 0 [Note] [MY-000000] [Galera] Fail to access the file (/var/lib/mysql//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
2024-06-20T12:06:47.731704Z 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
2024-06-20T12:06:47.731853Z 0 [Note] [MY-000000] [Galera] GMCast version 0
2024-06-20T12:06:47.731961Z 0 [Note] [MY-000000] [Galera] (91ab8c5f-b1f1, 'tcp://0.0.0.0:4567') listening at tcp://0.0.0.0:4567
2024-06-20T12:06:47.731971Z 0 [Note] [MY-000000] [Galera] (91ab8c5f-b1f1, 'tcp://0.0.0.0:4567') multicast: , ttl: 1
2024-06-20T12:06:47.732203Z 0 [Note] [MY-000000] [Galera] EVS version 1
2024-06-20T12:06:47.732256Z 0 [Note] [MY-000000] [Galera] gcomm: bootstrapping new group 'pxc-cluster-test'
2024-06-20T12:06:47.732287Z 0 [Note] [MY-000000] [Galera] start_prim is enabled, turn off pc_recovery
2024-06-20T12:06:47.732725Z 0 [Note] [MY-000000] [Galera] EVS version upgrade 0 -> 1
2024-06-20T12:06:47.732758Z 0 [Note] [MY-000000] [Galera] PC protocol upgrade 0 -> 1
2024-06-20T12:06:47.732780Z 0 [Note] [MY-000000] [Galera] Node 91ab8c5f-b1f1 state primary
2024-06-20T12:06:47.732830Z 0 [Note] [MY-000000] [Galera] Current view of cluster as seen by this node
view (view_id(PRIM,91ab8c5f-b1f1,1)
memb {
        91ab8c5f-b1f1,1
        }
joined {
        }
left {
        }
partitioned {
        }
)
2024-06-20T12:06:47.732844Z 0 [Note] [MY-000000] [Galera] Save the discovered primary-component to disk
2024-06-20T12:06:47.736575Z 0 [Note] [MY-000000] [Galera] discarding pending addr without UUID: tcp://10.9.2.103:4567
2024-06-20T12:06:47.736618Z 0 [Note] [MY-000000] [Galera] discarding pending addr proto entry 0x55e8b16118c0
2024-06-20T12:06:47.736680Z 0 [Note] [MY-000000] [Galera] discarding pending addr without UUID: tcp://10.9.2.104:4567
2024-06-20T12:06:47.736687Z 0 [Note] [MY-000000] [Galera] discarding pending addr proto entry 0x55e8b160bbd0
2024-06-20T12:06:47.736703Z 0 [Note] [MY-000000] [Galera] discarding pending addr without UUID: tcp://10.9.2.105:4567
2024-06-20T12:06:47.736713Z 0 [Note] [MY-000000] [Galera] discarding pending addr proto entry 0x55e8b15cd750
2024-06-20T12:06:47.736751Z 0 [Note] [MY-000000] [Galera] gcomm: connected
2024-06-20T12:06:47.736775Z 0 [Note] [MY-000000] [Galera] Changing maximum packet size to 131072, resulting msg size: 32636
2024-06-20T12:06:47.736872Z 0 [Note] [MY-000000] [Galera] Shifting CLOSED -> OPEN (TO: 0)
2024-06-20T12:06:47.736894Z 0 [Note] [MY-000000] [Galera] Opened channel 'pxc-cluster-test'
2024-06-20T12:06:47.737003Z 0 [Note] [MY-000000] [Galera] New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 1
2024-06-20T12:06:47.737180Z 0 [Note] [MY-000000] [Galera] Starting new group from scratch: 91ac607b-2efd-11ef-b296-ff8c1cc49d20
2024-06-20T12:06:47.737235Z 0 [Note] [MY-000000] [Galera] STATE_EXCHANGE: sent state UUID: 91ac621e-2efd-11ef-825d-eeb0d2855b5c
2024-06-20T12:06:47.737256Z 0 [Note] [MY-000000] [Galera] STATE EXCHANGE: sent state msg: 91ac621e-2efd-11ef-825d-eeb0d2855b5c
2024-06-20T12:06:47.737272Z 0 [Note] [MY-000000] [Galera] STATE EXCHANGE: got state msg: 91ac621e-2efd-11ef-825d-eeb0d2855b5c from 0 (test-vm-1)
2024-06-20T12:06:47.737302Z 0 [Note] [MY-000000] [Galera] Quorum results:
        version    = 6,
        component  = PRIMARY,
        conf_id    = 0,
        members    = 1/1 (primary/total),
        act_id     = 0,
        last_appl. = 0,
        protocols  = 2/10/4 (gcs/repl/appl),
        vote policy= 0,
        group UUID = 91ac607b-2efd-11ef-b296-ff8c1cc49d20
2024-06-20T12:06:47.737369Z 0 [Note] [MY-000000] [Galera] Flow-control interval: [4500, 5000]
2024-06-20T12:06:47.737377Z 0 [Note] [MY-000000] [Galera] Restored state OPEN -> JOINED (1)
2024-06-20T12:06:47.737378Z 2 [Note] [MY-000000] [WSREP] Starting rollbacker thread 2
2024-06-20T12:06:47.737414Z 0 [Note] [MY-000000] [Galera] Member 0.1 (test-vm-1) synced with group.
2024-06-20T12:06:47.737450Z 0 [Note] [MY-000000] [Galera] Shifting JOINED -> SYNCED (TO: 1)
2024-06-20T12:06:47.737444Z 1 [Note] [MY-000000] [WSREP] Starting applier thread 1
2024-06-20T12:06:47.737517Z 1 [Note] [MY-000000] [Galera] ####### processing CC 1, local, ordered
2024-06-20T12:06:47.737531Z 1 [Note] [MY-000000] [Galera] Maybe drain monitors from -1 upto current CC event 1 upto:-1
2024-06-20T12:06:47.737537Z 1 [Note] [MY-000000] [Galera] Drain monitors from -1 up to -1
2024-06-20T12:06:47.737545Z 1 [Note] [MY-000000] [Galera] Process first view: 91ac607b-2efd-11ef-b296-ff8c1cc49d20 my uuid: 91ab8c5f-2efd-11ef-b1f1-5787127e86e8
2024-06-20T12:06:47.737562Z 1 [Note] [MY-000000] [Galera] Server test-vm-1 connected to cluster at position 91ac607b-2efd-11ef-b296-ff8c1cc49d20:1 with ID 91ab8c5f-2efd-11ef-b1f1-5787127e86e8
2024-06-20T12:06:47.737572Z 1 [Note] [MY-000000] [WSREP] Server status change disconnected -> connected
2024-06-20T12:06:47.737603Z 1 [Note] [MY-000000] [WSREP] wsrep_notify_cmd is not defined, skipping notification.
2024-06-20T12:06:47.737630Z 1 [Note] [MY-000000] [Galera] ####### My UUID: 91ab8c5f-2efd-11ef-b1f1-5787127e86e8
2024-06-20T12:06:47.737645Z 1 [Note] [MY-000000] [Galera] Cert index reset to 00000000-0000-0000-0000-000000000000:-1 (proto: 10), state transfer needed: no
2024-06-20T12:06:47.737692Z 0 [Note] [MY-000000] [Galera] Service thread queue flushed.
2024-06-20T12:06:47.737762Z 1 [Note] [MY-000000] [Galera] ####### Assign initial position for certification: 00000000-0000-0000-0000-000000000000:-1, protocol version: -1
2024-06-20T12:06:47.737772Z 1 [Note] [MY-000000] [Galera] REPL Protocols: 10 (5)
2024-06-20T12:06:47.737782Z 1 [Note] [MY-000000] [Galera] ####### Adjusting cert position: -1 -> 1
2024-06-20T12:06:47.737805Z 0 [Note] [MY-000000] [Galera] Service thread queue flushed.
2024-06-20T12:06:47.754222Z 1 [Note] [MY-000000] [Galera] GCache history reset: 00000000-0000-0000-0000-000000000000:0 -> 91ac607b-2efd-11ef-b296-ff8c1cc49d20:0
2024-06-20T12:06:47.805848Z 1 [Note] [MY-000000] [Galera] ================================================
View:
  id: 91ac607b-2efd-11ef-b296-ff8c1cc49d20:1
  status: primary
  protocol_version: 4
  capabilities: MULTI-MASTER, CERTIFICATION, PARALLEL_APPLYING, REPLAY, ISOLATION, PAUSE, CAUSAL_READ, INCREMENTAL_WS, UNORDERED, PREORDERED, STREAMING, NBO
  final: no
  own_index: 0
  members(1):
        0: 91ab8c5f-2efd-11ef-b1f1-5787127e86e8, test-vm-1
=================================================
2024-06-20T12:06:47.805923Z 1 [Note] [MY-000000] [WSREP] Server status change connected -> joiner
2024-06-20T12:06:47.805945Z 1 [Note] [MY-000000] [WSREP] wsrep_notify_cmd is not defined, skipping notification.
2024-06-20T12:06:47.805970Z 1 [Note] [MY-000000] [WSREP] Server status change joiner -> initializing
2024-06-20T12:06:47.805982Z 1 [Note] [MY-000000] [WSREP] wsrep_notify_cmd is not defined, skipping notification.
2024-06-20T12:06:47.808624Z 0 [Note] [MY-010747] [Server] Plugin 'FEDERATED' is disabled.
2024-06-20T12:06:47.808723Z 0 [Note] [MY-010747] [Server] Plugin 'ndbcluster' is disabled.
2024-06-20T12:06:47.808738Z 0 [Note] [MY-010747] [Server] Plugin 'ndbinfo' is disabled.
2024-06-20T12:06:47.808749Z 0 [Note] [MY-010747] [Server] Plugin 'ndb_transid_mysql_connection_map' is disabled.
2024-06-20T12:06:47.809222Z 0 [Note] [MY-000000] [WSREP] Initiating SST cancellation
2024-06-20T12:06:47.809256Z 0 [Note] [MY-000000] [Server] Giving 2 client threads a chance to die gracefully
2024-06-20T12:06:49.809460Z 0 [Note] [MY-000000] [WSREP] Server status change initializing -> disconnecting
2024-06-20T12:06:49.809511Z 2 [Note] [MY-000000] [WSREP] rollbacker thread exiting 2
2024-06-20T12:06:49.809575Z 0 [Note] [MY-000000] [WSREP] wsrep_notify_cmd is not defined, skipping notification.
2024-06-20T12:06:49.809651Z 0 [Note] [MY-000000] [Galera] Closing send monitor...
2024-06-20T12:06:49.809668Z 0 [Note] [MY-000000] [Galera] Closed send monitor.
2024-06-20T12:06:49.809683Z 0 [Note] [MY-000000] [Galera] gcomm: terminating thread
2024-06-20T12:06:49.809706Z 0 [Note] [MY-000000] [Galera] gcomm: joining thread
2024-06-20T12:06:49.809842Z 0 [Note] [MY-000000] [Galera] gcomm: closing backend
2024-06-20T12:06:49.809903Z 0 [Note] [MY-000000] [Galera] PC protocol downgrade 1 -> 0
2024-06-20T12:06:49.809927Z 0 [Note] [MY-000000] [Galera] Current view of cluster as seen by this node
view ((empty))
2024-06-20T12:06:49.809960Z 1 [ERROR] [MY-000000] [Galera] Exception: State wait was interrupted
2024-06-20T12:06:49.810030Z 1 [ERROR] [MY-000000] [Galera] View callback failed. This is unrecoverable, restart required. (FATAL)
         at /mnt/jenkins/workspace/pxc80-autobuild-RELEASE/test/percona-xtradb-cluster-8.0.33-25/percona-xtradb-cluster-galera/galera/src/replicator_smm.cpp:submit_view_info():2628
2024-06-20T12:06:49.810044Z 1 [Note] [MY-000000] [Galera] ReplicatorSMM::abort()
2024-06-20T12:06:49.810083Z 1 [Note] [MY-000000] [Galera] mysqld: Terminated.
2024-06-20T12:06:49.810106Z 0 [Note] [MY-000000] [Galera] gcomm: closed
Aborted (core dumped)

What’s wrong here?

024-06-20T12:06:49.809960Z 1 [ERROR] [MY-000000] [Galera] Exception: State wait was interrupted
2024-06-20T12:06:49.810030Z 1 [ERROR] [MY-000000] [Galera] View callback failed. This is unrecoverable, restart required. (FATAL)
         at /mnt/jenkins/workspace/pxc80-autobuild-RELEASE/test/percona-xtradb-cluster-8.0.33-25/percona-xtradb-cluster-galera/galera/src/replicator_smm.cpp:submit_view_info():2628
2024-06-20T12:06:49.810044Z 1 [Note] [MY-000000] [Galera] ReplicatorSMM::abort()
2024-06-20T12:06:49.810083Z 1 [Note] [MY-000000] [Galera] mysqld: Terminated.
2024-06-20T12:06:49.810106Z 0 [Note] [MY-000000] [Galera] gcomm: closed
Aborted (core dumped)

So, I figured out what the problem was.
There were incorrect permissions 640 for the directory: /var/log/mysql/
and with the log-error parameter specified in the configuration:

[mysqld]
user=mysql
datadir = /var/lib/mysql
log-error = /var/log/mysql/error.log
pid-file = /var/run/mysqld/mysqld.pid
server-id = 103
socket = /var/run/mysqld/mysqld.sock
...

the server could not be started by bootstrap.
But if you remove the parameter, the server can be started.

I set the correct permissions to 750 and the server was launched without any problems.

Problem solved.

1 Like