Raises CannotConfigureDHCP when saving managedcluster interface.

[Newell Jensen]

Trunk (as of 11/24/2014) gives an "Internal server error." when trying to save a managed interface.

This was performed on a fresh MAAS installation (from packages).

Here is the relevant output from /var/log/maas/*.log:

==> /var/log/maas/maas-django.log <==
    return do_configure_dhcp(4, nodegroup, interfaces, ntp_server)
  File "/usr/lib/python2.7/dist-packages/provisioningserver/utils/twisted.py", line 148, in wrapper
    return func(*args, **kwargs)
  File "/usr/lib/python2.7/dist-packages/maasserver/dhcp.py", line 114, in do_configure_dhcp
    client(command, omapi_key=omapi_key, subnet_configs=subnets).wait(60)
  File "/usr/lib/python2.7/dist-packages/crochet/_eventloop.py", line 219, in wait
    result.raiseException()
  File "<string>", line 2, in raiseException
CannotConfigureDHCP: DHCPv4 server failed to restart: stop: Unknown instance:
start: Job failed to start

==> /var/log/maas/maas.log <==
Nov 24 13:19:23 mc maas.tftp: [WARNING] No boot images have been imported from the region.
Nov 24 13:15:21 mc maas.tftp: message repeated 2 times: [ [WARNING] No boot images have been imported from the region.]
Nov 24 13:19:42 mc maas: [WARNING] Failed to create Network when adding/editing cluster interface eth0-eth0 with error [{'ip': [u'Network with this Ip already exists.'], 'name': [u'Network with this Name already exists.']}]. This is OK if it already exists.
Nov 24 13:15:05 mc maas.tftp: [WARNING] No boot images have been imported from the region.
Nov 24 13:19:47 mc maas.calls: [INFO] Starting task 'write_full_dns_config' with args: () {'zones': [<provisioningserver.dns.zoneconfig.DNSForwardZoneConfig object at 0x7f09b808d550>, <provisioningserver.dns.zoneconfig.DNSReverseZoneConfig object at 0x7f09b808dd90>], 'callback': provisioningserver.tasks.rndc_command([u'reload'], False), 'upstream_dns': None, 'trusted_networks': u'192.168.122.0/24;'}
Nov 24 13:19:47 mc maas.calls: [INFO] Starting task 'rndc_command' with args: ([u'reload'], False) {}
Nov 24 13:19:47 mc maas.calls: [INFO] Finished task 'rndc_command' with args: ([u'reload'], False) {}
Nov 24 13:19:47 mc maas.calls: [INFO] Finished task 'write_full_dns_config' with args: () {'zones': [<provisioningserver.dns.zoneconfig.DNSForwardZoneConfig object at 0x7f09b808d550>, <provisioningserver.dns.zoneconfig.DNSReverseZoneConfig object at 0x7f09b808dd90>], 'callback': provisioningserver.tasks.rndc_command([u'reload'], False), 'upstream_dns': None, 'trusted_networks': u'192.168.122.0/24;'}
Nov 24 13:19:43 mc maas.tftp: message repeated 55 times: [ [WARNING] No boot images have been imported from the region.]
Nov 24 13:19:47 mc maas.dhcp: [ERROR] DHCPv4 server failed to restart (for network interfaces eth0): Command `sudo -n service maas-dhcpd restart` returned non-zero exit status 1:#012stop: Unknown instance: #012start: Job failed to start

==> /var/log/maas/pserv.log <==
2014-11-24 13:04:05-0800 [Uninitialized] ClusterClient connection established (HOST:IPv4Address(TCP, '127.0.0.1', 53178) PEER:IPv4Address(TCP, u'127.0.0.1', 51119))
2014-11-24 13:04:05-0800 [Uninitialized] ClusterClient connection established (HOST:IPv4Address(TCP, '127.0.0.1', 53178) PEER:IPv4Address(TCP, u'127.0.0.1', 51119))
2014-11-24 13:04:05-0800 [ClusterClient,client] Event-loop 'mc:pid=29867' authenticated.
2014-11-24 13:04:05-0800 [ClusterClient,client] Event-loop 'mc:pid=29867' authenticated.
2014-11-24 13:04:05-0800 [ClusterClient,client] Event-loop 'mc:pid=29866' authenticated.
2014-11-24 13:04:05-0800 [ClusterClient,client] Event-loop 'mc:pid=29866' authenticated.
2014-11-24 13:04:06-0800 [ClusterClient,client] Cluster '4c38247a-df7a-46ad-a696-a38d582abd34' registered (via mc:pid=29867).
2014-11-24 13:04:06-0800 [ClusterClient,client] Cluster '4c38247a-df7a-46ad-a696-a38d582abd34' registered (via mc:pid=29867).
2014-11-24 13:04:06-0800 [ClusterClient,client] Cluster '4c38247a-df7a-46ad-a696-a38d582abd34' registered (via mc:pid=29866).
2014-11-24 13:04:06-0800 [ClusterClient,client] Cluster '4c38247a-df7a-46ad-a696-a38d582abd34' registered (via mc:pid=29866).

ubuntu@mc:~$ dpkg -l '*maas*'|cat
Desired=Unknown/Install/Remove/Purge/Hold
| Status=Not/Inst/Conf-files/Unpacked/halF-conf/Half-inst/trig-aWait/Trig-pend
|/ Err?=(none)/Reinst-required (Status,Err: uppercase=bad)
||/ Name Version Architecture Description
+++-=================================-===================================-============-===============================================================================
ii maas 1.7.1+bzr3373-0ubuntu1 all MAAS server all-in-one metapackage
ii maas-cli 1.7.1+bzr3373-0ubuntu1 all MAAS command line API tool
ii maas-cluster-controller 1.7.1+bzr3373-0ubuntu1 all MAAS server cluster controller
ii maas-common 1.7.1+bzr3373-0ubuntu1 all MAAS server common files
ii maas-dhcp 1.7.1+bzr3373-0ubuntu1 all MAAS DHCP server
ii maas-dns 1.7.1+bzr3373-0ubuntu1 all MAAS DNS server
ii maas-proxy 1.7.1+bzr3373-0ubuntu1 all MAAS Caching Proxy
ii maas-region-controller 1.7.1+bzr3373-0ubuntu1 all MAAS server complete region controller
ii maas-region-controller-min 1.7.1+bzr3373-0ubuntu1 all MAAS Server minimum region controller
ii python-django-maas 1.7.1+bzr3373-0ubuntu1 all MAAS server Django web framework
ii python-maas-client 1.7.1+bzr3373-0ubuntu1 all MAAS python API client
ii python-maas-provisioningserver 1.7.1+bzr3373-0ubuntu1 all MAAS server provisioning libraries

[Andres Rodriguez (andreserl)]

Hi Newell,

Can you please verify this happens in the latest 1.7.1 which is in experimental?

Also, please provide an step by step and a sample configuration of the NIC's of your system to see if we can reproduce it.

[Christian Reis (kiko)]

See also bug 1361673

[Christian Reis (kiko)]

There is a hint in the bug report. The error message is:

  CannotConfigureDHCP: DHCPv4 server failed to restart: stop: Unknown instance:
  start: Job failed to start

The first error occurs when you attempt to stop a service which is already stopped:

  kiko@gasolinux:~/Dropbox/Download$ sudo initctl status dmesg
  dmesg stop/waiting
  kiko@gasolinux:~/Dropbox/Download$ sudo stop dmesg
  stop: Unknown instance:

What appears to have happened is that there was an error starting the DHCP server, which can happen when there is an error in the config file; here's what happens when you have a broken file:

  kiko@chorus:~$ sudo start isc-dhcp-server
  start: Job failed to start

The syslog output is invaluable in that situation:

kiko@chorus:~$ sudo tail /var/log/syslog
Feb 12 15:37:51 chorus dhcpd: key "rndc-key";
Feb 12 15:37:51 chorus dhcpd: ^
Feb 12 15:37:51 chorus dhcpd: /etc/dhcp/dhcpd.conf line 37: unknown key rndc-key
Feb 12 15:37:51 chorus dhcpd: key "rndc-key"
Feb 12 15:37:51 chorus dhcpd: ^
Feb 12 15:37:51 chorus dhcpd: /etc/dhcp/dhcpd.conf line 42: unknown key rndc-key
Feb 12 15:37:51 chorus dhcpd: key "rndc-key"
Feb 12 15:37:51 chorus dhcpd: ^
Feb 12 15:37:51 chorus dhcpd: Configuration file errors encountered -- exiting
Feb 12 15:37:51 chorus kernel: [376499.698220] init: isc-dhcp-server pre-start process (1011) terminated with status 1

I'm afraid without syslog output we can't easily help this one.

[Christian Reis (kiko)]

We had a user report a similar error on IRC, with the following error: http://pastebin.com/8FEcA2ta

[Christian Reis (kiko)]

That one is different:

Feb 10 12:07:16 vmslab-maas maas.dhcp: [ERROR] Could not rewrite DHCPv4 server configuration (for network interfaces eth1): Command `sudo -n maas-provision atomic-write --filename /etc/maas/dhcpd.conf --mode 0644` returned non-zero exit status 1:#012None

Now why would atomic_write() fail?

I'm a bit confused as to what ActionScript.__call__() is doing when an error is reported -- is error.output actually emitted anywhere?

[Raphaël Badin (rvb)]

@Newell:

Can you please have a look in upstart's log: /var/log/upstart/maas-dhcpd.log ?
Also, please attach the result of `ifconfig` and the content of /etc/maas/dhcpd.conf to this bug so that we can see if the generated DHCP config is wrong.

[Raphaël Badin (rvb)]

@Newell: is this running from within a LXC machine by any chance?

[Newell Jensen (newell-jensen)]

No this was not running within an LXC machine. This was on my host
machine. I have not been able to reproduce this with the current code. I
will need to try and re-install that specific branch and see if I can
reproduce it.

On Tue, Feb 17, 2015 at 2:03 PM, Raphaël Badin <email address hidden>
wrote:

> @Newell: is this running from within a LXC machine by any chance?
>
> --
> You received this bug notification because you are subscribed to the bug
> report.
> https://bugs.launchpad.net/bugs/1395896
>
> Title:
> Raises CannotConfigureDHCP when saving managedcluster interface.
>
> Status in MAAS:
> Triaged
>
> Bug description:
> Trunk (as of 11/24/2014) gives an "Internal server error." when trying
> to save a managed interface.
>
> This was performed on a fresh MAAS installation (from packages).
>
> Here is the relevant output from /var/log/maas/*.log:
>
> ==> /var/log/maas/maas-django.log <==
> return do_configure_dhcp(4, nodegroup, interfaces, ntp_server)
> File
> "/usr/lib/python2.7/dist-packages/provisioningserver/utils/twisted.py",
> line 148, in wrapper
> return func(*args, **kwargs)
> File "/usr/lib/python2.7/dist-packages/maasserver/dhcp.py", line 114,
> in do_configure_dhcp
> client(command, omapi_key=omapi_key, subnet_configs=subnets).wait(60)
> File "/usr/lib/python2.7/dist-packages/crochet/_eventloop.py", line
> 219, in wait
> result.raiseException()
> File "<string>", line 2, in raiseException
> CannotConfigureDHCP: DHCPv4 server failed to restart: stop: Unknown
> instance:
> start: Job failed to start
>
> ==> /var/log/maas/maas.log <==
> Nov 24 13:19:23 mc maas.tftp: [WARNING] No boot images have been
> imported from the region.
> Nov 24 13:15:21 mc maas.tftp: message repeated 2 times: [ [WARNING] No
> boot images have been imported from the region.]
> Nov 24 13:19:42 mc maas: [WARNING] Failed to create Network when
> adding/editing cluster interface eth0-eth0 with error [{'ip': [u'Network
> with this Ip already exists.'], 'name': [u'Network with this Name already
> exists.']}]. This is OK if it already exists.
> Nov 24 13:15:05 mc maas.tftp: [WARNING] No boot images have been
> imported from the region.
> Nov 24 13:19:47 mc maas.calls: [INFO] Starting task
> 'write_full_dns_config' with args: () {'zones':
> [<provisioningserver.dns.zoneconfig.DNSForwardZoneConfig object at
> 0x7f09b808d550>, <provisioningserver.dns.zoneconfig.DNSReverseZoneConfig
> object at 0x7f09b808dd90>], 'callback':
> provisioningserver.tasks.rndc_command([u'reload'], False), 'upstream_dns':
> None, 'trusted_networks': u'192.168.122.0/24;'}
> Nov 24 13:19:47 mc maas.calls: [INFO] Starting task 'rndc_command' with
> args: ([u'reload'], False) {}
> Nov 24 13:19:47 mc maas.calls: [INFO] Finished task 'rndc_command' with
> args: ([u'reload'], False) {}
> Nov 24 13:19:47 mc maas.calls: [INFO] Finished task
> 'write_full_dns_config' with args: () {'zones':
> [<provisioningserver.dns.zoneconfig.DNSForwardZoneConfig object at
> 0x7f09b808d550>, <provisioningserver.dns.zoneconfig.DNSReverseZoneConfig
> object at 0x7f09b808dd90>], 'callback':
> provisioningserver.tasks.rndc_command(...

[Andres Rodriguez (andreserl)]

Hi Newell,

I';m marking this as incomplete as we have not been able to reproduce. If you can confirm it is still present it can be marked back as new.

[mahmoh (mahmoh)]

I can reproduce I believe:

$ Jun 17 12:25:22 maas maas.calls: [INFO] Starting task 'write_full_dns_config' with args: () {'zones': [<provisioningserver.dns.zoneconfig.DNSForwardZoneConfig object at 0x7f7e90c10dd0>, <provisioningserver.dns.zoneconfig.DNSReverseZoneConfig object at 0x7f7e92521d90>], 'callback': provisioningserver.tasks.rndc_command([u'reload'], False), 'upstream_dns': u'8.8.8.8', 'trusted_networks': u'192.168.2.0/24;'}
Jun 17 12:25:22 maas maas.calls: [INFO] Starting task 'rndc_command' with args: ([u'reload'], False) {}
Jun 17 12:25:22 maas maas.tasks: [ERROR] rndc_command failed: Command `rndc -c /etc/bind/maas/rndc.conf.maas reload` returned non-zero exit status 1:#012rndc: connection to remote host closed#012This may indicate that#012* the remote server is using an older version of the command protocol,#012* this host is not authorized to connect,#012* the clocks are not synchronized, or#012* the key is invalid.
Jun 17 12:25:22 maas maas.tasks: [ERROR] rndc_command: Command `rndc -c /etc/bind/maas/rndc.conf.maas reload` returned non-zero exit status 1:#012rndc: connection to remote host closed#012This may indicate that#012* the remote server is using an older version of the command protocol,#012* this host is not authorized to connect,#012* the clocks are not synchronized, or#012* the key is invalid.
Jun 17 12:25:22 maas maas.tasks: [ERROR] write_full_dns_config: Command `rndc -c /etc/bind/maas/rndc.conf.maas reload` returned non-zero exit status 1:#012rndc: connection to remote host closed#012This may indicate that#012* the remote server is using an older version of the command protocol,#012* this host is not authorized to connect,#012* the clocks are not synchronized, or#012* the key is invalid.
ERROR 2015-06-17 12:25:22,493 django.request Internal Server Error: /MAAS/clusters/6e051520-ed1c-4d2a-a1df-7ea93a35e175/interfaces/eth0/edit/
Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/django/core/handlers/base.py", line 112, in get_response
    response = wrapped_callback(request, *callback_args, **callback_kwargs)
  File "/usr/lib/python2.7/dist-packages/django/contrib/auth/decorators.py", line 22, in _wrapped_view
    return view_func(request, *args, **kwargs)
  File "/usr/lib/python2.7/dist-packages/django/views/generic/base.py", line 69, in view
    return self.dispatch(request, *args, **kwargs)
  File "/usr/lib/python2.7/dist-packages/django/views/generic/base.py", line 87, in dispatch
    return handler(request, *args, **kwargs)
  File "/usr/lib/python2.7/dist-packages/django/views/generic/edit.py", line 228, in post
    return super(BaseUpdateView, self).post(request, *args, **kwargs)
  File "/usr/lib/python2.7/dist-packages/django/views/generic/edit.py", line 171, in post
    return self.form_valid(form)
  File "/usr/lib/python2.7/dist-packages/maasserver/views/clusters.py", line 224, in form_valid
    return super(ClusterInterfaceEdit, self).form_valid(form)
  File "/usr/lib/python2.7/dist-packages/django/views/generic/edit.py", line 147, in form_valid
    self.object = form.save()
  File "/usr/lib/python2.7/dist-packages/maasserver/forms.py", line 1510, in save
    interface = super(Nod...

[mahmoh (mahmoh)]

^, I can reproduce this on both 1.7 & 1.8:

$ dpkg -l | grep maas
ii maas 1.7.5+bzr3369-0ubuntu1~trusty1 all MAAS server all-in-one metapackage
ii maas-cli 1.7.5+bzr3369-0ubuntu1~trusty1 all MAAS command line API tool
ii maas-cluster-controller 1.7.5+bzr3369-0ubuntu1~trusty1 all MAAS server cluster controller
ii maas-common 1.7.5+bzr3369-0ubuntu1~trusty1 all MAAS server common files
ii maas-dhcp 1.7.5+bzr3369-0ubuntu1~trusty1 all MAAS DHCP server
ii maas-dns 1.7.5+bzr3369-0ubuntu1~trusty1 all MAAS DNS server
ii maas-proxy 1.7.5+bzr3369-0ubuntu1~trusty1 all MAAS Caching Proxy
ii maas-region-controller 1.7.5+bzr3369-0ubuntu1~trusty1 all MAAS server complete region controller
ii maas-region-controller-min 1.7.5+bzr3369-0ubuntu1~trusty1 all MAAS Server minimum region controller
ii python-django-maas 1.7.5+bzr3369-0ubuntu1~trusty1 all MAAS server Django web framework
ii python-maas-client 1.7.5+bzr3369-0ubuntu1~trusty1 all MAAS python API client
ii python-maas-provisioningserver 1.7.5+bzr3369-0ubuntu1~trusty1 all MAAS server provisioning libraries

[mahmoh (mahmoh)]

$ Jun 17 12:54:06 maas maas.tftp: [WARNING] No boot images have been imported from the region.
Jun 17 12:55:51 maas maas.bootsources: [INFO] Updated boot sources cache.
Jun 17 12:55:51 maas maas.bootresources: [INFO] Started importing of boot images from 1 source(s).
Jun 17 12:55:53 maas maas.bootresources: [INFO] Importing images from source: http://maas.ubuntu.com/images/ephemeral-v2/releases/
Jun 17 12:56:58 maas maas: [WARNING] Failed to create Network when adding/editing cluster interface maas-p4p1 with error [{'ip': [u'Network with this Ip already exists.'], 'name': [u'Network with this Name already exists.']}]. This is OK if it already exists.
Jun 17 12:56:58 maas maas.dns: [ERROR] Reloading BIND failed: Command `rndc -c /etc/bind/maas/rndc.conf.maas reload` returned non-zero exit status 1:#012rndc: recv failed: connection reset
Jun 17 12:57:07 maas maas: [WARNING] Failed to create Network when adding/editing cluster interface maas-p4p1 with error [{'ip': [u'Network with this Ip already exists.'], 'name': [u'Network with this Name already exists.']}]. This is OK if it already exists.
Jun 17 12:57:07 maas maas.dns: [ERROR] Reloading BIND failed: Command `rndc -c /etc/bind/maas/rndc.conf.maas reload` returned non-zero exit status 1:#012rndc: connection to remote host closed#012This may indicate that#012* the remote server is using an older version of the command protocol,#012* this host is not authorized to connect,#012* the clocks are not synchronized, or#012* the key is invalid.
Jun 17 12:57:13 maas maas.bootresources: [INFO] Finished importing of boot images from 1 source(s).
Jun 17 12:57:13 maas maas.import-images: [INFO] Started importing boot images.
tail -f regiond.log
 * the key is invalid.

2015-06-17 12:57:07 [-] 192.168.2.1 - - [17/Jun/2015:16:57:06 +0000] "POST /MAAS/clusters/23fdb518-197e-4116-8c41-98c56e6c6899/interfaces/p4p1/edit/ HTTP/1.1" 500 332 "http://192.168.2.1/MAAS/clusters/23fdb518-197e-4116-8c41-98c56e6c6899/interfaces/p4p1/edit/" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:38.0) Gecko/20100101 Firefox/38.0"
2015-06-17 12:57:13 [RegionServer,0,192.168.2.1] {}
2015-06-17 12:57:13 [-] 192.168.2.1 - - [17/Jun/2015:16:57:12 +0000] "GET /MAAS/images-stream/streams/v1/index.json HTTP/1.1" 200 347 "-" "Python-urllib/2.7"
2015-06-17 12:57:13 [-] 192.168.2.1 - - [17/Jun/2015:16:57:13 +0000] "GET /MAAS/images-stream/streams/v1/maas:v2:download.json HTTP/1.1" 200 1888 "-" "Python-urllib/2.7"
2015-06-17 12:57:13 [-] 192.168.2.1 - - [17/Jun/2015:16:57:13 +0000] "GET /MAAS/images-stream/streams/v1/index.json HTTP/1.1" 200 347 "-" "Python-urllib/2.7"
2015-06-17 12:57:14 [-] 192.168.2.1 - - [17/Jun/2015:16:57:13 +0000] "GET /MAAS/images-stream/streams/v1/maas:v2:download.json HTTP/1.1" 200 1888 "-" "Python-urllib/2.7"
2015-06-17 12:57:22 [-] 192.168.2.1 - - [17/Jun/2015:16:57:21 +0000] "GET /MAAS/images-stream/ubuntu/amd64/hwe-t/trusty/20140904/root-image.gz HTTP/1.1" 200 341135891 "-" "Python-urllib/2.7"
2015-06-17 12:57:31 [-] 192.168.2.1 - - [17/Jun/2015:16:57:30 +0000] "GET /MAAS/rpc/ HTTP/1.1" 200 364 "-" "provisioningserver.rpc.clusterservice.ClusterClientService"

2015-06-17 12:58:01 [-] 192.168.2.1 - - [17/Jun/2015:16:5...

[Blake Rouse (blake-rouse)]

I beleive this has been fixed for a while.