Not able to add the node 2 to the cluster - PXC 8.0.27

Cluster version : PXC 8.0.27
OS : Centos 7
No . Of nodes : 3

Hi there ,
When i am trying to add the nod2e to the cluster ,below is the error reported …

Note : Already bootstrapped the node 1, trying to add the node 2(this is the first time iam trying to add ) .

[testuser@test3 etc]$ sudo systemctl status mysql.service
● mysql.service - Percona XtraDB Cluster
   Loaded: loaded (/usr/lib/systemd/system/mysql.service; enabled; vendor preset: disabled)
   Active: failed (Result: exit-code) since Fri 2022-06-24 18:14:14 IST; 58s ago
  Process: 19152 ExecStopPost=/usr/bin/mysql-systemd stop-post (code=exited, status=0/SUCCESS)
  Process: 16244 ExecStop=/usr/bin/mysql-systemd stop (code=exited, status=0/SUCCESS)
  Process: 16166 ExecStartPost=/usr/bin/mysql-systemd start-post $MAINPID (code=exited, status=0/SUCCESS)
  Process: 16164 ExecStartPost=/bin/sh -c systemctl unset-environment _WSREP_START_POSITION (code=exited, status=0/SUCCESS)
  Process: 19148 ExecStart=/usr/sbin/mysqld $_WSREP_START_POSITION (code=exited, status=1/FAILURE)
  Process: 19097 ExecStartPre=/bin/sh -c VAR=`bash /usr/bin/mysql-systemd galera-recovery`; [ $? -eq 0 ] && systemctl set-environment _WSREP_START_POSITION=$VAR || exit 1 (code=exited, status=0/SUCCESS)
  Process: 19094 ExecStartPre=/bin/sh -c systemctl unset-environment _WSREP_START_POSITION (code=exited, status=0/SUCCESS)
  Process: 19053 ExecStartPre=/usr/bin/mysql-systemd start-pre (code=exited, status=0/SUCCESS)
 Main PID: 19148 (code=exited, status=1/FAILURE)
   Status: "Server startup in progress"
    Error: 2 (No such file or directory)

Jun 24 18:14:13 test3 systemd[1]: Starting Percona XtraDB Cluster...
Jun 24 18:14:14 test3 systemd[1]: mysql.service: main process exited, code=exited, status=1/FAILURE
Jun 24 18:14:14 test3 mysql-systemd[19152]: WARNING: mysql pid file /var/run/mysqld/mysqld.pid empty or not readable
Jun 24 18:14:14 test3 mysql-systemd[19152]: WARNING: mysql may be already dead
Jun 24 18:14:14 test3 systemd[1]: Failed to start Percona XtraDB Cluster.
Jun 24 18:14:14 test3 systemd[1]: Unit mysql.service entered failed state.
Jun 24 18:14:14 test3 systemd[1]: mysql.service failed.

Logfile

