No rack controllers can access the BMC of node

[Eric Desrochers]

A user brought to my attention that he has the following configuration:

Version: 2.8.6-8602-g.07cdffcaa-0ubuntu1~18.04.1
server01 - region controller + rack controller + vip (keepalived)
server02 - region controller + rack controller + (keepalived)
db - external db
DHCP relay is used

- When server01 is down, deployment fails because "no rack controller can access BMC".
- Rack controller on server02 can access bmc address without problem.
- He manually overwrote /usr/lib/python3/dist-packages/maasserver/models/node.py with hard coded client_idents and fallback_idents, and deployment is able to complete.

It looks like `_get_bmc_client_connection_info` function fails to get appropriate rack controller that can control bmc.

[Bill Wear (billwear)]

Eric, can you reproduce this bug? If so, can you show me your reproduction of it, and if it seems correct, I'll triage this one? Moving to incomplete in the meantime.

[Eric Desrochers (slashd)]

So far it is only reproducible on customers side.

[Eric Desrochers (slashd)]

@billwear, we have some sosreport collection.

[Björn Tillenius (bjornt)]

Can you please provide the patch that he did, as well as the sosreport?

[Björn Tillenius (bjornt)]

Ok, I've managed to reproduce this locally with by having to rack controllers, one that can access the BMC via layer2, and the other that has layer3 access only.

If I turn off the first rack controller, I get the same error. There's code that should try all rack controllers if it can't find any that has a direct connection, but for some reason that code doesn't work. Will have to look into that.

To work around it, I manually inserted a row in the maasserver_bmcroutablerackcontrollerrelationship:

  https://paste.ubuntu.com/p/TFR6VT8szh/

That's the table that MAAS should update if it doesn't find a rack controller that can currently connect to the BMC.

[Dan Streetman (ddstreet)]

It seems this is now affecting single-rack setups as well; we are running a single region/rack controller at snap version 2.9.2 (9165-g.c3e7848d1), and it no longer can have new machines added. PXE booting new machines does not result in them showing up in maas, and when i manually 'add machine' with the new box ipmi info, maas raises this error "No rack controllers can access the BMC of node", even though the BMC address is reachable from the single region/rack controller.

Note that the maas controller isn't in the BMC subnet, but it can reach the BMC subnet via normal default routing through the default gateway.

This effectively breaks adding any new machines to maas.

[Eric Desrochers (slashd)]

Another impact user brought this to my attention:

We enlisted 3 racks of machines (124 nodes) successfully but were unable to successfully enlist machines in the 4th rack (only 4 out of around 40).

The machines that fail to enlist, just stay in the 'Powering On' state in the MAAS UI but via the IPMI console, we can see that the machines PXE boot and reboot. Furthermore, the machines are pretty much identical (same manufacturer/models)

Specifics:

#maas DEB package:
2.8.6-8602-g.07cdffcaa-0ubuntu1~18.04.1

# sanitized logs:
maas.api: [info] <HOSTNAME>: Enlisted new machine
maas.node: [info] <HOSTNAME>: Status transition from NEW to COMMISSIONING
maas.node: [warn] <HOSTNAME>: Could not change the power state. No rack controllers can access the BMC.
maas.node: [info] <HOSTNAME>: Aborting COMMISSIONING and reverted to NEW. Unable to power control the node. Please check power credentials.
maas.node: [info] <HOSTNAME>: Status transition from COMMISSIONING to NEW
maas.node: [error] <HOSTNAME>: Could not start node for commissioning: No rack controllers can access the BMC of node <HOSTNAME>

[Eric Desrochers (slashd)]

I'll start working on a reproducer and debug from there.
It seems like Bjornt managed to reproduce it locally using 'virsh' as a power type.

I'll deploy a similar situation and test as well.

[Eric Desrochers (slashd)]

My colleague Pedro was able to reproduce the problem.

He has 2 rack controllers (on the same subnet).

Both rack controller can access the qemu system (virsh).

Commissioning is only working when maas-rack01 is up.

I have instrumented[0] maas in order to know what code path client_idents[] and fallback_client[] generation was taking.

