search

codership / galera

Synchronous multi-master replication library
GNU General Public License v2.0
450 stars 176 forks source link

Galera arbitrator 4 Protocol violation. JOIN message sender is not in state transfer (SYNCED) #626

Open miro-igov opened 2 years ago

miro-igov commented 2 years ago

Hello, i see strange warnings in Galera Arbitrator 26.4.12.r log file. The cluster consist of 2 nodes: intranet-test1 192.168.2.54 and intranet-test2 192.168.2.55. On a LXC container i run garb 192.168.2.59. If i stop a node, for example intranet-test2 "service mysql stop" and later i start the node, i see the following in garb log:

2022-09-30 17:39:16.498  INFO:  cleaning up 77b781a1-a057 (ssl://192.168.2.55:4567)
2022-09-30 17:40:43.562  INFO: (62b7836b-b891, 'ssl://0.0.0.0:4567') turning message relay requesting on, nonlive peers: ssl://192.168.2.55:4567
2022-09-30 17:40:43.574  INFO: (62b7836b-b891, 'ssl://0.0.0.0:4567') connection established to 3e91a835-ba37 ssl://192.168.2.55:4567
2022-09-30 17:40:44.035  INFO: declaring 3e91a835-ba37 at ssl://192.168.2.55:4567 stable
2022-09-30 17:40:44.038  INFO: declaring 721d5346-b744 at ssl://192.168.2.54:4567 stable
2022-09-30 17:40:44.043  INFO: Node 62b7836b-b891 state prim
.
.
.
2022-09-30 17:40:44.959  WARN: Protocol violation. JOIN message sender 2.0 (intranet-test1) is not in state transfer (SYNCED). Message ignored.
2022-09-30 17:40:45.163  WARN: Rejecting JOIN message from 0.0 (intranet-test2): new State Transfer required.
2022-09-30 17:40:45.168  WARN: SYNC message from non-JOINED 0.0 (intranet-test2, PRIMARY). Ignored.

Why JOIN message sender is intranet-test1? The joining node is intranet-test2

2022-09-30 17:40:43 0 [Note] WSREP: gcomm: connecting to group 'Intranet Cluster (Test)', peer '192.168.2.54:,192.168.2.55:,192.168.2.59:'
2022-09-30 17:40:43 0 [Note] WSREP: (3e91a835-ba37, 'ssl://0.0.0.0:4567') Found matching local endpoint for a connection, blacklisting address ssl://192.168.2.55:4567
2022-09-30 17:40:43 0 [Note] WSREP: (3e91a835-ba37, 'ssl://0.0.0.0:4567') connection established to 721d5346-b744 ssl://192.168.2.54:4567
2022-09-30 17:40:43 0 [Note] WSREP: (3e91a835-ba37, 'ssl://0.0.0.0:4567') turning message relay requesting on, nonlive peers:
2022-09-30 17:40:43 0 [Note] WSREP: (3e91a835-ba37, 'ssl://0.0.0.0:4567') connection established to 62b7836b-b891 ssl://192.168.2.59:4567
.
.
.
022-09-30 17:40:44 1 [Note] WSREP: Server status change connected -> joiner
2022-09-30 17:40:44 1 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
2022-09-30 17:40:44 0 [Note] WSREP: Joiner monitor thread started to monitor
2022-09-30 17:40:44 0 [Note] WSREP: Running: 'wsrep_sst_mariabackup --role 'joiner' --address '192.168.2.55' --datadir '/var/lib/mysql/' --parent 244663 --progress 0 --mysqld-args --wsrep_start_position=a6d885cf-23bd-11ed-a7b5-fb2da02f3a3d:13545'
WSREP_SST: [INFO] mariabackup SST started on joiner (20220930 17:40:44.552)
.
.
.
2022-09-30 17:40:44 1 [Note] WSREP: IST receiver addr using ssl://192.168.2.55:4568
2022-09-30 17:40:44 1 [Note] WSREP: IST receiver using ssl
2022-09-30 17:40:44 1 [Note] WSREP: Prepared IST receiver for 13546-13552, listening at: ssl://192.168.2.55:4568
2022-09-30 17:40:44 0 [Note] WSREP: Member 0.0 (intranet-test2) requested state transfer from '*any*'. Selected 2.0 (intranet-test1)(SYNCED) as donor.
2022-09-30 17:40:44 0 [Note] WSREP: Shifting PRIMARY -> JOINER (TO: 13552)
2022-09-30 17:40:44 1 [Note] WSREP: Requesting state transfer: success, donor: 2
2022-09-30 17:40:44 0 [Note] WSREP: 2.0 (intranet-test1): State transfer to 0.0 (intranet-test2) complete.
2022-09-30 17:40:44 0 [Note] WSREP: Member 2.0 (intranet-test1) synced with group.
2022-09-30 17:40:44 3 [Note] WSREP: SST received
2022-09-30 17:40:44 3 [Note] WSREP: Server status change joiner -> initializing

Does this mean that garb wrongly interprets which is the joiner node?

miro-igov commented 1 year ago

No ideas?