Description

In paragon 23.1, we may encounter the frequent safe mode alerts in the cluster setup.

Symptoms

When checked the rabbitMQ logs , We could see crash report and this is causing socket closed. We could see upstream stream channel

shutdown and this intern causing socket close. So this indicates that the connection between both the sites is closing.

 

Master site:

 

** socket_closed_unexpectedly

2024-11-22 06:00:05.184 [error] <0.18386.0> CRASH REPORT Process <0.18386.0> with 0 neighbours exited with reason:

socket_closed_unexpectedly in gen_server:handle_common_reply/8 line 751

2024-11-22 06:00:05.184 [error] <0.18384.0> Supervisor {<0.18384.0>,amqp_connection_sup} had child connection started

with amqp_gen_connection:start_link(<0.18385.0>,

{amqp_params_network,<<"northstar">>,{encrypted,<<"QzmluZvxU0ZiOe21iHxF55p7WifPkPPagOAkb7V623k9tj9...">>},...}) at

<0.18386.0> exit with reason socket_closed_unexpectedly in context child_terminated

2024-11-22 06:00:05.184 [error] <0.18384.0> Supervisor {<0.18384.0>,amqp_connection_sup} had child connection started

with amqp_gen_connection:start_link(<0.18385.0>,

{amqp_params_network,<<"northstar">>,{encrypted,<<"QzmluZvxU0ZiOe21iHxF55p7WifPkPPagOAkb7V623k9tj9...">>},...}) at

<0.18386.0> exit with reason reached_max_restart_intensity in context shutdown

2024-11-22 06:00:05.184 [error] <0.18371.0> ** Generic server <0.18371.0> terminating

