[2.5] MAAS doesn't sync resource-pools with RBAC

Bug #1814114 reported by Andres Rodriguez
12
This bug affects 1 person
Affects Status Importance Assigned to Milestone
MAAS
Fix Released
Critical
Blake Rouse
2.5
Fix Released
Critical
Blake Rouse

Bug Description

I had a running MAAS that was previously working with Candid and RBAC. I had to completely re-installed candid and upgraded to a new rev of MAAS. After I tried to connect MAAS to new RBAC/Candid, no resource pools are available in RBAC even though they are available in MAAS.

There are no logs. Restarting MAAS yields no logs for RBAC (regiond.log):

2019-01-31 14:33:18 twisted.scripts: [info] twistd 17.9.0 (/usr/bin/python3 3.6.7) starting up.
2019-01-31 14:33:18 twisted.scripts: [info] reactor class: twisted.internet.asyncioreactor.AsyncioSelectorReactor.
2019-01-31 14:33:19 maasserver.regiondservices.active_discovery: [info] Active network discovery: Discovery interval set to 10800 seconds.
2019-01-31 14:33:19 maasserver.listener: [info] Listening for database notifications.
2019-01-31 14:33:19 maasserver.region_controller: [info] Synced RBAC service; regiond started.
2019-01-31 14:33:19 maasserver.regiondservices.active_discovery: [info] Active network discovery: Active scanning is not enabled on any subnet. Skipping periodic scan.
2019-01-31 14:33:20 stderr: [error] request to http://127.0.0.1:5240/MAAS/metadata/2012-03-01/ failed. sleeping 1.: <urlopen error [Errno 111] Connection refused>
2019-01-31 14:33:20 maasserver.region_controller: [info] Successfully configured proxy.
2019-01-31 14:33:21 stderr: [error] request to http://127.0.0.1:5240/MAAS/metadata/2012-03-01/ failed. sleeping 1.: <urlopen error [Errno 111] Connection refused>
2019-01-31 14:33:22 stderr: [error] request to http://127.0.0.1:5240/MAAS/metadata/2012-03-01/ failed. sleeping 2.: <urlopen error [Errno 111] Connection refused>
2019-01-31 14:33:22 twisted.scripts: [info] twistd 17.9.0 (/usr/bin/python3 3.6.7) starting up.
2019-01-31 14:33:22 twisted.scripts: [info] reactor class: twisted.internet.asyncioreactor.AsyncioSelectorReactor.
2019-01-31 14:33:22 -: [info] IPCWorker connection established (HOST:UNIXAddress(None) PEER:UNIXAddress('/var/lib/maas/maas-regiond.sock'))
2019-01-31 14:33:22 twisted.internet.protocol.Factory: [info] IPCMaster connection established (HOST:UNIXAddress('/var/lib/maas/maas-regiond.sock') PEER:UNIXAddress(None))
2019-01-31 14:33:22 maasserver.listener: [info] Listening for database notifications.
2019-01-31 14:33:22 maasserver.ipc: [info] Worker pid:9267 IPC connected.
2019-01-31 14:33:22 twisted.scripts: [info] twistd 17.9.0 (/usr/bin/python3 3.6.7) starting up.
2019-01-31 14:33:22 twisted.scripts: [info] reactor class: twisted.internet.asyncioreactor.AsyncioSelectorReactor.
2019-01-31 14:33:23 twisted.scripts: [info] twistd 17.9.0 (/usr/bin/python3 3.6.7) starting up.
2019-01-31 14:33:23 twisted.scripts: [info] reactor class: twisted.internet.asyncioreactor.AsyncioSelectorReactor.
2019-01-31 14:33:23 twisted.scripts: [info] twistd 17.9.0 (/usr/bin/python3 3.6.7) starting up.
2019-01-31 14:33:23 twisted.scripts: [info] reactor class: twisted.internet.asyncioreactor.AsyncioSelectorReactor.
2019-01-31 14:33:23 twisted.internet.protocol.Factory: [info] IPCMaster connection established (HOST:UNIXAddress('/var/lib/maas/maas-regiond.sock') PEER:UNIXAddress(None))
2019-01-31 14:33:23 -: [info] IPCWorker connection established (HOST:UNIXAddress(None) PEER:UNIXAddress('/var/lib/maas/maas-regiond.sock'))
2019-01-31 14:33:23 maasserver.ipc: [info] Worker pid:9267 opened RPC listener on port:5250.
2019-01-31 14:33:23 maasserver.ipc: [info] Worker pid:9266 IPC connected.
2019-01-31 14:33:23 -: [info] IPCWorker connection established (HOST:UNIXAddress(None) PEER:UNIXAddress('/var/lib/maas/maas-regiond.sock'))
2019-01-31 14:33:23 twisted.internet.protocol.Factory: [info] IPCMaster connection established (HOST:UNIXAddress('/var/lib/maas/maas-regiond.sock') PEER:UNIXAddress(None))
2019-01-31 14:33:23 maasserver.listener: [info] Listening for database notifications.
2019-01-31 14:33:23 twisted.internet.protocol.Factory: [info] IPCMaster connection established (HOST:UNIXAddress('/var/lib/maas/maas-regiond.sock') PEER:UNIXAddress(None))
2019-01-31 14:33:23 -: [info] IPCWorker connection established (HOST:UNIXAddress(None) PEER:UNIXAddress('/var/lib/maas/maas-regiond.sock'))
2019-01-31 14:33:23 maasserver.listener: [error] Unable to connect to database: dictionary changed size during iteration
2019-01-31 14:33:23 maasserver.ipc: [info] Worker pid:9268 IPC connected.
2019-01-31 14:33:23 maasserver.ipc: [info] Worker pid:9265 IPC connected.
2019-01-31 14:33:23 maasserver.listener: [error] Unable to connect to database: dictionary changed size during iteration
2019-01-31 14:33:23 regiond: [info] 127.0.0.1 GET /MAAS/rpc/ HTTP/1.1 --> 200 OK (referrer: -; agent: provisioningserver.rpc.clusterservice.ClusterClientService)
2019-01-31 14:33:23 twisted.internet.protocol.Factory: [info] RegionServer connection established (HOST:IPv6Address(TCP, '::ffff:192.168.1.13', 5250) PEER:IPv6Address(TCP, '::ffff:192.168.1.13', 54574))
2019-01-31 14:33:23 maasserver.rpc.regionservice: [info] Rack controller authenticated from '::ffff:192.168.1.13:54574'.
2019-01-31 14:33:23 maasserver.ipc: [info] Worker pid:9268 opened RPC listener on port:5252.
2019-01-31 14:33:23 maasserver.ipc: [info] Worker pid:9266 opened RPC listener on port:5251.
2019-01-31 14:33:23 maasserver.ipc: [info] Worker pid:9265 opened RPC listener on port:5253.
2019-01-31 14:33:23 maasserver.ipc: [info] Worker pid:9267 registered RPC connection to ('xrrxcb', '192.168.1.13', 5250).
2019-01-31 14:33:24 regiond: [info] 127.0.0.1 GET /MAAS/rpc/ HTTP/1.1 --> 200 OK (referrer: -; agent: provisioningserver.rpc.clusterservice.ClusterClientService)
2019-01-31 14:33:24 twisted.internet.protocol.Factory: [info] RegionServer connection established (HOST:IPv6Address(TCP, '::ffff:192.168.1.13', 5251) PEER:IPv6Address(TCP, '::ffff:192.168.1.13', 37608))
2019-01-31 14:33:24 twisted.internet.protocol.Factory: [info] RegionServer connection established (HOST:IPv6Address(TCP, '::ffff:192.168.1.13', 5252) PEER:IPv6Address(TCP, '::ffff:192.168.1.13', 41628))
2019-01-31 14:33:24 twisted.internet.protocol.Factory: [info] RegionServer connection established (HOST:IPv6Address(TCP, '::ffff:192.168.100.1', 5253) PEER:IPv6Address(TCP, '::ffff:192.168.100.1', 51882))
2019-01-31 14:33:24 maasserver.rpc.regionservice: [info] Rack controller authenticated from '::ffff:192.168.1.13:37608'.
2019-01-31 14:33:24 maasserver.rpc.regionservice: [info] Rack controller authenticated from '::ffff:192.168.1.13:41628'.
2019-01-31 14:33:24 maasserver.rpc.regionservice: [info] Rack controller authenticated from '::ffff:192.168.100.1:51882'.
2019-01-31 14:33:24 regiond: [info] 127.0.0.1 POST /MAAS/metadata/2012-03-01/ HTTP/1.1 --> 200 OK (referrer: -; agent: Python-urllib/3.6)
2019-01-31 14:33:24 maasserver.ipc: [info] Worker pid:9266 registered RPC connection to ('xrrxcb', '192.168.1.13', 5251).
2019-01-31 14:33:25 maasserver.ipc: [info] Worker pid:9268 registered RPC connection to ('xrrxcb', '192.168.1.13', 5252).
2019-01-31 14:33:25 maasserver.ipc: [info] Worker pid:9265 registered RPC connection to ('xrrxcb', '192.168.100.1', 5253).
2019-01-31 14:33:25 maasserver.region_controller: [info] Reloaded DNS configuration; regiond started.
2019-01-31 14:33:25 regiond: [info] 127.0.0.1 POST /MAAS/metadata/2012-03-01/ HTTP/1.1 --> 200 OK (referrer: -; agent: Python-urllib/3.6)
2019-01-31 14:33:26 maasserver.listener: [info] Listening for database notifications.
2019-01-31 14:33:26 maasserver.listener: [info] Listening for database notifications.
2019-01-31 14:33:26 regiond: [info] 127.0.0.1 POST /MAAS/metadata/2012-03-01/ HTTP/1.1 --> 200 OK (referrer: -; agent: Python-urllib/3.6)
2019-01-31 14:33:26 regiond: [info] 127.0.0.1 POST /MAAS/metadata/2012-03-01/ HTTP/1.1 --> 200 OK (referrer: -; agent: Python-urllib/3.6)
2019-01-31 14:33:27 regiond: [info] 127.0.0.1 POST /MAAS/metadata/2012-03-01/ HTTP/1.1 --> 200 OK (referrer: -; agent: Python-urllib/3.6)
2019-01-31 14:33:27 regiond: [info] 127.0.0.1 GET /MAAS/rpc/ HTTP/1.1 --> 200 OK (referrer: -; agent: provisioningserver.rpc.clusterservice.ClusterClientService)
2019-01-31 14:33:28 regiond: [info] 127.0.0.1 POST /MAAS/metadata/2012-03-01/ HTTP/1.1 --> 200 OK (referrer: -; agent: Python-urllib/3.6)
2019-01-31 14:33:28 regiond: [info] 127.0.0.1 POST /MAAS/metadata/2012-03-01/ HTTP/1.1 --> 200 OK (referrer: -; agent: Python-urllib/3.6)
2019-01-31 14:33:28 regiond: [info] 127.0.0.1 POST /MAAS/metadata/2012-03-01/ HTTP/1.1 --> 200 OK (referrer: -; agent: Python-urllib/3.6)
2019-01-31 14:33:28 regiond: [info] 127.0.0.1 POST /MAAS/metadata/2012-03-01/ HTTP/1.1 --> 200 OK (referrer: -; agent: Python-urllib/3.6)
2019-01-31 14:33:29 regiond: [info] 127.0.0.1 POST /MAAS/metadata/2012-03-01/ HTTP/1.1 --> 200 OK (referrer: -; agent: Python-urllib/3.6)
2019-01-31 14:33:29 regiond: [info] 127.0.0.1 POST /MAAS/metadata/2012-03-01/ HTTP/1.1 --> 200 OK (referrer: -; agent: Python-urllib/3.6)
2019-01-31 14:33:29 regiond: [info] 127.0.0.1 POST /MAAS/metadata/2012-03-01/ HTTP/1.1 --> 200 OK (referrer: -; agent: Python-urllib/3.6)
2019-01-31 14:33:29 regiond: [info] 127.0.0.1 POST /MAAS/metadata/2012-03-01/ HTTP/1.1 --> 200 OK (referrer: -; agent: Python-urllib/3.6)
2019-01-31 14:33:29 regiond: [info] 127.0.0.1 POST /MAAS/metadata/2012-03-01/ HTTP/1.1 --> 200 OK (referrer: -; agent: Python-urllib/3.6)
2019-01-31 14:33:29 regiond: [info] 127.0.0.1 POST /MAAS/metadata/2012-03-01/ HTTP/1.1 --> 200 OK (referrer: -; agent: Python-urllib/3.6)
2019-01-31 14:33:31 maasserver.region_controller: [info] Reloaded DNS configuration:
         * rack controller maas00 connected
         * rack controller maas00 disconnected
         * rack controller maas00 disconnected
         * rack controller maas00 disconnected
         * rack controller maas00 disconnected
