Percona XtraDB Cluster 8.0.28(MySQL)三主安装报错处理

概述

    本文记录在PXC（MySQL）三主安装时遇到两个报错及解决方法。

1.PXC新增节点使用systemctl start mysql启动时报错

    mysql-systemd[5845]: WARNING: mysql pid file /var/run/mysqld/mysqld.pid empty or not readable

    具体日志

[root@node7 mysql]# journalctl -xe
-- The start-up result is done.
Sep 08 12:01:01 node7 CROND[5657]: (root) CMD (run-parts /etc/cron.hourly)
Sep 08 12:01:01 node7 run-parts(/etc/cron.hourly)[5660]: starting 0anacron
Sep 08 12:01:01 node7 run-parts(/etc/cron.hourly)[5666]: finished 0anacron
Sep 08 12:10:47 node7 polkitd[4547]: Registered Authentication Agent for unix-process:5676:420571 (system bus name :1.24 [/usr/bin/pkttyagent --notify-fd 5 --fallback], object path /org/freedesktop/Pol
Sep 08 12:10:47 node7 systemd[1]: Stopping Percona XtraDB Cluster...
-- Subject: Unit mysql.service has begun shutting down
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit mysql.service has begun shutting down.
Sep 08 12:10:47 node7 mysql-systemd[5682]: SUCCESS! Stopping Percona XtraDB Cluster......
Sep 08 12:11:01 node7 mysql-systemd[5711]: WARNING: mysql pid file /var/run/mysqld/mysqld.pid empty or not readable
Sep 08 12:11:01 node7 mysql-systemd[5711]: WARNING: mysql may be already dead
Sep 08 12:11:01 node7 systemd[1]: Stopped Percona XtraDB Cluster.
-- Subject: Unit mysql.service has finished shutting down
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit mysql.service has finished shutting down.
Sep 08 12:11:01 node7 polkitd[4547]: Unregistered Authentication Agent for unix-process:5676:420571 (system bus name :1.24, object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale en_US.UTF
Sep 08 12:11:27 node7 polkitd[4547]: Registered Authentication Agent for unix-process:5740:424584 (system bus name :1.25 [/usr/bin/pkttyagent --notify-fd 5 --fallback], object path /org/freedesktop/Pol
Sep 08 12:11:27 node7 systemd[1]: Starting Percona XtraDB Cluster...
-- Subject: Unit mysql.service has begun start-up
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit mysql.service has begun starting up.
Sep 08 12:12:02 node7 systemd[1]: mysql.service: main process exited, code=exited, status=1/FAILURE
Sep 08 12:12:02 node7 mysql-systemd[5845]: WARNING: mysql pid file /var/run/mysqld/mysqld.pid empty or not readable
Sep 08 12:12:02 node7 mysql-systemd[5845]: ERROR! mysql already dead
Sep 08 12:12:02 node7 systemd[1]: mysql.service: control process exited, code=exited status=2
Sep 08 12:12:02 node7 mysql-systemd[5874]: WARNING: mysql pid file /var/run/mysqld/mysqld.pid empty or not readable
Sep 08 12:12:02 node7 mysql-systemd[5874]: WARNING: mysql may be already dead
Sep 08 12:12:02 node7 systemd[1]: Failed to start Percona XtraDB Cluster.
-- Subject: Unit mysql.service has failed
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit mysql.service has failed.
-- 
-- The result is failed.
Sep 08 12:12:02 node7 systemd[1]: Unit mysql.service entered failed state.
Sep 08 12:12:02 node7 systemd[1]: mysql.service failed.
Sep 08 12:12:02 node7 polkitd[4547]: Unregistered Authentication Agent for unix-process:5740:424584 (system bus name :1.25, object path /org/freedesktop/PolicyKit1/AuthenticationAgent, locale en_US.UTF

    mysql.log日志内容

2022-09-08T04:14:19.508209Z 0 [Warning] [MY-011068] [Server] The syntax 'wsrep_slave_threads' is deprecated and will be removed in a future release. Please use wsrep_applier_threads instead.
2022-09-08T04:14:19.510841Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 8.0.28-19.1) starting as process 6007
2022-09-08T04:14:19.514688Z 0 [Warning] [MY-013595] [Server] Failed to initialize TLS for channel: mysql_main. See below for the description of exact issue.
2022-09-08T04:14:19.514713Z 0 [Warning] [MY-010069] [Server] Failed to set up SSL because of the following SSL library error: SSL_CTX_new failed
2022-09-08T04:14:19.514740Z 0 [Note] [MY-000000] [WSREP] New joining cluster node configured to use specified SSL artifacts
2022-09-08T04:14:19.514827Z 0 [Note] [MY-000000] [Galera] Loading provider /usr/lib64/galera4/libgalera_smm.so initial position: 95e49e92-2f22-11ed-8d7c-2a5b5705df90:1
2022-09-08T04:14:19.514878Z 0 [Note] [MY-000000] [Galera] wsrep_load(): loading provider library '/usr/lib64/galera4/libgalera_smm.so'
2022-09-08T04:14:19.517278Z 0 [Note] [MY-000000] [Galera] wsrep_load(): Galera 4.11(a9008fc) by Codership Oy <info@codership.com> (modified by Percona <https://percona.com/>) loaded successfully.
2022-09-08T04:14:19.517365Z 0 [Note] [MY-000000] [Galera] CRC-32C: using 64-bit x86 acceleration.
2022-09-08T04:14:19.517837Z 0 [ERROR] [MY-000000] [Galera] Unrecognized parameter '”socket.ssl_key'
2022-09-08T04:14:19.518625Z 0 [Note] [MY-000000] [Galera] Found saved state: 95e49e92-2f22-11ed-8d7c-2a5b5705df90:1, safe_to_bootstrap: 1
2022-09-08T04:14:19.518785Z 0 [Note] [MY-000000] [Galera] GCache DEBUG: opened preamble:
Version: 2
UUID: 95e49e92-2f22-11ed-8d7c-2a5b5705df90
Seqno: 1 - 1
Offset: 1280
Synced: 1
2022-09-08T04:14:19.518817Z 0 [Note] [MY-000000] [Galera] Recovering GCache ring buffer: version: 2, UUID: 95e49e92-2f22-11ed-8d7c-2a5b5705df90, offset: 1280
2022-09-08T04:14:19.518939Z 0 [Note] [MY-000000] [Galera] GCache::RingBuffer initial scan...  0.0% (        0/134217752 bytes) complete.
2022-09-08T04:14:19.519027Z 0 [Note] [MY-000000] [Galera] GCache::RingBuffer initial scan...100.0% (134217752/134217752 bytes) complete.
2022-09-08T04:14:19.519052Z 0 [Note] [MY-000000] [Galera] Recovering GCache ring buffer: found gapless sequence 1-1
2022-09-08T04:14:19.519109Z 0 [Note] [MY-000000] [Galera] GCache::RingBuffer unused buffers scan...  0.0% (  0/176 bytes) complete.
2022-09-08T04:14:19.519149Z 0 [Note] [MY-000000] [Galera] GCache::RingBuffer unused buffers scan...100.0% (176/176 bytes) complete.
2022-09-08T04:14:19.519172Z 0 [Note] [MY-000000] [Galera] Recovering GCache ring buffer: found 0/1 locked buffers
2022-09-08T04:14:19.519194Z 0 [Note] [MY-000000] [Galera] Recovering GCache ring buffer: free space: 134217552/134217728
2022-09-08T04:14:19.519810Z 0 [Warning] [MY-000000] [Galera] Option 'gcs.fc_master_slave' is deprecated and will be removed in the future versions, please use 'gcs.fc_single_primary' instead. 
2022-09-08T04:14:19.520645Z 0 [Note] [MY-000000] [Galera] Passing config to GCS: base_dir = /var/lib/mysql/; base_host = 192.168.59.33; 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/; 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; socket.ssl = YES; socket.ssl_ca = /var/lib/mysql/ca.pem; socket.ssl_cert = /var/lib/mysql/server-cert.pem; socket.ssl_cipher = ; socket.ssl_compression = YES; socket.ssl_key = /var/lib/mysql/server-key.pem; socket.ssl_reload = 1; 
2022-09-08T04:14:19.531061Z 0 [Note] [MY-000000] [Galera] Service thread queue flushed.
2022-09-08T04:14:19.531158Z 0 [Note] [MY-000000] [Galera] ####### Assign initial position for certification: 95e49e92-2f22-11ed-8d7c-2a5b5705df90:1, protocol version: -1
2022-09-08T04:14:19.531287Z 0 [Note] [MY-000000] [WSREP] Starting replication
2022-09-08T04:14:19.531315Z 0 [Note] [MY-000000] [Galera] Connecting with bootstrap option: 0
2022-09-08T04:14:19.531348Z 0 [Note] [MY-000000] [Galera] Setting GCS initial position to 95e49e92-2f22-11ed-8d7c-2a5b5705df90:1
2022-09-08T04:14:19.531442Z 0 [Note] [MY-000000] [Galera] protonet asio version 0
2022-09-08T04:14:19.531827Z 0 [Note] [MY-000000] [Galera] Using CRC-32C for message checksums.
2022-09-08T04:14:19.531868Z 0 [Note] [MY-000000] [Galera] backend: asio
2022-09-08T04:14:19.531945Z 0 [Note] [MY-000000] [Galera] gcomm thread scheduling priority set to other:0 
2022-09-08T04:14:19.532087Z 0 [Warning] [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
2022-09-08T04:14:19.532117Z 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
2022-09-08T04:14:19.532329Z 0 [Note] [MY-000000] [Galera] GMCast version 0
2022-09-08T04:14:19.532558Z 0 [Note] [MY-000000] [Galera] (b5e85338-91ee, 'ssl://0.0.0.0:4567') listening at ssl://0.0.0.0:4567
2022-09-08T04:14:19.532585Z 0 [Note] [MY-000000] [Galera] (b5e85338-91ee, 'ssl://0.0.0.0:4567') multicast: , ttl: 1
2022-09-08T04:14:19.532983Z 0 [Note] [MY-000000] [Galera] EVS version 1
2022-09-08T04:14:19.533152Z 0 [Note] [MY-000000] [Galera] gcomm: connecting to group 'pxc-vzoom', peer '192.168.59.31:,192.168.59.32:,192.168.59.33:'
2022-09-08T04:14:19.540386Z 0 [Note] [MY-000000] [Galera] (b5e85338-91ee, 'ssl://0.0.0.0:4567') Found matching local endpoint for a connection, blacklisting address ssl://192.168.59.33:4567
2022-09-08T04:14:22.535052Z 0 [Note] [MY-000000] [Galera] announce period timed out (pc.announce_timeout)
2022-09-08T04:14:22.535223Z 0 [Note] [MY-000000] [Galera] EVS version upgrade 0 -> 1
2022-09-08T04:14:22.535265Z 0 [Note] [MY-000000] [Galera] PC protocol upgrade 0 -> 1
2022-09-08T04:14:22.535333Z 0 [Warning] [MY-000000] [Galera] no nodes coming from prim view, prim not possible
2022-09-08T04:14:22.535374Z 0 [Note] [MY-000000] [Galera] Current view of cluster as seen by this node
view (view_id(NON_PRIM,b5e85338-91ee,1)
memb {
  b5e85338-91ee,0
  }
joined {
  }
left {
  }
partitioned {
  }
)
2022-09-08T04:14:23.035821Z 0 [Warning] [MY-000000] [Galera] last inactive check more than PT1.5S (3*evs.inactive_check_period) ago (PT3.50282S), skipping check
2022-09-08T04:14:52.547163Z 0 [Note] [MY-000000] [Galera] PC protocol downgrade 1 -> 0
2022-09-08T04:14:52.547263Z 0 [Note] [MY-000000] [Galera] Current view of cluster as seen by this node
view ((empty))
2022-09-08T04:14:52.547456Z 0 [ERROR] [MY-000000] [Galera] failed to open gcomm backend connection: 110: failed to reach primary view (pc.wait_prim_timeout): 110 (Connection timed out)
   at gcomm/src/pc.cpp:connect():161
2022-09-08T04:14:52.547509Z 0 [ERROR] [MY-000000] [Galera] gcs/src/gcs_core.cpp:gcs_core_open():219: Failed to open backend connection: -110 (Connection timed out)
2022-09-08T04:14:53.547822Z 0 [Note] [MY-000000] [Galera] gcomm: terminating thread
2022-09-08T04:14:53.547874Z 0 [Note] [MY-000000] [Galera] gcomm: joining thread
2022-09-08T04:14:53.548005Z 0 [ERROR] [MY-000000] [Galera] gcs/src/gcs.cpp:gcs_open():1811: Failed to open channel 'pxc-vzoom' at 'gcomm://192.168.59.31,192.168.59.32,192.168.59.33': -110 (Connection timed out)
2022-09-08T04:14:53.548032Z 0 [ERROR] [MY-000000] [Galera] gcs connect failed: Connection timed out
2022-09-08T04:14:53.548054Z 0 [ERROR] [MY-000000] [WSREP] Provider/Node (gcomm://192.168.59.31,192.168.59.32,192.168.59.33) failed to establish connection with cluster (reason: 7)
2022-09-08T04:14:53.548085Z 0 [ERROR] [MY-010119] [Server] Aborting
2022-09-08T04:14:53.548493Z 0 [System] [MY-010910] [Server] /usr/sbin/mysqld: Shutdown complete (mysqld 8.0.28-19.1)  Percona XtraDB Cluster (GPL), Release rel19, Revision f544540, WSREP version 26.4.3.
2022-09-08T04:14:53.550304Z 0 [Note] [MY-000000] [Galera] dtor state: CLOSED
2022-09-08T04:14:53.550413Z 0 [Note] [MY-000000] [Galera] MemPool(TrxHandleSlave): hit ratio: 0, misses: 0, in use: 0, in pool: 0
2022-09-08T04:14:53.554142Z 0 [Note] [MY-000000] [Galera] apply mon: entered 0
2022-09-08T04:14:53.557926Z 0 [Note] [MY-000000] [Galera] apply mon: entered 0
2022-09-08T04:14:53.561180Z 0 [Note] [MY-000000] [Galera] apply mon: entered 0
2022-09-08T04:14:53.561239Z 0 [Note] [MY-000000] [Galera] cert index usage at exit 0
2022-09-08T04:14:53.561252Z 0 [Note] [MY-000000] [Galera] cert trx map usage at exit 0
2022-09-08T04:14:53.561263Z 0 [Note] [MY-000000] [Galera] deps set usage at exit 0
2022-09-08T04:14:53.561285Z 0 [Note] [MY-000000] [Galera] avg deps dist 0
2022-09-08T04:14:53.561299Z 0 [Note] [MY-000000] [Galera] avg cert interval 0
2022-09-08T04:14:53.561310Z 0 [Note] [MY-000000] [Galera] cert index size 0
2022-09-08T04:14:53.561365Z 0 [Note] [MY-000000] [Galera] Service thread queue flushed.
2022-09-08T04:14:53.561402Z 0 [Note] [MY-000000] [Galera] wsdb trx map usage 0 conn query map usage 0
2022-09-08T04:14:53.561418Z 0 [Note] [MY-000000] [Galera] MemPool(LocalTrxHandle): hit ratio: 0, misses: 0, in use: 0, in pool: 0
2022-09-08T04:14:53.561537Z 0 [Note] [MY-000000] [Galera] Shifting CLOSED -> DESTROYED (TO: 0)
2022-09-08T04:14:53.562352Z 0 [Note] [MY-000000] [Galera] Flushing memory map to disk...

    解决方案

    官方文档中说明认证密钥文件必须每个节点一样

    所以，需要把第一个使用mysql@bootstrap.service启动节点下的*.pem文件复制给其余节点，第一次启动时mysql服务会生成密钥文件在对应的data目录下，如果/etc/my.cnf为默认参数，文件在/var/lib/mysql下。

2.添加节点时mysql.log报错

[ERROR] [MY-000000] [Galera] gcs/src/gcs_group.cpp:gcs_group_handle_join_msg():1214: Will never receive state. Need to abort.

    解决方法：

    最终发现是/etc/my.cnf下参数wsrep_node_address的IP地址配置手误写错。

    此问题可以从下面几个方面排查：

• 检查SST用户的用户名和密码是否正确，并且有权限(wsrep_sst_auth)
• 检查防火墙（selinux，firewalld）
• 参数文件中wsrep_node_address是否配置的是本机IP地址