2022-06-24T17:40:59.856198+05:30 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 8.0.27-18.1) starting as process 18565
2022-06-24T17:40:59.858771+05:30 0 [Warning] [MY-013746] [Server] A deprecated TLS version TLSv1 is enabled for channel mysql_main
2022-06-24T17:40:59.858784+05:30 0 [Warning] [MY-013746] [Server] A deprecated TLS version TLSv1.1 is enabled for channel mysql_main
2022-06-24T17:40:59.858910+05:30 0 [Warning] [MY-013595] [Server] Failed to initialize TLS for channel: mysql_main. See below for the description of exact issue.
2022-06-24T17:40:59.858935+05:30 0 [Warning] [MY-010069] [Server] Failed to set up SSL because of the following SSL library error: SSL_CTX_new failed
2022-06-24T17:40:59.858957+05:30 0 [Note] [MY-000000] [WSREP] New joining cluster node configured to use specified SSL artifacts
2022-06-24T17:40:59.859009+05:30 0 [Note] [MY-000000] [Galera] Loading provider /usr/lib64/galera4/libgalera_smm.so initial position: 0b30b9d6-f3a7-11ec-a44d-67d27c33010c:1
2022-06-24T17:40:59.859052+05:30 0 [Note] [MY-000000] [Galera] wsrep_load(): loading provider library '/usr/lib64/galera4/libgalera_smm.so'
2022-06-24T17:40:59.860430+05:30 0 [Note] [MY-000000] [Galera] wsrep_load(): Galera 4.10(9728532) by Codership Oy <info@codership.com> (modified by Percona <https://percona.com/>) loaded successfully.
2022-06-24T17:40:59.860487+05:30 0 [Note] [MY-000000] [Galera] CRC-32C: using 64-bit x86 acceleration.
2022-06-24T17:40:59.861267+05:30 0 [Note] [MY-000000] [Galera] Found saved state: 0b30b9d6-f3a7-11ec-a44d-67d27c33010c:1, safe_to_bootstrap: 0
2022-06-24T17:40:59.861362+05:30 0 [Note] [MY-000000] [Galera] GCache DEBUG: opened preamble:
Version: 2
UUID: 0b30b9d6-f3a7-11ec-a44d-67d27c33010c
Seqno: 1 - 1
Offset: 1280
Synced: 1
2022-06-24T17:40:59.861394+05:30 0 [Note] [MY-000000] [Galera] Recovering GCache ring buffer: version: 2, UUID: 0b30b9d6-f3a7-11ec-a44d-67d27c33010c, offset: 1280
2022-06-24T17:40:59.861466+05:30 0 [Note] [MY-000000] [Galera] GCache::RingBuffer initial scan...  0.0% (        0/134217752 bytes) complete.
2022-06-24T17:40:59.861504+05:30 0 [Note] [MY-000000] [Galera] GCache::RingBuffer initial scan...100.0% (134217752/134217752 bytes) complete.
2022-06-24T17:40:59.861533+05:30 0 [Note] [MY-000000] [Galera] Recovering GCache ring buffer: found gapless sequence 1-1
2022-06-24T17:40:59.861579+05:30 0 [Note] [MY-000000] [Galera] GCache::RingBuffer unused buffers scan...  0.0% (  0/176 bytes) complete.
2022-06-24T17:40:59.861605+05:30 0 [Note] [MY-000000] [Galera] GCache::RingBuffer unused buffers scan...100.0% (176/176 bytes) complete.
2022-06-24T17:40:59.861630+05:30 0 [Note] [MY-000000] [Galera] GCache DEBUG: RingBuffer::recover(): found 0/1 locked buffers
2022-06-24T17:40:59.861657+05:30 0 [Note] [MY-000000] [Galera] GCache DEBUG: RingBuffer::recover(): free space: 134217552/134217728
2022-06-24T17:40:59.862325+05:30 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-06-24T17:40:59.862731+05:30 0 [Note] [MY-000000] [Galera] Passing config to GCS: base_dir = /var/lib/mysql/; base_host = 192.168.1.3; 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 = ca.pem; socket.ssl_cert = server-cert.pem; socket.ssl_cipher = ; socket.ssl_compression = YES; socket.ssl_key = server-key.pem; socket.ssl_reload = 1;
2022-06-24T17:40:59.866960+05:30 0 [Note] [MY-000000] [Galera] Service thread queue flushed.
2022-06-24T17:40:59.867069+05:30 0 [Note] [MY-000000] [Galera] ####### Assign initial position for certification: 0b30b9d6-f3a7-11ec-a44d-67d27c33010c:1, protocol version: -1
2022-06-24T17:40:59.867162+05:30 0 [Note] [MY-000000] [WSREP] Starting replication
2022-06-24T17:40:59.867187+05:30 0 [Note] [MY-000000] [Galera] Connecting with bootstrap option: 0
2022-06-24T17:40:59.867208+05:30 0 [Note] [MY-000000] [Galera] Setting GCS initial position to 0b30b9d6-f3a7-11ec-a44d-67d27c33010c:1
2022-06-24T17:40:59.867275+05:30 0 [Note] [MY-000000] [Galera] protonet asio version 0
2022-06-24T17:40:59.867522+05:30 0 [Note] [MY-000000] [Galera] Using CRC-32C for message checksums.
2022-06-24T17:40:59.867552+05:30 0 [Note] [MY-000000] [Galera] backend: asio
2022-06-24T17:40:59.867604+05:30 0 [Note] [MY-000000] [Galera] gcomm thread scheduling priority set to other:0



2022-06-24T17:40:59.867686+05:30 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-06-24T17:40:59.867704+05:30 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-06-24T17:40:59.867860+05:30 0 [Note] [MY-000000] [Galera] GMCast version 0
2022-06-24T17:40:59.867982+05:30 0 [Note] [MY-000000] [Galera] (b5a43317-98da, 'ssl://0.0.0.0:4567') listening at ssl://0.0.0.0:4567
2022-06-24T17:40:59.868000+05:30 0 [Note] [MY-000000] [Galera] (b5a43317-98da, 'ssl://0.0.0.0:4567') multicast: , ttl: 1
2022-06-24T17:40:59.868215+05:30 0 [Note] [MY-000000] [Galera] EVS version 1
2022-06-24T17:40:59.868302+05:30 0 [Note] [MY-000000] [Galera] gcomm: connecting to group 'PR-pxc-cluster-u', peer '192.168.1.1:,192.168.1.2:,192.168.1.3:'
2022-06-24T17:40:59.871767+05:30 0 [Note] [MY-000000] [Galera] (b5a43317-98da, 'ssl://0.0.0.0:4567') Found matching local endpoint for a connection, blacklisting address ssl://192.168.1.3:4567
2022-06-24T17:41:02.869772+05:30 0 [Note] [MY-000000] [Galera] announce period timed out (pc.announce_timeout)
2022-06-24T17:41:02.869895+05:30 0 [Note] [MY-000000] [Galera] EVS version upgrade 0 -> 1
2022-06-24T17:41:02.869925+05:30 0 [Note] [MY-000000] [Galera] PC protocol upgrade 0 -> 1
2022-06-24T17:41:02.869966+05:30 0 [Warning] [MY-000000] [Galera] no nodes coming from prim view, prim not possible
2022-06-24T17:41:02.869996+05:30 0 [Note] [MY-000000] [Galera] Current view of cluster as seen by this node
view (view_id(NON_PRIM,b5a43317-98da,1)
memb {
        b5a43317-98da,0
        }
joined {
        }
left {
        }
partitioned {
        }
)
2022-06-24T17:41:03.370116+05:30 0 [Warning] [MY-000000] [Galera] last inactive check more than PT1.5S (3*evs.inactive_check_period) ago (PT3.50188S), skipping check
2022-06-24T17:41:32.876682+05:30 0 [Note] [MY-000000] [Galera] PC protocol downgrade 1 -> 0
2022-06-24T17:41:32.876732+05:30 0 [Note] [MY-000000] [Galera] Current view of cluster as seen by this node
view ((empty))
2022-06-24T17:41:32.877101+05:30 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-06-24T17:41:32.877131+05:30 0 [ERROR] [MY-000000] [Galera] gcs/src/gcs_core.cpp:gcs_core_open():219: Failed to open backend connection: -110 (Connection timed out)
2022-06-24T17:41:33.877370+05:30 0 [Note] [MY-000000] [Galera] gcomm: terminating thread
2022-06-24T17:41:33.877436+05:30 0 [Note] [MY-000000] [Galera] gcomm: joining thread
2022-06-24T17:41:33.877559+05:30 0 [ERROR] [MY-000000] [Galera] gcs/src/gcs.cpp:gcs_open():1758: Failed to open channel 'PR-pxc-cluster-u' at 'gcomm://192.168.1.1,192.168.1.2,192.168.1.3': -110 (Connection timed out)
2022-06-24T17:41:33.877586+05:30 0 [ERROR] [MY-000000] [Galera] gcs connect failed: Connection timed out
2022-06-24T17:41:33.877607+05:30 0 [ERROR] [MY-000000] [WSREP] Provider/Node (gcomm://192.168.1.1,192.168.1.2,192.168.1.3) failed to establish connection with cluster (reason: 7)
2022-06-24T17:41:33.877632+05:30 0 [ERROR] [MY-010119] [Server] Aborting
2022-06-24T17:41:33.877916+05:30 0 [System] [MY-010910] [Server] /usr/sbin/mysqld: Shutdown complete (mysqld 8.0.27-18.1)  Percona XtraDB Cluster (GPL), Release rel18, Revision ac35177, WSREP version 26.4.3.
2022-06-24T17:41:33.878569+05:30 0 [Note] [MY-000000] [Galera] dtor state: CLOSED
2022-06-24T17:41:33.878619+05:30 0 [Note] [MY-000000] [Galera] MemPool(TrxHandleSlave): hit ratio: 0, misses: 0, in use: 0, in pool: 0
2022-06-24T17:41:33.879581+05:30 0 [Note] [MY-000000] [Galera] apply mon: entered 0
2022-06-24T17:41:33.880359+05:30 0 [Note] [MY-000000] [Galera] apply mon: entered 0
2022-06-24T17:41:33.881108+05:30 0 [Note] [MY-000000] [Galera] apply mon: entered 0
2022-06-24T17:41:33.881128+05:30 0 [Note] [MY-000000] [Galera] cert index usage at exit 0
2022-06-24T17:41:33.881134+05:30 0 [Note] [MY-000000] [Galera] cert trx map usage at exit 0
2022-06-24T17:41:33.881139+05:30 0 [Note] [MY-000000] [Galera] deps set usage at exit 0
2022-06-24T17:41:33.881146+05:30 0 [Note] [MY-000000] [Galera] avg deps dist 0
2022-06-24T17:41:33.881152+05:30 0 [Note] [MY-000000] [Galera] avg cert interval 0
2022-06-24T17:41:33.881182+05:30 0 [Note] [MY-000000] [Galera] cert index size 0
2022-06-24T17:41:33.881234+05:30 0 [Note] [MY-000000] [Galera] Service thread queue flushed.
2022-06-24T17:41:33.881275+05:30 0 [Note] [MY-000000] [Galera] wsdb trx map usage 0 conn query map usage 0
2022-06-24T17:41:33.881290+05:30 0 [Note] [MY-000000] [Galera] MemPool(LocalTrxHandle): hit ratio: 0, misses: 0, in use: 0, in pool: 0
2022-06-24T17:41:33.881395+05:30 0 [Note] [MY-000000] [Galera] Shifting CLOSED -> DESTROYED (TO: 0)
2022-06-24T17:41:33.882274+05:30 0 [Note] [MY-000000] [Galera] Flushing memory map to disk...
1 Like

The error
2022-06-24T17:41:33.877559+05:30 0 [ERROR] [MY-000000] [Galera] gcs/src/gcs.cpp:gcs_open():1758: Failed to open channel ‘PR-pxc-cluster-u’ at ‘gcomm://192.168.1.1,192.168.1.2,192.168.1.3’: -110 (Connection timed out)
indicates there is networking problem between nodes.
Do you really have nodes with IP addresses 192.168.1.1,192.168.1.2,192.168.1.3 and there is network connection between them?

If that is correct, the next thing is to make sure that needed ports are not blocked by firewalls.
Needed ports:
https://www.percona.com/doc/percona-xtradb-cluster/LATEST/security/secure-network.html

2 Likes

Hi …
Ports are not blocked ,any other solution…?

2 Likes

Hi @AneeshBabu

From one of the nodes that is attempting to connect to the cluster, can you show us the output of the following:

node3 $ nc -w2 192.168.1.1 4567

This command will test whether the port 4567/tcp is open and if so whether node3 can begin to join the cluster

1 Like

by default we have TCP port for MySQL

1 Like

Hi AneeshBabu,

Assuming you have all ports open (3306, 4444, 4567 and 4568) then I would say you check encryption.

By default pxc 8 has encryption enabled (check this variable pxc_encrypt_cluster_traffic ).
I suggest you disable PXC encryption , bootstrap the 1st node again and then start the 2nd node and check if it can join the existing cluster.

1 Like

Hi there,
bootstrapped the node1 , and node1 is online ,When trying to join the node2 to the cluster below is the error reported .
2022-06-28T23:04:26.342480+05:30 0 [ERROR] [MY-000000] [Galera] gcs/src/gcs_group.cpp:gcs_group_handle_join_msg():1214: Will never receive state. Need to abort.

LogFile of node2



[testuser@testserveruat2 certs]$ sudo service mysql start
Redirecting to /bin/systemctl start mysql.service
Job for mysql.service failed because a fatal signal was delivered to the control process. See "systemctl status mysql.service" and "journalctl -xe" for details.
[testuser@testserveruat certs]$ sudo tail -n 100 /var/log/mysqld.log
2022-06-28T23:04:25.080569+05:30 0 [Note] [MY-000000] [Galera] (8db35066-80d2, 'tcp://0.0.0.0:4567') Found matching local endpoint for a connection, blacklisting address tcp://172.31.2.59:4567
2022-06-28T23:04:25.081941+05:30 0 [Note] [MY-000000] [Galera] (8db35066-80d2, 'tcp://0.0.0.0:4567') connection established to ded2c73f-a972 tcp://172.31.15.228:4567
2022-06-28T23:04:25.082014+05:30 0 [Note] [MY-000000] [Galera] (8db35066-80d2, 'tcp://0.0.0.0:4567') turning message relay requesting on, nonlive peers:
2022-06-28T23:04:25.251880+05:30 0 [Note] [MY-000000] [Galera] EVS version upgrade 0 -> 1
2022-06-28T23:04:25.251924+05:30 0 [Note] [MY-000000] [Galera] declaring ded2c73f-a972 at tcp://172.31.15.228:4567 stable
2022-06-28T23:04:25.251953+05:30 0 [Note] [MY-000000] [Galera] PC protocol upgrade 0 -> 1
2022-06-28T23:04:25.252196+05:30 0 [Note] [MY-000000] [Galera] Node ded2c73f-a972 state primary
2022-06-28T23:04:25.252400+05:30 0 [Note] [MY-000000] [Galera] Current view of cluster as seen by this node
view (view_id(PRIM,8db35066-80d2,4)
memb {
        8db35066-80d2,0
        ded2c73f-a972,0
        }
joined {
        }
left {
        }
partitioned {
        }
)
2022-06-28T23:04:25.252430+05:30 0 [Note] [MY-000000] [Galera] Save the discovered primary-component to disk
2022-06-28T23:04:25.254282+05:30 0 [Note] [MY-000000] [Galera] discarding pending addr without UUID: tcp://172.31.2.202:4567
2022-06-28T23:04:25.580392+05:30 0 [Note] [MY-000000] [Galera] gcomm: connected
2022-06-28T23:04:25.580473+05:30 0 [Note] [MY-000000] [Galera] Changing maximum packet size to 64500, resulting msg size: 32636
2022-06-28T23:04:25.580694+05:30 0 [Note] [MY-000000] [Galera] Shifting CLOSED -> OPEN (TO: 0)
2022-06-28T23:04:25.580717+05:30 0 [Note] [MY-000000] [Galera] Opened channel 'pxcragabh'
2022-06-28T23:04:25.580887+05:30 0 [Note] [MY-000000] [Galera] New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 2
2022-06-28T23:04:25.581374+05:30 0 [Note] [MY-000000] [Galera] STATE_EXCHANGE: sent state UUID: 8e000da4-f708-11ec-8eab-ce2cda688c8a
2022-06-28T23:04:25.581490+05:30 2 [Note] [MY-000000] [WSREP] Starting rollbacker thread 2
2022-06-28T23:04:25.581547+05:30 1 [Note] [MY-000000] [WSREP] Starting applier thread 1
2022-06-28T23:04:25.581747+05:30 0 [Note] [MY-000000] [Galera] STATE EXCHANGE: sent state msg: 8e000da4-f708-11ec-8eab-ce2cda688c8a
2022-06-28T23:04:25.581968+05:30 0 [Note] [MY-000000] [Galera] STATE EXCHANGE: got state msg: 8e000da4-f708-11ec-8eab-ce2cda688c8a from 0 (pxc2)
2022-06-28T23:04:25.582182+05:30 0 [Note] [MY-000000] [Galera] STATE EXCHANGE: got state msg: 8e000da4-f708-11ec-8eab-ce2cda688c8a from 1 (pxc2)
2022-06-28T23:04:25.582201+05:30 0 [Note] [MY-000000] [Galera] Quorum results:
        version    = 6,
        component  = PRIMARY,
        conf_id    = 3,
        members    = 1/2 (primary/total),
        act_id     = 10,
        last_appl. = 7,
        protocols  = 2/10/4 (gcs/repl/appl),
        vote policy= 0,
        group UUID = 680c03b4-f3b4-11ec-ae26-a71ace89b9e1
2022-06-28T23:04:25.582252+05:30 0 [Note] [MY-000000] [Galera] Flow-control interval: [141, 141]
2022-06-28T23:04:25.582268+05:30 0 [Note] [MY-000000] [Galera] Shifting OPEN -> PRIMARY (TO: 11)
2022-06-28T23:04:25.582334+05:30 1 [Note] [MY-000000] [Galera] ####### processing CC 11, local, ordered
2022-06-28T23:04:25.582360+05:30 1 [Note] [MY-000000] [Galera] Maybe drain monitors from 20 upto current CC event 11 upto:20
2022-06-28T23:04:25.582374+05:30 1 [Note] [MY-000000] [Galera] Drain monitors from 20 up to 20
2022-06-28T23:04:25.582401+05:30 1 [Note] [MY-000000] [Galera] Process first view: 680c03b4-f3b4-11ec-ae26-a71ace89b9e1 my uuid: 8db35066-f708-11ec-80d2-7a13554b160b
2022-06-28T23:04:25.582429+05:30 1 [Note] [MY-000000] [Galera] Server pxc2 connected to cluster at position 680c03b4-f3b4-11ec-ae26-a71ace89b9e1:11 with ID 8db35066-f708-11ec-80d2-7a13554b160b
2022-06-28T23:04:25.582449+05:30 1 [Note] [MY-000000] [WSREP] Server status change disconnected -> connected
2022-06-28T23:04:25.582472+05:30 1 [Note] [MY-000000] [WSREP] wsrep_notify_cmd is not defined, skipping notification.
2022-06-28T23:04:25.582506+05:30 1 [Note] [MY-000000] [Galera] ####### My UUID: 8db35066-f708-11ec-80d2-7a13554b160b
2022-06-28T23:04:25.582530+05:30 1 [Note] [MY-000000] [Galera] Cert index reset to 00000000-0000-0000-0000-000000000000:-1 (proto: 10), state transfer needed: yes
2022-06-28T23:04:25.582584+05:30 0 [Note] [MY-000000] [Galera] Service thread queue flushed.
2022-06-28T23:04:25.582626+05:30 1 [Note] [MY-000000] [Galera] ####### Assign initial position for certification: 00000000-0000-0000-0000-000000000000:-1, protocol version: -1
2022-06-28T23:04:25.582648+05:30 1 [Note] [MY-000000] [Galera] State transfer required:
        Group state: 680c03b4-f3b4-11ec-ae26-a71ace89b9e1:11
        Local state: aa86c6b2-f38e-11ec-b0ce-7aaf91441ec9:20
2022-06-28T23:04:25.582663+05:30 1 [Note] [MY-000000] [WSREP] Server status change connected -> joiner
2022-06-28T23:04:25.582676+05:30 1 [Note] [MY-000000] [WSREP] wsrep_notify_cmd is not defined, skipping notification.
2022-06-28T23:04:25.582778+05:30 0 [Note] [MY-000000] [WSREP] Initiating SST/IST transfer on JOINER side (wsrep_sst_xtrabackup-v2 --role 'joiner' --address '172.31.2.59' --datadir '/var/lib/mysql/' --basedir '/usr/' --plugindir '/usr/lib64/mysql/plugin/' --defaults-file '/etc/my.cnf' --defaults-group-suffix '' --parent '7503' --mysqld-version '8.0.27-18.1'   '' )
2022-06-28T23:04:26.124156+05:30 1 [Note] [MY-000000] [WSREP] Prepared SST request: xtrabackup-v2|172.31.2.59:4444/xtrabackup_sst//1
2022-06-28T23:04:26.124228+05:30 1 [Note] [MY-000000] [Galera] Check if state gap can be serviced using IST
2022-06-28T23:04:26.124258+05:30 1 [Note] [MY-000000] [Galera] Local UUID: aa86c6b2-f38e-11ec-b0ce-7aaf91441ec9 != Group UUID: 680c03b4-f3b4-11ec-ae26-a71ace89b9e1
2022-06-28T23:04:26.124278+05:30 1 [Note] [MY-000000] [Galera] ####### IST uuid:aa86c6b2-f38e-11ec-b0ce-7aaf91441ec9 f: 0, l: 11, STRv: 3
2022-06-28T23:04:26.124365+05:30 1 [Note] [MY-000000] [Galera] IST receiver addr using tcp://172.31.2.59:4568
2022-06-28T23:04:26.124603+05:30 1 [Note] [MY-000000] [Galera] Prepared IST receiver for 0-11, listening at: tcp://172.31.2.59:4568
2022-06-28T23:04:26.126475+05:30 0 [Note] [MY-000000] [Galera] Member 0.0 (pxc2) requested state transfer from '*any*'. Selected 1.0 (pxc2)(SYNCED) as donor.
2022-06-28T23:04:26.126503+05:30 0 [Note] [MY-000000] [Galera] Shifting PRIMARY -> JOINER (TO: 11)
2022-06-28T23:04:26.126549+05:30 1 [Note] [MY-000000] [Galera] Requesting state transfer: success, donor: 1
2022-06-28T23:04:26.126576+05:30 1 [Note] [MY-000000] [Galera] Resetting GCache seqno map due to different histories.
2022-06-28T23:04:26.126599+05:30 1 [Note] [MY-000000] [Galera] GCache history reset: aa86c6b2-f38e-11ec-b0ce-7aaf91441ec9:20 -> 680c03b4-f3b4-11ec-ae26-a71ace89b9e1:11
2022-06-28T23:04:26.127396+05:30 1 [Note] [MY-000000] [Galera] GCache DEBUG: RingBuffer::seqno_reset(): discarded 3200 bytes
2022-06-28T23:04:26.127420+05:30 1 [Note] [MY-000000] [Galera] GCache DEBUG: RingBuffer::seqno_reset(): found 1/2 locked buffers
2022-06-28T23:04:26.341769+05:30 0 [Warning] [MY-000000] [Galera] 1.0 (pxc2): State transfer to 0.0 (pxc2) failed: -78 (Remote address changed)
2022-06-28T23:04:26.342480+05:30 0 [ERROR] [MY-000000] [Galera] gcs/src/gcs_group.cpp:gcs_group_handle_join_msg():1214: Will never receive state. Need to abort.
2022-06-28T23:04:26.342518+05:30 0 [Note] [MY-000000] [Galera] gcomm: terminating thread
2022-06-28T23:04:26.342552+05:30 0 [Note] [MY-000000] [Galera] gcomm: joining thread
2022-06-28T23:04:26.342635+05:30 0 [Note] [MY-000000] [Galera] gcomm: closing backend
2022-06-28T23:04:27.344937+05:30 0 [Note] [MY-000000] [Galera] Current view of cluster as seen by this node
view (view_id(NON_PRIM,8db35066-80d2,4)
memb {
        8db35066-80d2,0
        }
joined {
        }
left {
        }
partitioned {
        ded2c73f-a972,0
        }
)
2022-06-28T23:04:27.345000+05:30 0 [Note] [MY-000000] [Galera] PC protocol downgrade 1 -> 0
2022-06-28T23:04:27.345018+05:30 0 [Note] [MY-000000] [Galera] Current view of cluster as seen by this node
view ((empty))
2022-06-28T23:04:27.345166+05:30 0 [Note] [MY-000000] [Galera] gcomm: closed
2022-06-28T23:04:27.345190+05:30 0 [Note] [MY-000000] [Galera] /usr/sbin/mysqld: Terminated.
2022-06-28T23:04:27.345206+05:30 0 [Note] [MY-000000] [WSREP] Initiating SST cancellation
2022-06-28T23:04:27.345218+05:30 0 [Note] [MY-000000] [WSREP] Terminating SST process


Logfile of node3

[testuser@testserveruat3  mysql]$ sudo tail -n 100 /var/log/mysqld.log
2022-06-28T23:18:08.990139+05:30 0 [Note] [MY-000000] [Galera] PC protocol upgrade 0 -> 1
2022-06-28T23:18:08.990329+05:30 0 [Note] [MY-000000] [Galera] Node ded2c73f-a972 state primary
2022-06-28T23:18:08.990511+05:30 0 [Note] [MY-000000] [Galera] Current view of cluster as seen by this node
view (view_id(PRIM,787db9c4-aff4,12)
memb {
        787db9c4-aff4,0
        ded2c73f-a972,0
        }
joined {
        }
left {
        }
partitioned {
        }
)
2022-06-28T23:18:08.990534+05:30 0 [Note] [MY-000000] [Galera] Save the discovered primary-component to disk
2022-06-28T23:18:08.992536+05:30 0 [Note] [MY-000000] [Galera] discarding pending addr without UUID: tcp://172.31.2.59:4567
2022-06-28T23:18:09.489362+05:30 0 [Note] [MY-000000] [Galera] gcomm: connected
2022-06-28T23:18:09.489446+05:30 0 [Note] [MY-000000] [Galera] Changing maximum packet size to 64500, resulting msg size: 32636
2022-06-28T23:18:09.489568+05:30 0 [Note] [MY-000000] [Galera] Shifting CLOSED -> OPEN (TO: 0)
2022-06-28T23:18:09.489594+05:30 0 [Note] [MY-000000] [Galera] Opened channel 'pxcragabh'
2022-06-28T23:18:09.489707+05:30 0 [Note] [MY-000000] [Galera] New COMPONENT: primary = yes, bootstrap = no, my_idx = 0, memb_num = 2
2022-06-28T23:18:09.490003+05:30 0 [Note] [MY-000000] [Galera] STATE_EXCHANGE: sent state UUID: 79169299-f70a-11ec-afb7-4612a2646ffb
2022-06-28T23:18:09.490119+05:30 2 [Note] [MY-000000] [WSREP] Starting rollbacker thread 2
2022-06-28T23:18:09.490188+05:30 1 [Note] [MY-000000] [WSREP] Starting applier thread 1
2022-06-28T23:18:09.490331+05:30 0 [Note] [MY-000000] [Galera] STATE EXCHANGE: sent state msg: 79169299-f70a-11ec-afb7-4612a2646ffb
2022-06-28T23:18:09.490527+05:30 0 [Note] [MY-000000] [Galera] STATE EXCHANGE: got state msg: 79169299-f70a-11ec-afb7-4612a2646ffb from 0 (pxc2)
2022-06-28T23:18:09.490707+05:30 0 [Note] [MY-000000] [Galera] STATE EXCHANGE: got state msg: 79169299-f70a-11ec-afb7-4612a2646ffb from 1 (pxc2)
2022-06-28T23:18:09.490733+05:30 0 [Note] [MY-000000] [Galera] Quorum results:
        version    = 6,
        component  = PRIMARY,
        conf_id    = 11,
        members    = 1/2 (primary/total),
        act_id     = 18,
        last_appl. = 7,
        protocols  = 2/10/4 (gcs/repl/appl),
        vote policy= 0,
        group UUID = 680c03b4-f3b4-11ec-ae26-a71ace89b9e1
2022-06-28T23:18:09.490771+05:30 0 [Note] [MY-000000] [Galera] Flow-control interval: [141, 141]
2022-06-28T23:18:09.490784+05:30 0 [Note] [MY-000000] [Galera] Shifting OPEN -> PRIMARY (TO: 19)
2022-06-28T23:18:09.490951+05:30 1 [Note] [MY-000000] [Galera] ####### processing CC 19, local, ordered
2022-06-28T23:18:09.490984+05:30 1 [Note] [MY-000000] [Galera] Maybe drain monitors from 1 upto current CC event 19 upto:1
2022-06-28T23:18:09.491009+05:30 1 [Note] [MY-000000] [Galera] Drain monitors from 1 up to 1
2022-06-28T23:18:09.491062+05:30 1 [Note] [MY-000000] [Galera] Process first view: 680c03b4-f3b4-11ec-ae26-a71ace89b9e1 my uuid: 787db9c4-f70a-11ec-aff4-ea275152eb29
2022-06-28T23:18:09.491098+05:30 1 [Note] [MY-000000] [Galera] Server pxc2 connected to cluster at position 680c03b4-f3b4-11ec-ae26-a71ace89b9e1:19 with ID 787db9c4-f70a-11ec-aff4-ea275152eb29
2022-06-28T23:18:09.491126+05:30 1 [Note] [MY-000000] [WSREP] Server status change disconnected -> connected
2022-06-28T23:18:09.491154+05:30 1 [Note] [MY-000000] [WSREP] wsrep_notify_cmd is not defined, skipping notification.
2022-06-28T23:18:09.491196+05:30 1 [Note] [MY-000000] [Galera] ####### My UUID: 787db9c4-f70a-11ec-aff4-ea275152eb29
2022-06-28T23:18:09.491228+05:30 1 [Note] [MY-000000] [Galera] Cert index reset to 00000000-0000-0000-0000-000000000000:-1 (proto: 10), state transfer needed: yes
2022-06-28T23:18:09.491276+05:30 0 [Note] [MY-000000] [Galera] Service thread queue flushed.
2022-06-28T23:18:09.491312+05:30 1 [Note] [MY-000000] [Galera] ####### Assign initial position for certification: 00000000-0000-0000-0000-000000000000:-1, protocol version: -1
2022-06-28T23:18:09.491342+05:30 1 [Note] [MY-000000] [Galera] State transfer required:
        Group state: 680c03b4-f3b4-11ec-ae26-a71ace89b9e1:19
        Local state: 0b30b9d6-f3a7-11ec-a44d-67d27c33010c:1
2022-06-28T23:18:09.491365+05:30 1 [Note] [MY-000000] [WSREP] Server status change connected -> joiner
2022-06-28T23:18:09.491389+05:30 1 [Note] [MY-000000] [WSREP] wsrep_notify_cmd is not defined, skipping notification.
2022-06-28T23:18:09.491477+05:30 0 [Note] [MY-000000] [WSREP] Initiating SST/IST transfer on JOINER side (wsrep_sst_xtrabackup-v2 --role 'joiner' --address '172.31.2.202' --datadir '/var/lib/mysql/' --basedir '/usr/' --plugindir '/usr/lib64/mysql/plugin/' --defaults-file '/etc/my.cnf' --defaults-group-suffix '' --parent '2485' --mysqld-version '8.0.27-18.1'   '' )
2022-06-28T23:18:09.654094+05:30 0 [Note] [MY-000000] [WSREP-SST] which: no openssl in (/usr/sbin:/sbin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin)
2022-06-28T23:18:09.654947+05:30 0 [ERROR] [MY-000000] [WSREP] Failed to read 'ready <addr>' from: wsrep_sst_xtrabackup-v2 --role 'joiner' --address '172.31.2.202' --datadir '/var/lib/mysql/' --basedir '/usr/' --plugindir '/usr/lib64/mysql/plugin/' --defaults-file '/etc/my.cnf' --defaults-group-suffix '' --parent '2485' --mysqld-version '8.0.27-18.1'   ''
        Read: ''openssl' not found in PATH'
2022-06-28T23:18:09.655254+05:30 0 [ERROR] [MY-000000] [WSREP] Process completed with error: wsrep_sst_xtrabackup-v2 --role 'joiner' --address '172.31.2.202' --datadir '/var/lib/mysql/' --basedir '/usr/' --plugindir '/usr/lib64/mysql/plugin/' --defaults-file '/etc/my.cnf' --defaults-group-suffix '' --parent '2485' --mysqld-version '8.0.27-18.1'   '' : 2 (No such file or directory)
2022-06-28T23:18:09.655332+05:30 1 [ERROR] [MY-000000] [WSREP] Failed to prepare for 'xtrabackup-v2' SST. Unrecoverable.
2022-06-28T23:18:09.655444+05:30 1 [ERROR] [MY-000000] [Galera] SST request callback failed. This is unrecoverable, restart required.
2022-06-28T23:18:09.655464+05:30 1 [Note] [MY-000000] [Galera] ReplicatorSMM::abort()
2022-06-28T23:18:09.655482+05:30 1 [Note] [MY-000000] [Galera] Closing send monitor...
2022-06-28T23:18:09.655498+05:30 1 [Note] [MY-000000] [Galera] Closed send monitor.
2022-06-28T23:18:09.655517+05:30 1 [Note] [MY-000000] [Galera] gcomm: terminating thread
2022-06-28T23:18:09.655539+05:30 1 [Note] [MY-000000] [Galera] gcomm: joining thread
2022-06-28T23:18:09.655596+05:30 1 [Note] [MY-000000] [Galera] gcomm: closing backend
2022-06-28T23:18:10.658160+05:30 1 [Note] [MY-000000] [Galera] Current view of cluster as seen by this node
view (view_id(NON_PRIM,787db9c4-aff4,12)
memb {
        787db9c4-aff4,0
        }
joined {
        }
left {
        }
partitioned {
        ded2c73f-a972,0
        }
)
2022-06-28T23:18:10.658239+05:30 1 [Note] [MY-000000] [Galera] PC protocol downgrade 1 -> 0
2022-06-28T23:18:10.658280+05:30 1 [Note] [MY-000000] [Galera] Current view of cluster as seen by this node
view ((empty))
2022-06-28T23:18:10.658418+05:30 1 [Note] [MY-000000] [Galera] gcomm: closed
2022-06-28T23:18:10.658482+05:30 0 [Note] [MY-000000] [Galera] New COMPONENT: primary = no, bootstrap = no, my_idx = 0, memb_num = 1
2022-06-28T23:18:10.658558+05:30 0 [Note] [MY-000000] [Galera] Flow-control interval: [100, 100]
2022-06-28T23:18:10.658591+05:30 0 [Note] [MY-000000] [Galera] Received NON-PRIMARY.
2022-06-28T23:18:10.658624+05:30 0 [Note] [MY-000000] [Galera] Shifting PRIMARY -> OPEN (TO: 19)
2022-06-28T23:18:10.658657+05:30 0 [Note] [MY-000000] [Galera] New SELF-LEAVE.
2022-06-28T23:18:10.658705+05:30 0 [Note] [MY-000000] [Galera] Flow-control interval: [0, 0]
2022-06-28T23:18:10.658918+05:30 0 [Note] [MY-000000] [Galera] Received SELF-LEAVE. Closing connection.
2022-06-28T23:18:10.658949+05:30 0 [Note] [MY-000000] [Galera] Shifting OPEN -> CLOSED (TO: 19)
2022-06-28T23:18:10.658982+05:30 0 [Note] [MY-000000] [Galera] RECV thread exiting 0: Success
2022-06-28T23:18:10.659091+05:30 1 [Note] [MY-000000] [Galera] recv_thread() joined.
2022-06-28T23:18:10.659112+05:30 1 [Note] [MY-000000] [Galera] Closing replication queue.
2022-06-28T23:18:10.659146+05:30 1 [Note] [MY-000000] [Galera] Closing slave action queue.
2022-06-28T23:18:10.659162+05:30 1 [Note] [MY-000000] [Galera] /usr/sbin/mysqld: Terminated.
2022-06-28T23:18:10.659177+05:30 1 [Note] [MY-000000] [WSREP] Initiating SST cancellation


1 Like

Hi…
can anyone look into this issue.?

1 Like

Hi @AneeshBabu

Can you send us the output to confirm? It certainly looks like firewall issue between nodes

Also please keep in mind that this is a volunteer-supported forum and that we will answer your questions as quickly as we can :slight_smile:

1 Like

Hi
below is the output.


[testuser@testserveruat3 ~]$ sudo nc -v -w 2  192.168.1.1 4567
Ncat: Version 7.50 ( https://nmap.org/ncat )
Ncat: Connected to 192.168.1.1 4567.
1 Like

Hi there
Please have a look on this issue .

1 Like

There is something off with your network configuration.
your nodes are

gcomm://192.168.1.1,192.168.1.2,192.168.1.3
but in logs you have:

connection established to ded2c73f-a972 tcp://172.31.15.228:4567

172.31.15.228 is not in the list of your nodes.

2 Likes