2019-01-31 14:33:33 maasserver.dhcp: [info] Successfully configured DHCPv4 on rack controller 'maas00 (xrrxcb)'.
2019-01-31 14:33:33 maasserver.dhcp: [info] Successfully configured DHCPv6 on rack controller 'maas00 (xrrxcb)'.
2019-01-31 14:33:47 regiond: [info] 127.0.0.1 GET /MAAS/rpc/ HTTP/1.1 --> 200 OK (referrer: -; agent: provisioningserver.rpc.clusterservice.ClusterClientService)
2019-01-31 14:34:11 -: [info] b'/etc/resolv.conf' changed, reparsing
2019-01-31 14:34:11 -: [info] Resolver added ('127.0.0.53', 53) to server list
2019-01-31 14:34:17 regiond: [info] 127.0.0.1 GET /MAAS/rpc/ HTTP/1.1 --> 200 OK (referrer: -; agent: provisioningserver.rpc.clusterservice.ClusterClientService)

maas.log:

2019-01-31T14:35:11.708643+00:00 maas00 maas.service_monitor: [info] Service 'maas-dhcpd' is not off, it will be stopped.
2019-01-31T14:35:11.774008+00:00 maas00 maas.service_monitor: [info] Service 'maas-dhcpd' has been stopped and is 'dead'.
2019-01-31T14:35:14.946022+00:00 maas00 maas.refresh: [info] Refreshing rack controller hardware information.
2019-01-31T14:35:14.946039+00:00 maas00 maas.service_monitor: [info] Service 'maas-syslog' has been restarted. Its current state is 'on' and 'running'.
2019-01-31T14:35:15.846863+00:00 maas00 maas.service_monitor: [info] Service 'chrony' has been restarted. Its current state is 'on' and 'running'.
2019-01-31T14:35:17.155733+00:00 maas00 maas.bootresources: [info] Skipping periodic import of boot resources; it has been disabled.
2019-01-31T14:35:17.839974+00:00 maas00 maas.rpc.rackcontrollers: [info] Existing rack controller 'maas00' running version 2.5.1-7505-g0d6ea574e-0ubuntu1~18.04.1 has connected to region 'maas00'.
2019-01-31T14:35:19.306846+00:00 maas00 maas.rpc.rackcontrollers: message repeated 3 times: [ [info] Existing rack controller 'maas00' running
version 2.5.1-7505-g0d6ea574e-0ubuntu1~18.04.1 has connected to region 'maas00'.]
2019-01-31T14:35:27.174967+00:00 maas00 maas.service_monitor: [info] Service 'maas-dhcpd' is not on, it will be started.
2019-01-31T14:35:27.234055+00:00 maas00 maas.service_monitor: [info] Service 'maas-dhcpd' has been started and is 'running'.

Related branches

Changed in maas:
importance: Undecided → Critical
milestone: none → 2.5.1
Revision history for this message
Andres Rodriguez (andreserl) wrote :

This seems like configauth has a table that keeps the state and knows when it has been run against an RBAC. If we were to re-configure, such as in this case, it would think that it is the same rbac and no updates are send to RBAC.

It seems like any time this is run (configauth) we should be sending all the information again to rbac because, in fact, this could be a re-configuration.

Changed in maas:
status: New → Confirmed
assignee: nobody → Alberto Donato (ack)
Changed in maas:
status: Confirmed → In Progress
assignee: Alberto Donato (ack) → Blake Rouse (blake-rouse)
Changed in maas:
status: In Progress → Fix Committed
Changed in maas:
milestone: 2.5.1 → 2.6.0
Changed in maas:
milestone: 2.6.0 → 2.6.0alpha1
Changed in maas:
status: Fix Committed → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Duplicates of this bug

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.