** Last message in was {'DOWN',#Ref<0.3928699797.390856705.35790>,process,<0.18402.0>,shutdown}

** When Server state ==

{state,{upstream,[{encrypted,<<"B8YWyj038Fi1P9tuyeEGy5t1DhEpQ4eba+ek1jJ/vFH5cYgnr6+rPUZZori7cIXvgRMPMVPCsjmtFnspKnQv08

L4hDnWkwJzkIX5SBOLFTs3m01MZXlZpcmW5sYMgmOLmKvYZrFQovq7eW2XRnDqjUP3j6kIZbXJRQ/KdqAonVcoAZPZsA/EFlog1Kvm90FallInNVyRojU6

7RJ3HvB8dA==">>}],<<"controller.federated.topo">>,<<"controller.federated.topo">>,<<"federation-link-myupstream">>,

1000,1,5,15000,none,false,'on-confirm',none,<<"myupstream">>,

false,default},{upstream_params,{encrypted,<<"OjGjXXwTkYZ9CKx804xZWzCDSJgOZyb+G90fe/GkJFYTMXJee531BOkt0jHL

f/w/H7EYicgZsPte/3p9Q2gVj7sGbsqM3o9unrhRCWHk0jHrI5a1ADmtGLMxiVylo4ut5Jl9mzWkJqnEm7obEMvPXrb9ZZNx3aEKMNLQNjKYVNlU1AFCsN

MF7wGuHGn5RFmD8uHAojK0piHiyBcVs4x2tA==">>},{amqp_params_network,<<"northstar">>,{encrypted,<<"loJrbNewcK82fKGpaz/UMbA4

RXI1RA+InBxe+cFnadTWBN/NemkliNfKZPZII5Q8">>},<<"/">>,"10.16.2.19",undefined,2047,0,10,60000,[{verify,verify_none},

{cacertfile,"/opt/bitnami/rabbitmq/certs/ca_certificate.pem"}],[#Fun<amqp_uri.12.131604370>,#Fun<amqp_uri.12.131604370

>],[],[]},{exchange,{resource,<<"/">>,exchange,<<"controller.federated.topo">>},direct,false,false,false,[],[{federati

on,[{{<<"my-upstream">>,<<"controller.federated.topo">>},<<"B">>}]}],[{vhost,<<"/">>},{name,<<"federateme">>},{

pattern,<<"^controller\\.federated\\.">>},{'apply-to',<<"exchanges">>},{definition,[{<<"federation-upstreamset">>,<<"

all">>}]},{priority,0}],undefined,{[],[rabbit_federation_exchange]},#{user =>

<<"northstar">>}},<<"amqps://10.16.2.19">>,[{<<"uri">>,longstr,<<"amqps://10.16.2.19">>},{<<"exchange">>,longs

tr,<<"controller.federated.topo">>}]},<<[email protected].

northstar.svc.cluster.local>>,<0.18386.0>,<0.18398.0>,<0.18402.0>,<<"amq.ctag-mtWgU3l11aMPJA2-

FmUnfw">>,<<"federation: controller.federated.topo -> [email protected].

northstar.svc.cluster.local">>,<<"federation: controller.federated.topo -> rabbit@rabbitmq-0....">>,...}

** Reason for termination ==

** {upstream_channel_down,shutdown}

2024-11-22 06:00:05.185 [error] <0.18371.0> CRASH REPORT Process <0.18371.0> with 0 neighbours exited with reason:

{upstream_channel_down,shutdown} in gen_server2:terminate/3 line 1183

2024-11-22 06:00:05.185 [error] <0.5610.0> Supervisor {<0.5610.0>,rabbit_federation_link_sup} had child

{upstream,[{encrypted,<<"B8YWyj038Fi1P9tuyeEGy5t1DhEpQ4eba+ek1jJ/vFH5cYgnr6+rPUZZori7cIXvgRMPMVPCsjmtFnspKnQv08L4hDnWk

wJzkIX5SBOLFTs3m01MZXlZpcmW5sYMgmOLmKvYZrFQovq7eW2XRnDqjUP3j6kIZbXJRQ/KdqAonVcoAZPZsA/EFlog1Kvm90FallInNVyRojU67RJ3HvB

8dA==">>}],

<<"controller.federated.topo">>,<<"controller.federated.topo">>,

<<"federation-link-my-upstream">>,1000,1,5,15000,none,false,

'on-confirm',none,<<"my-upstream">>,false,default} started with

rabbit_federation_exchange_link:start_link({{upstream,[{encrypted,<<"B8YWyj038Fi1P9tuyeEGy5t1DhEpQ4eba+ek1jJ/vFH5cYgnr

6+rPUZZori7cIXvgRMPMV...">>}],...},...}) at <0.18371.0> exit with reason {upstream_channel_down,shutdown} in context

child_terminated

2024-11-22 06:00:05.575 [info] <0.20196.0> closing AMQP connection <0.20196.0> (10.24.3.9:38480 ->

10.24.3.13:5671, vhost: '/', user: 'northstar')

 

Backup site:

 

Noticing missed heartbeats and this causing connection to close.

 

2024-11-22 05:27:20.884 [error] <0.12878.0> closing AMQP connection <0.12878.0> (10.24.4.15:51474 ->10.24.4.15:5671 - Federation link (upstream: my-upstream, policy: federate-me)):missed heartbeats from client, timeout: 10s

--

2024-11-22 05:29:50.869 [error] <0.14230.0> closing AMQP connection <0.14230.0> (10.24.4.15:37952 ->10.24.4.15:5671 - Federation link (upstream: my-upstream, policy: federate-me)):missed heartbeats from client, timeout: 10s

--

2024-11-22 05:43:20.868 [error] <0.16818.0> closing AMQP connection <0.16818.0> (10.24.4.15:52784 ->10.24.4.15:5671 - Federation link (upstream: my-upstream, policy: federate-me)):missed heartbeats from client, timeout: 10s

--

2024-11-22 05:44:40.864 [error] <0.17382.0> closing AMQP connection <0.17382.0> (10.24.4.155:41622 ->10.24.4.15:5671 - Federation link (upstream: my-upstream, policy: federate-me)):missed heartbeats from client, timeout: 10s

--

2024-11-22 06:10:25.782 [error] <0.22793.0> closing AMQP connection <0.22793.0> (10.24.4.155:49622 ->10.24.4.15:5671 - Federation link (upstream: my-upstream, policy: federate-me)):missed heartbeats from client, timeout: 10s

 

 

 

 

 

Solution

We are frequently noticing this heartbeats missing and because of this the connection is getting closed.


2024-11-22 05:29:50.869 [error] <0.14230.0> closing AMQP connection <0.14230.0> (10.24.4.157:37952 ->10.24.4.15:5671 - Federation link (upstream: my-upstream, policy: federate-me)): missed heartbeats from client, timeout: 10s


Communication for the federate exchange happens through ambassador , where the connection is managed through port 5671 and it will communicate to the VIP ip of the site which will be the web UI..

 

CommunicationFlow: Master site rabbitmq > router > intranet > BackUP Site cluster VIP > ambassador pod > BackUP site rabbitmq pod


We need to understand why the timeouts are noticed and also why the socket is getting closed. 

 

We need to collect below info:

 

  • Collect metallb logs

# kubectl logs -n metallb-system controller-<UUID>

# kubectl logs -n metallb-system speaker-<UUID>

  • Collect ambassador logs

# kubectl logs -n ambassador ambassador-<UUID>

  • Collect RabbitMQ logs

#kubectl logs -n northstar rabbitmq-0 rabbitmq

#kubectl logs -n northstar rabbitmq-1 rabbitmq

#kubectl logs -n northstar rabbitmq-2 rabbitmq

  • Collect the tcpdump to verify it’s because of the VIP ip changing between the sites, need to enable PCAP on all nodes.

#tcpdump -n -i <external interface> -s 0 -w xxx.pcap "port 5671 or arp"

  • Get below output from both the sites.

# kubectl exec -it rabbitmq-0 -n northstar -- bin/bash -c 'for i in 0 1 2; do rabbitmqctl federation_status -n rabbit@rabbitmq-$i.rabbitmq-headless.northstar.svc.cluster.local; done'

  • Verify the sources of truth for the respective sites.

#root@ns-cmgd-57dd5659c4-x5x5r> show configuration |display set

set northstar topology-server application source-of-truth




###########################


 So on the further troubleshooting PCAP on all the nodes which were captured

  • From the PCAP, we notice the VIP is moving from one node to other node.
    • At least, we can see 2 different mac
    • We can’t tell this is because metallb move the VIP from one node to another, or it is the upstream router has incorrect mac table.
      • We need to check all metallb speaker and controller pod , normally metallb will log if they move the VIP to different node
  • We can also see that Master received TCP reset from backup but we could not find the same packet on backup side
    • This can happen if VIP is moved (or VIP to mac addr mapping change) while TCP session still live
    • After the VIP moved, the new node does not know anything about existing session, so it will send the TCP reset.


In general, we should have VIP IP mapped to one of the ambassador node, but here in this case we could see that the its flapping between two ambassador nodes and because of this the TCP connections are getting disconnected because of different mac address for the VIP IP and this intern causing the federate exchange going down.

 

Restarting metallb & Ambassador pods will recover the issue. 



Modification History

2025-01-29 : Article Created