The results are the following:

maas-rack01 (rmmrkr)
maas-rack02 (7htx7y)

* When maas-rack01 and maas-rack02 are both UP:
2021-10-27T14:24:40.344933+00:00 maas01 maas.node: [info] DEBUG client_idents else: ['rmmrkr', '7htx7y']
2021-10-27T14:24:40.345512+00:00 maas01 maas.node: [info] DEBUG fallback_idents: []

* When maas-rack01 is DOWN and maas-rack02 UP
maas.log:2021-10-27T14:14:00.076812+00:00 maas01 maas.node: [info] DEBUG client_idents else: []
maas.log:2021-10-27T14:14:00.079471+00:00 maas01 maas.node: [info] DEBUG fallback_idents: []

* Comparing the route on both maas, they weren't identical, we fix maas-rack02 to make it identical to maas-rack01 and then:
maas.log:2021-10-27T14:23:12.954083+00:00 maas01 maas.node: [info] DEBUG client_idents else: ['7htx7y']
maas.log:2021-10-27T14:23:12.954218+00:00 maas01 maas.node: [info] DEBUG fallback_idents: []

When both controllers are UP (regardless of the route) we saw both, then we stop maas-rack01, we lost both, until we fix the route.

The whole time, maas-rack02 was able to access the QEMU system.

Is it possible that MAAS is expecting both rack controller to have the exact same routing table ?

