If a Node is released while the DHCP server is down, its IP address remains reserved.

[Mike Pontillo]

Seen in regiond.log:

2015-08-13 09:40:15 [-] Unhandled error in Deferred:
2015-08-13 09:40:15 [-] Unhandled Error
    Traceback (most recent call last):
    Failure: provisioningserver.rpc.exceptions.CannotRemoveHostMap: DHCPv4 server is disabled.

This could happen if the DHCPv4 service is down, or otherwise cannot be reached (via omshell) to release the IP address.

In this case, the Node is successfully released, but its "AUTO-type" StaticIPAddress remains in the table.

This was seen on an LXC where its host OS did not have an updated AppArmor profile (via the maas-dhcp package).

This defect could possibly be reproduced by doing a "chmod -x /usr/bin/omshell".

This was seen on 1.9, but we need to check if it affects 1.8 as well.

[Blake Rouse (blake-rouse)]

Are we sure this is the case? If the DHCP server is down and it should be on it will be turned on before using the omshell. What your describing is just a misconfigured machine with the omshell tool has invalid permissions. Now if the DHCP server is disabled and then the node is released it will cause an issue. Is that what this bug is trying to describe?

[Ricardo Bánffy (rbanffy)]

Using the chmod hack, your traceback will look like this:

==> /var/log/maas/clusterd.log <==
2015-10-15 17:28:43-0400 [-] Unhandled failure dispatching AMP command. This is probably a bug. Please ensure that this error is handled within application code or declared in the signature of the RemoveHostMaps command. [maas-trusty-testbench:pid=639:cmd=RemoveHostMaps:ask=7]
 Traceback (most recent call last):
   File "/usr/lib/python2.7/threading.py", line 783, in __bootstrap
     self.__bootstrap_inner()
   File "/usr/lib/python2.7/threading.py", line 810, in __bootstrap_inner
     self.run()
   File "/usr/lib/python2.7/threading.py", line 763, in run
     self.__target(*self.__args, **self.__kwargs)
 --- <exception caught here> ---
   File "/usr/lib/python2.7/dist-packages/twisted/python/threadpool.py", line 191, in _worker
     result = context.call(ctx, function, *args, **kwargs)
   File "/usr/lib/python2.7/dist-packages/twisted/python/context.py", line 118, in callWithContext
     return self.currentContext().callWithContext(ctx, func, *args, **kw)
   File "/usr/lib/python2.7/dist-packages/twisted/python/context.py", line 81, in callWithContext
     return func(*args,**kw)
   File "/usr/lib/python2.7/dist-packages/provisioningserver/utils/twisted.py", line 200, in wrapper
     return func(*args, **kwargs)
   File "/usr/lib/python2.7/dist-packages/provisioningserver/rpc/dhcp.py", line 224, in remove_host_maps
     omshell.remove(mac_address)
   File "/usr/lib/python2.7/dist-packages/provisioningserver/dhcp/omshell.py", line 225, in remove
     returncode, output = self._run(stdin)
   File "/usr/lib/python2.7/dist-packages/provisioningserver/dhcp/omshell.py", line 133, in _run
     proc = Popen(self.command, stdin=PIPE, stdout=PIPE)
   File "/usr/lib/python2.7/subprocess.py", line 710, in __init__
     errread, errwrite)
   File "/usr/lib/python2.7/subprocess.py", line 1327, in _execute_child
     raise child_exception
 exceptions.OSError: [Errno 13] Permission denied

Most likely, while experimenting a real failure, you'll see a different exception, but on the same line.

[Ricardo Bánffy (rbanffy)]

Other attempts to replicate the issue, by forcing a MAAS DHCP failure to start (moving the /var/lib/maas/dhcpd.conf file) we'll have a log output similar to this:

==> /var/log/maas/maas.log <==
Oct 16 20:38:50 maas-1484698 maas.node: [INFO] meaty-ball: Releasing node
Oct 16 20:38:50 maas-1484698 maas.node: [INFO] meaty-ball: Status transition from DEPLOYED to RELEASING
Oct 16 20:38:51 maas-1484698 maas.power: [INFO] Changing power state (off) of node: meaty-ball (node-958b88a4-73f7-11e5-bbc4-525400111c6c)
Oct 16 20:38:56 maas-1484698 maas.node: [INFO] meaty-ball: Status transition from RELEASING to READY
Oct 16 20:38:56 maas-1484698 maas.power: [INFO] Changed power state (off) of node: meaty-ball (node-958b88a4-73f7-11e5-bbc4-525400111c6c)
Oct 16 20:38:57 maas-1484698 maas.service_monitor: [INFO] Service 'maas-dhcpd' is not on, it will be started.
Oct 16 20:38:57 maas-1484698 maas.service_monitor: [ERROR] Service 'maas-dhcpd' failed to start. Its current state is 'off' and 'dead'.

[Ricardo Bánffy (rbanffy)]

... and this in regiond.log:

==> /var/log/maas/regiond.log <==
2015-10-16 20:38:57 [-] Unhandled error in Deferred:
2015-10-16 20:38:57 [-] Unhandled Error
 Traceback (most recent call last):
 Failure: provisioningserver.rpc.exceptions.CannotRemoveHostMap: DHCPv4 server failed to start: Service 'maas-dhcpd' failed to start. Its current state is 'off' and 'dead'.

[Andres Rodriguez (andreserl)]

Marking this bug as won't fix provided that this was fixed in MAAS 2.0 by completely re-designing how MAAS manages DHCP.

This cannot be fixed in 1.9 exactly due to the way how MAAS managed DHCP in 1.x, and the reason for re-design in 2.0 came from this and other issues.