[0] diff --git a/src/maasserver/models/node.py b/src/maasserver/models/node.py
index 532c45a90..9bc3952bf 100644
--- a/src/maasserver/models/node.py
+++ b/src/maasserver/models/node.py
@@ -5331,11 +5331,15 @@ class Node(CleanSave, TimestampedModel):
         """
         if self.bmc is None:
             client_idents = []
+ maaslog.info("DEBUG client_idents if: %s" % client_idents)
         else:
             client_idents = self.bmc.get_client_identifiers()
+ maaslog.info("DEBUG client_idents else: %s" % client_idents)
         fallback_idents = [
             rack.system_id for rack in self.get_boot_rack_controllers()
         ]
+ maaslog.info("DEBUG fallback_idents: %s" % fallback_idents)
+
         if len(client_idents) == 0 and len(fallback_idents) == 0:
             err_msg = "No rack controllers can access the BMC of node %s" % (
                 self.hostname
--
2.25.1

[Eric Desrochers (slashd)]

[Part 2]

# maas-rack01
root@maas01:/var/log/maas# ip r
default via 172.16.99.1 dev enp7s0 proto static
default via 192.168.10.1 dev enp1s0 proto dhcp src 192.168.10.23 metric 100
172.16.99.0/24 dev enp7s0 proto kernel scope link src 172.16.99.5
192.168.10.0/24 dev enp1s0 proto kernel scope link src 192.168.10.23
192.168.10.1 dev enp1s0 proto dhcp scope link src 192.168.10.23 metric 100

# maas-rack02
virsh -c qemu+ssh://pedrovlf@172.16.99.1/system list
pedrovlf@172.16.99.1's password:
 Id Name State
----------------------------------------------------
 8 maas01 running
 9 maas02 running

ubuntu@maas02:~$ ip r
default via 172.16.99.1 dev enp7s0 proto static # the route we added, without this route, when maas-rack01 is DOWN, we can't commission nodes. Even if the rack controller can access the QEMU system.
default via 192.168.10.1 dev enp1s0 proto dhcp src 192.168.10.52 metric 100
172.16.99.0/24 dev enp7s0 proto kernel scope link src 172.16.99.6
192.168.10.0/24 dev enp1s0 proto kernel scope link src 192.168.10.52
192.168.10.1 dev enp1s0 proto dhcp scope link src 192.168.10.52 metric 100

[Eric Desrochers (slashd)]

client_idents[] is generated by the result of get_client_identifiers() which calls get_usable_rack_controllers() which calls get_layer2_usable_rack_controllers() to access BMC using layer2.

If no layer2 routable rack controller found, it moves to get_routable_usable_rack_controllers() which interact with the DB to find if the rack controller is routable.

In our reproducer, the rack controllers were routable at all time with maked with a 't'.

and then it returns the racks.

[Eric Desrochers (slashd)]

Instrumenting the routable_racks in get_routable_usable_rack_controllers()

We got the following:

maas.log:2021-10-27T16:12:49.988824+00:00 maas01 maas.node: [info] DEBUG in get_routable_usable_rack_controllers() routable_racks: []

[Eric Desrochers (slashd)]

maas01 = Down
maas02 = Up

I have instructed get_usable_rack_controllers() to only use self.get_layer2_usable_rack_controllers() in that case, it fails to find the working rack (maas02) as follows:

2021-11-03T15:24:18.376679+00:00 maas01 maas.node: [info] vmtest: Status transition from NEW to COMMISSIONING
2021-11-03T15:24:18.506998+00:00 maas01 maas.node: [info] DEBUG layer2 get_usable_rack_controllers racks: [<RackController: rmmrkr (maas01)>]
2021-11-03T15:24:18.541500+00:00 maas01 maas.node: [info] DEBUG layer2 get_usable_rack_controllers racks: []
2021-11-03T15:24:18.542087+00:00 maas01 maas.node: [info] DEBUG client_idents else: []
2021-11-03T15:24:18.555902+00:00 maas01 maas.node: [info] DEBUG fallback_idents: ['rmmrkr']
2021-11-03T15:24:18.567139+00:00 maas01 maas.node: [info] vmtest: Aborting COMMISSIONING and reverted to NEW. Unable to power control the node. Please check power credentials.
2021-11-03T15:24:18.602687+00:00 maas01 maas.node: [info] vmtest: Status transition from COMMISSIONING to NEW
2021-11-03T15:24:18.705983+00:00 maas01 maas.node: [error] vmtest: Could not start node for commissioning: Unable to connect to any rack controller rmmrkr; no connections available.

But if I instructed get_usable_rack_controllers() to only use self.get_routable_usable_rack_controllers() which if I read this right, query the Database, then it works:

2009 2021-11-03T15:19:42.812047+00:00 maas01 maas.node: [info] DEBUG in get_routable_usable_rack_controllers() routable_racks: [<RackControl ler: rmmrkr (maas01)>, <RackController: 7htx7y (maas02)>]
2010 2021-11-03T15:19:42.812156+00:00 maas01 maas.node: [info] DEBUG database racks: [<RackController: rmmrkr (maas01)>, <RackController: 7h tx7y (maas02)>]
2011 2021-11-03T15:19:42.819889+00:00 maas01 maas.node: [info] DEBUG in get_routable_usable_rack_controllers() routable_racks: [<RackControl ler: rmmrkr (maas01)>, <RackController: 7htx7y (maas02)>]
2012 2021-11-03T15:19:42.820324+00:00 maas01 maas.node: [info] DEBUG database racks: [<RackController: 7htx7y (maas02)>]
2013 2021-11-03T15:19:42.820434+00:00 maas01 maas.node: [info] DEBUG client_idents else: ['7htx7y']
2014 2021-11-03T15:19:42.825616+00:00 maas01 maas.node: [info] DEBUG fallback_idents: ['rmmrkr']
2015 2021-11-03T15:19:11+00:00 maas02 maas.service_monitor: [info] Service 'maas-proxy' has been started and is 'running'.
2016 2021-11-03T15:19:42+00:00 maas02 maas.power: [info] Changing power state (off) of node: vmtest (kengcd)
2017 2021-11-03T15:19:42.881516+00:00 maas01 maas.node: [info] vmtest: Status transition from COMMISSIONING to NEW

At first glance, the problem might be located in get_layer2_usable_rack_controllers().

[Eric Desrochers (slashd)]

To summarize:

maas01 rack service UP and maas02 rack service UP /w maas02's interface up in the subnet: GOOD
maas01 rack service DOWN and maas02 rack service UP /w maas02's interface up in the subnet: GOOD
maas01 rack service DOWN and maas02 rack service UP /wo maas02's interface up in the subnet: BAD

On comment #17, I was suspecting get_layer2_usable_rack_controllers() since the problem since to start from there, but in fact it sounds like it might be in get_best_subnet_for_ip() which is called inside get_layer2_usable_rack_controllers().

If the rack controller doesn't have a direct route to the subnet of the BMC (even if the rack controller access the BMC just fine) it doesn't seem to return the given rack and consider it as a usable/routable one)

[Eric Desrochers (slashd)]

rmmrkr == maas01 (DOWN)
7htx7y == maas02 (UP)

This time I instrumented the get_best_subnet_for_ip() method:

2021-11-05T14:54:48.521389+00:00 maas01 maas.rpc.rackcontrollers: [info] Existing rack controller 'maas02' running version 2.8.7-8611-g.f2514168f-0ubuntu1~18.04.1 has connected to region 'maas01'.
2021-11-05T14:54:48.708314+00:00 maas01 maas.rpc.rackcontrollers: [info] Existing rack controller 'maas02' running version 2.8.7-8611-g.f2514168f-0ubuntu1~18.04.1 has connected to region 'maas01'.
2021-11-05T14:54:52.263227+00:00 maas01 maas.node: [info] vmtest: Status transition from NEW to COMMISSIONING
2021-11-05T14:54:52.407983+00:00 maas01 maas.subnet: [info] DEBUG ip: 172.16.99.1
2021-11-05T14:54:52.408188+00:00 maas01 maas.subnet: [info] DEBUG subnets: <RawQuerySet: #012 SELECT DISTINCT#012 subnet.*,#012 masklen(subnet.cidr) "prefixlen",#012 vlan.dhcp_on "dhcp_on"#012 FROM maasserver_subnet AS subnet#012 INNER JOIN maasserver_vlan AS vlan#012 ON subnet.vlan_id = vlan.id#012 WHERE#012 172.16.99.1 << subnet.cidr /* Specified IP is inside range */#012 ORDER BY#012 /* Pick subnet that is on a VLAN that is managed over a subnet#012 that is not managed on a VLAN. */#012 dhcp_on DESC,#012 /* If there are multiple subnets we want to pick the most specific#012 one that the IP address falls within. */#012 prefixlen DESC#012 LIMIT 1#012 >
2021-11-05T14:54:52.409355+00:00 maas01 maas.subnet: [info] DEBUG ip: 172.16.99.1
2021-11-05T14:54:52.409514+00:00 maas01 maas.subnet: [info] DEBUG subnets: <RawQuerySet: #012 SELECT DISTINCT#012 subnet.*,#012 masklen(subnet.cidr) "prefixlen",#012 vlan.dhcp_on "dhcp_on"#012 FROM maasserver_subnet AS subnet#012 INNER JOIN maasserver_vlan AS vlan#012 ON subnet.vlan_id = vlan.id#012 WHERE#012 172.16.99.1 << subnet.cidr /* Specified IP is inside range */#012 ORDER BY#012 /* Pick subnet that is on a VLAN that is managed over a subnet#012 that is not managed on a VLAN. */#012 dhcp_on DESC,#012 /* If there are multiple subnets we want to pick the most specific#012 one that the IP address falls within. */#012 prefixlen DESC#012 LIMIT 1#012 >
2021-11-05T14:54:52.414451+00:00 maas01 maas.node: [info] DEBUG layer2 get_usable_rack_controllers racks: [<RackController: rmmrkr (maas01)>]
2021-11-05T14:54:52.415302+00:00 maas01 maas.subnet: [info] DEBUG ip: 172.16.99.1
2021-11-05T14:54:52.415510+00:00 maas01 maas.subnet: [info] DEBUG subnets: <RawQuerySet: #012 SELECT DISTINCT#012 subnet.*,#012 masklen(subnet.cidr) "prefixlen",#012 vlan.dhcp_on "dhcp_on"#012 FROM maasserver_subnet AS subnet#012 INNER JOIN maasserver_vlan AS vlan#012 ON subnet.vlan_id = vlan.id#012 WHERE#012 172.16.99.1 << subnet.cidr /* Specified IP is inside range */#012 ORDER BY#012 /* Pick subnet that is on a VLA...