Ask Your Question

Revision history [back]

click to hide/show revision 1
initial version

asked 2015-03-17 17:20:42 -0600

jcope gravatar image

nova boot creates instance in error state: network bridge isn't created

This is my first go at Openstack. I'm following steps 1 - 7 here: http://docs.openstack.org/juno/install-guide/install/yum/content/launch-instance-nova.html

General:

  • RHEL 7.0
  • Juno
  • LEGACY Networking (Nova)
  • 8 compute nodes / 1 controller
  • NetworkManger off / disabled
  • iptables off / disabled
  • 1 network interface per node ( bond0 )

Issue: Every time I create an instance with nova boot, the result is a server with state: ERROR. Combing through the logs, nova-conductor.log has an error line that mentions "Cannot get interface MTU on 'br100': No such device". Looking at the node that the instance was created on, there is no bridge interface. The guide doesn't mention anything about manually creating the bridge.

My understanding is that it's meant to be done automatically at the moment the instance is created. Is that true? And if so, I'd appreciate any help diagnosing the cause.

Sorry in advance for the wall of text. I tried to make it as readable as I could.

Following http://docs.openstack.org/juno/install-guide/install/yum/content/launch-instance-nova.html , I run 

# nova boot --flavor m1.tiny --image cirros-0.3.3-x86_64 --nic net-id=8fed6262-d5d5-497d-996b-2c26922fcbcf  --security-group default --key-name demo-key demo-instance1

--------------------------------------------------------------------------------------------
| Property                             | Value
| OS-DCF:diskConfig                    | MANUAL
| OS-EXT-AZ:availability_zone          | nova
| OS-EXT-STS:power_state               | 0
| OS-EXT-STS:task_state                | scheduling
| OS-EXT-STS:vm_state                  | building
| OS-SRV-USG:launched_at               | - 
| OS-SRV-USG:terminated_at             | - 
| accessIPv4                           |           
| accessIPv6                           |            
| adminPass                            | w4zcTWdi69J8
| config_drive                         |               
| created                              | 2015-03-17T20:51:17Z
| flavor                               | m1.tiny (1)
| hostId                               |                
| id                                   | c87f8800-63c5-47fd-96c3-8d37dceba955     
| image                                | cirros-0.3.3-x86_64 (2d70875d-d07c-413c-8a6e-d521b21ac192)
| key_name                             | demo-key
| metadata                             | {}        
| name                                 | demo-instance1  
| os-extended-volumes:volumes_attached | []               
| progress                             | 0      
| security_groups                      | default         
| status                               | BUILD         
| tenant_id                            | 1cb52dc33f8142c69590b16bd6fa53d2
| updated                              | 2015-03-17T20:51:17Z     
| user_id                              | 3a6e30e6d1334f499ff13e00b65859a5
-------------------------------------------------------------------------------------------------

[root@controller ~]# nova list
| ID              | Name           | Status | Task State | Power State | Networks
| c87f8800-63c5-47fd-96c3-8d37dceba955 | demo-instance1 | ERROR  | -    | NOSTATE     | demo-net=10.1.7.2

From controller /var/log/nova/nova-conductor.log

2015-03-17 20:51:17.420 26007 INFO oslo.messaging._drivers.impl_rabbit [req-b3441565-61df-4c9c-ba79-71093f4b3d31 ] Connecting to AMQP server on localhost:5672

2015-03-17 20:51:17.446 26007 INFO oslo.messaging._drivers.impl_rabbit [req-b3441565-61df-4c9c-ba79-71093f4b3d31 ] Connected to AMQP server on localhost:5672

2015-03-17 20:51:36.891 26001 ERROR nova.scheduler.utils [req-b3441565-61df-4c9c-ba79-71093f4b3d31 None] [instance: c87f8800-63c5-47fd-96c3-8d37dceba955] Error from last host: compute2.osp (node compute2.osp): [u'Traceback (most recent call last):\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2033, in _do_build_and_run_instance\n    filter_properties)\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2164, in _build_and_run_instance\n    instance_uuid=instance.uuid, reason=six.text_type(e))\n', u"RescheduledException: Build of instance c87f8800-63c5-47fd-96c3-8d37dceba955 was re-scheduled: internal error: referenced filter 'no-mac-spoofing' is missing\n"]

2015-03-17 20:51:36.897 26001 INFO oslo.messaging._drivers.impl_rabbit [req-b3441565-61df-4c9c-ba79-71093f4b3d31 ] Connecting to AMQP server on localhost:5672

2015-03-17 20:51:36.922 26001 INFO oslo.messaging._drivers.impl_rabbit [req-b3441565-61df-4c9c-ba79-71093f4b3d31 ] Connected to AMQP server on localhost:5672

2015-03-17 20:51:43.437 26001 ERROR nova.scheduler.utils [req-b3441565-61df-4c9c-ba79-71093f4b3d31 None] [instance: c87f8800-63c5-47fd-96c3-8d37dceba955] Error from last host: compute3.osp (node compute3.osp): [u'Traceback (most recent call last):\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2033, in _do_build_and_run_instance\n    filter_properties)\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2164, in _build_and_run_instance\n    instance_uuid=instance.uuid, reason=six.text_type(e))\n', u"RescheduledException: Build of instance c87f8800-63c5-47fd-96c3-8d37dceba955 was re-scheduled: Cannot get interface MTU on 'br100': No such device\n"]

2015-03-17 20:51:48.958 25987 ERROR nova.scheduler.utils [req-b3441565-61df-4c9c-ba79-71093f4b3d31 None] [instance: c87f8800-63c5-47fd-96c3-8d37dceba955] Error from last host: compute5.osp (node compute5.osp): [u'Traceback (most recent call last):\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2033, in _do_build_and_run_instance\n    filter_properties)\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2164, in _build_and_run_instance\n    instance_uuid=instance.uuid, reason=six.text_type(e))\n', u"RescheduledException: Build of instance c87f8800-63c5-47fd-96c3-8d37dceba955 was re-scheduled: Cannot get interface MTU on 'br100': No such device\n"]

2015-03-17 20:51:48.960 25987 WARNING nova.scheduler.driver [req-b3441565-61df-4c9c-ba79-71093f4b3d31 None] [instance: c87f8800-63c5-47fd-96c3-8d37dceba955] NoValidHost exception with message: 'No valid host was found. Exceeded max scheduling attempts 3 for instance c87f8800-63c5-47fd-96c3-8d37dceba955. Last exception: [u'Traceback (most recent call last):\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2033, in _do_build_and_run_instance\n    filter_properties)\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2164, in _build_and_run_instance\n    instance_uuid=instance.uuid, reason=six.text_type(e))\n', u"RescheduledException: Build of instance c87f8800-63c5-47fd-96c3-8d37dceba955 was re-scheduled: Cannot get interface MTU on 'br100': No such device\n"]'

2015-03-17 20:51:48.960 25987 WARNING nova.scheduler.driver [req-b3441565-61df-4c9c-ba79-71093f4b3d31 None] [instance: c87f8800-63c5-47fd-96c3-8d37dceba955] Setting instance to ERROR state.

And from compute5:/var/log/nova/nova-network.log:

Command: sudo nova-rootwrap /etc/nova/rootwrap.conf env CONFIG_FILE=["/usr/share/nova/nova-dist.conf", "/etc/nova/nova.conf"] NETWORK_ID=3 dnsmasq --strict-order --bind-interfaces --conf-file= --pid-file=/var/lib/nova/networks/nova-br100.pid --dhcp-optsfile=/var/lib/nova/networks/nova-br100.opts --listen-address=10.1.7.1 --except-interface=lo --dhcp-range=set:demo-net2,10.1.7.2,static,255.255.255.0,86400s --dhcp-lease-max=256 --dhcp-hostsfile=/var/lib/nova/networks/nova-br100.conf --dhcp-script=/usr/bin/nova-dhcpbridge --no-hosts --leasefile-ro --domain=novalocal --addn-hosts=/var/lib/nova/networks/nova-br100.hosts
Exit code: 2
Stdout: u''
Stderr: u'\ndnsmasq: failed to create listening socket for 10.1.7.1: Cannot assign requested address\n'
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher Traceback (most recent call last):
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 134, in _dispatch_and_reply

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     incoming.message))

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-      packages/oslo/messaging/rpc/dispatcher.py", line 177, in _dispatch

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     return self._do_dispatch(endpoint, method, ctxt, args)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 123, in _do_dispatch

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     result = getattr(endpoint, method)(ctxt, **new_args)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/network/manager.py", line 222, in deallocate_fixed_ip

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     address, instance=instance)

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-
packages/nova/network/manager.py", line 1033, in deallocate_fixed_ip

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     self._teardown_network_on_host(context, network)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/network/manager.py", line 1837, in _teardown_network_on_host

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     self.driver.update_dhcp(elevated, dev, network)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/network/linux_net.py", line 1012, in update_dhcp

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     restart_dhcp(context, dev, network_ref, fixedips)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/openstack/common/lockutils.py", line 272, in inner

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     return f(*args, **kwargs)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/network/linux_net.py", line 1127, in restart_dhcp

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     _execute(*cmd, run_as_root=True)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/network/linux_net.py", line 1228, in _execute

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     return utils.execute(*cmd, **kwargs)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/utils.py", line 163, in execute
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     return processutils.execute(*cmd, **kwargs)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/openstack/common/processutils.py", line 203, in execute

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     cmd=sanitized_cmd)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher ProcessExecutionError: Unexpected error while running command.
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher Command: sudo nova-rootwrap /etc/nova/rootwrap.conf env CONFIG_FILE=["/usr/share/nova/nova-dist.conf", "/etc/nova/nova.conf"] NETWORK_ID=3 dnsmasq --strict-order --bind-interfaces --conf-file= --pid-file=/var/lib/nova/networks/nova-br100.pid --dhcp-optsfile=/var/lib/nova/networks/nova-br100.opts --listen-address=10.1.7.1 --except-interface=lo --dhcp-range=set:demo-net2,10.1.7.2,static,255.255.255.0,86400s --dhcp-lease-max=256 --dhcp-hostsfile=/var/lib/nova/networks/nova-br100.conf --dhcp-script=/usr/bin/nova-dhcpbridge --no-hosts --leasefile-ro --domain=novalocal --addn-hosts=/var/lib/nova/networks/nova-br100.hosts
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher Exit code: 2
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher Stdout: u''
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher Stderr: u'\ndnsmasq: failed to create listening socket for 10.1.7.1: Cannot assign requested address\n'
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher
2015-03-17 20:21:29.762 12661 ERROR oslo.messaging._drivers.common [req-a39517b6-2f21-4afb-8189-94381c553bf7 ] Returning exception Unexpected error while running command.
Command: sudo nova-rootwrap /etc/nova/rootwrap.conf env CONFIG_FILE=["/usr/share/nova/nova-dist.conf", "/etc/nova/nova.conf"] NETWORK_ID=3 dnsmasq --strict-order --bind-interfaces --conf-file= --pid-file=/var/lib/nova/networks/nova-br100.pid --dhcp-optsfile=/var/lib/nova/networks/nova-br100.opts --listen-address=10.1.7.1 --except-interface=lo --dhcp-range=set:demo-net2,10.1.7.2,static,255.255.255.0,86400s --dhcp-lease-max=256 --dhcp-hostsfile=/var/lib/nova/networks/nova-br100.conf --dhcp-script=/usr/bin/nova-dhcpbridge --no-hosts --leasefile-ro --domain=novalocal --addn-hosts=/var/lib/nova/networks/nova-br100.hosts
Exit code: 2
Stdout: u''
Stderr: u'\ndnsmasq: failed to create listening socket for 10.1.7.1: Cannot assign requested address\n' to caller

nova boot creates instance in error state: network bridge isn't created

This is my first go at Openstack. I'm following steps 1 - 7 here: http://docs.openstack.org/juno/install-guide/install/yum/content/launch-instance-nova.html

General:

  • RHEL 7.0
  • Juno
  • LEGACY Networking (Nova)
  • 8 compute nodes / 1 controller
  • NetworkManger off / disabled
  • iptables off / disabled
  • 1 network interface per node ( bond0 )

Issue: Every time I create an instance with nova boot, the result is a server with state: ERROR. Combing through the logs, nova-conductor.log has an error line that mentions "Cannot get interface MTU on 'br100': No such device". Looking at the node that the instance was created on, there is no bridge interface. The guide doesn't mention anything about manually creating the bridge.

My understanding is that it's meant to be done automatically at the moment the instance is created. Is that true? And if so, I'd appreciate any help diagnosing the cause.

Sorry in advance for the wall of text. I tried to make it as readable as I could.

Following http://docs.openstack.org/juno/install-guide/install/yum/content/launch-instance-nova.html , I run 

# nova boot --flavor m1.tiny --image cirros-0.3.3-x86_64 --nic net-id=8fed6262-d5d5-497d-996b-2c26922fcbcf  --security-group default --key-name demo-key demo-instance1

--------------------------------------------------------------------------------------------
| Property                             | Value
| OS-DCF:diskConfig                    | MANUAL
| OS-EXT-AZ:availability_zone          | nova
| OS-EXT-STS:power_state               | 0
| OS-EXT-STS:task_state                | scheduling
| OS-EXT-STS:vm_state                  | building
| OS-SRV-USG:launched_at               | - 
| OS-SRV-USG:terminated_at             | - 
| accessIPv4                           |           
| accessIPv6                           |            
| adminPass                            | w4zcTWdi69J8
| config_drive                         |               
| created                              | 2015-03-17T20:51:17Z
| flavor                               | m1.tiny (1)
| hostId                               |                
| id                                   | c87f8800-63c5-47fd-96c3-8d37dceba955     
| image                                | cirros-0.3.3-x86_64 (2d70875d-d07c-413c-8a6e-d521b21ac192)
| key_name                             | demo-key
| metadata                             | {}        
| name                                 | demo-instance1  
| os-extended-volumes:volumes_attached | []               
| progress                             | 0      
| security_groups                      | default         
| status                               | BUILD         
| tenant_id                            | 1cb52dc33f8142c69590b16bd6fa53d2
| updated                              | 2015-03-17T20:51:17Z     
| user_id                              | 3a6e30e6d1334f499ff13e00b65859a5
-------------------------------------------------------------------------------------------------

[root@controller ~]# nova list
| ID              | Name           | Status | Task State | Power State | Networks
| c87f8800-63c5-47fd-96c3-8d37dceba955 | demo-instance1 | ERROR  | -    | NOSTATE     | demo-net=10.1.7.2

From controller /var/log/nova/nova-conductor.log

2015-03-17 20:51:17.420 26007 INFO oslo.messaging._drivers.impl_rabbit [req-b3441565-61df-4c9c-ba79-71093f4b3d31 ] Connecting to AMQP server on localhost:5672

2015-03-17 20:51:17.446 26007 INFO oslo.messaging._drivers.impl_rabbit [req-b3441565-61df-4c9c-ba79-71093f4b3d31 ] Connected to AMQP server on localhost:5672

2015-03-17 20:51:36.891 26001 ERROR nova.scheduler.utils [req-b3441565-61df-4c9c-ba79-71093f4b3d31 None] [instance: c87f8800-63c5-47fd-96c3-8d37dceba955] Error from last host: compute2.osp (node compute2.osp): [u'Traceback (most recent call last):\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2033, in _do_build_and_run_instance\n    filter_properties)\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2164, in _build_and_run_instance\n    instance_uuid=instance.uuid, reason=six.text_type(e))\n', u"RescheduledException: Build of instance c87f8800-63c5-47fd-96c3-8d37dceba955 was re-scheduled: internal error: referenced filter 'no-mac-spoofing' is missing\n"]

2015-03-17 20:51:36.897 26001 INFO oslo.messaging._drivers.impl_rabbit [req-b3441565-61df-4c9c-ba79-71093f4b3d31 ] Connecting to AMQP server on localhost:5672

2015-03-17 20:51:36.922 26001 INFO oslo.messaging._drivers.impl_rabbit [req-b3441565-61df-4c9c-ba79-71093f4b3d31 ] Connected to AMQP server on localhost:5672

2015-03-17 20:51:43.437 26001 ERROR nova.scheduler.utils [req-b3441565-61df-4c9c-ba79-71093f4b3d31 None] [instance: c87f8800-63c5-47fd-96c3-8d37dceba955] Error from last host: compute3.osp (node compute3.osp): [u'Traceback (most recent call last):\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2033, in _do_build_and_run_instance\n    filter_properties)\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2164, in _build_and_run_instance\n    instance_uuid=instance.uuid, reason=six.text_type(e))\n', u"RescheduledException: Build of instance c87f8800-63c5-47fd-96c3-8d37dceba955 was re-scheduled: Cannot get interface MTU on 'br100': No such device\n"]

2015-03-17 20:51:48.958 25987 ERROR nova.scheduler.utils [req-b3441565-61df-4c9c-ba79-71093f4b3d31 None] [instance: c87f8800-63c5-47fd-96c3-8d37dceba955] Error from last host: compute5.osp (node compute5.osp): [u'Traceback (most recent call last):\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2033, in _do_build_and_run_instance\n    filter_properties)\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2164, in _build_and_run_instance\n    instance_uuid=instance.uuid, reason=six.text_type(e))\n', u"RescheduledException: Build of instance c87f8800-63c5-47fd-96c3-8d37dceba955 was re-scheduled: Cannot get interface MTU on 'br100': No such device\n"]

2015-03-17 20:51:48.960 25987 WARNING nova.scheduler.driver [req-b3441565-61df-4c9c-ba79-71093f4b3d31 None] [instance: c87f8800-63c5-47fd-96c3-8d37dceba955] NoValidHost exception with message: 'No valid host was found. Exceeded max scheduling attempts 3 for instance c87f8800-63c5-47fd-96c3-8d37dceba955. Last exception: [u'Traceback (most recent call last):\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2033, in _do_build_and_run_instance\n    filter_properties)\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2164, in _build_and_run_instance\n    instance_uuid=instance.uuid, reason=six.text_type(e))\n', u"RescheduledException: Build of instance c87f8800-63c5-47fd-96c3-8d37dceba955 was re-scheduled: Cannot get interface MTU on 'br100': No such device\n"]'

2015-03-17 20:51:48.960 25987 WARNING nova.scheduler.driver [req-b3441565-61df-4c9c-ba79-71093f4b3d31 None] [instance: c87f8800-63c5-47fd-96c3-8d37dceba955] Setting instance to ERROR state.

And from compute5:/var/log/nova/nova-network.log:

Command: sudo nova-rootwrap /etc/nova/rootwrap.conf env CONFIG_FILE=["/usr/share/nova/nova-dist.conf", "/etc/nova/nova.conf"] NETWORK_ID=3 dnsmasq --strict-order --bind-interfaces --conf-file= --pid-file=/var/lib/nova/networks/nova-br100.pid --dhcp-optsfile=/var/lib/nova/networks/nova-br100.opts --listen-address=10.1.7.1 --except-interface=lo --dhcp-range=set:demo-net2,10.1.7.2,static,255.255.255.0,86400s --dhcp-lease-max=256 --dhcp-hostsfile=/var/lib/nova/networks/nova-br100.conf --dhcp-script=/usr/bin/nova-dhcpbridge --no-hosts --leasefile-ro --domain=novalocal --addn-hosts=/var/lib/nova/networks/nova-br100.hosts
Exit code: 2
Stdout: u''
Stderr: u'\ndnsmasq: failed to create listening socket for 10.1.7.1: Cannot assign requested address\n'
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher Traceback (most recent call last):
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 134, in _dispatch_and_reply

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     incoming.message))

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-      packages/oslo/messaging/rpc/dispatcher.py", line 177, in _dispatch

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     return self._do_dispatch(endpoint, method, ctxt, args)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 123, in _do_dispatch

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     result = getattr(endpoint, method)(ctxt, **new_args)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/network/manager.py", line 222, in deallocate_fixed_ip

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     address, instance=instance)

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-
packages/nova/network/manager.py", line 1033, in deallocate_fixed_ip

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     self._teardown_network_on_host(context, network)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/network/manager.py", line 1837, in _teardown_network_on_host

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     self.driver.update_dhcp(elevated, dev, network)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/network/linux_net.py", line 1012, in update_dhcp

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     restart_dhcp(context, dev, network_ref, fixedips)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/openstack/common/lockutils.py", line 272, in inner

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     return f(*args, **kwargs)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/network/linux_net.py", line 1127, in restart_dhcp

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     _execute(*cmd, run_as_root=True)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/network/linux_net.py", line 1228, in _execute

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     return utils.execute(*cmd, **kwargs)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/utils.py", line 163, in execute
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     return processutils.execute(*cmd, **kwargs)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/openstack/common/processutils.py", line 203, in execute

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     cmd=sanitized_cmd)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher ProcessExecutionError: Unexpected error while running command.
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher Command: sudo nova-rootwrap /etc/nova/rootwrap.conf env CONFIG_FILE=["/usr/share/nova/nova-dist.conf", "/etc/nova/nova.conf"] NETWORK_ID=3 dnsmasq --strict-order --bind-interfaces --conf-file= --pid-file=/var/lib/nova/networks/nova-br100.pid --dhcp-optsfile=/var/lib/nova/networks/nova-br100.opts --listen-address=10.1.7.1 --except-interface=lo --dhcp-range=set:demo-net2,10.1.7.2,static,255.255.255.0,86400s --dhcp-lease-max=256 --dhcp-hostsfile=/var/lib/nova/networks/nova-br100.conf --dhcp-script=/usr/bin/nova-dhcpbridge --no-hosts --leasefile-ro --domain=novalocal --addn-hosts=/var/lib/nova/networks/nova-br100.hosts
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher Exit code: 2
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher Stdout: u''
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher Stderr: u'\ndnsmasq: failed to create listening socket for 10.1.7.1: Cannot assign requested address\n'
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher
2015-03-17 20:21:29.762 12661 ERROR oslo.messaging._drivers.common [req-a39517b6-2f21-4afb-8189-94381c553bf7 ] Returning exception Unexpected error while running command.
Command: sudo nova-rootwrap /etc/nova/rootwrap.conf env CONFIG_FILE=["/usr/share/nova/nova-dist.conf", "/etc/nova/nova.conf"] NETWORK_ID=3 dnsmasq --strict-order --bind-interfaces --conf-file= --pid-file=/var/lib/nova/networks/nova-br100.pid --dhcp-optsfile=/var/lib/nova/networks/nova-br100.opts --listen-address=10.1.7.1 --except-interface=lo --dhcp-range=set:demo-net2,10.1.7.2,static,255.255.255.0,86400s --dhcp-lease-max=256 --dhcp-hostsfile=/var/lib/nova/networks/nova-br100.conf --dhcp-script=/usr/bin/nova-dhcpbridge --no-hosts --leasefile-ro --domain=novalocal --addn-hosts=/var/lib/nova/networks/nova-br100.hosts
Exit code: 2
Stdout: u''
Stderr: u'\ndnsmasq: failed to create listening socket for 10.1.7.1: Cannot assign requested address\n' to caller

nova boot creates instance in error state: network bridge isn't created

This is my first go at Openstack. I'm following steps 1 - 7 here: http://docs.openstack.org/juno/install-guide/install/yum/content/launch-instance-nova.htmlfrom openstack Juno docs

General:

  • RHEL 7.0
  • Juno
  • LEGACY Networking (Nova)
  • 8 compute nodes / 1 controller
  • NetworkManger off / disabled
  • iptables off / disabled
  • 1 network interface per node ( bond0 )

Issue: Every time I create an instance with nova boot, the result is a server with state: ERROR. Combing through the logs, nova-conductor.log has an error line that mentions "Cannot get interface MTU on 'br100': No such device". Looking at the node that the instance was created on, there is no bridge interface. The guide doesn't mention anything about manually creating the bridge.

My understanding is that it's meant to be done automatically at the moment the instance is created. Is that true? And if so, I'd appreciate any help diagnosing the cause.

Sorry in advance for the wall of text. I tried to make it as readable as I could.

Following http://docs.openstack.org/juno/install-guide/install/yum/content/launch-instance-nova.html , I run 

# nova boot --flavor m1.tiny --image cirros-0.3.3-x86_64 --nic net-id=8fed6262-d5d5-497d-996b-2c26922fcbcf  --security-group default --key-name demo-key demo-instance1

--------------------------------------------------------------------------------------------
| Property                             | Value
| OS-DCF:diskConfig                    | MANUAL
| OS-EXT-AZ:availability_zone          | nova
| OS-EXT-STS:power_state               | 0
| OS-EXT-STS:task_state                | scheduling
| OS-EXT-STS:vm_state                  | building
| OS-SRV-USG:launched_at               | - 
| OS-SRV-USG:terminated_at             | - 
| accessIPv4                           |           
| accessIPv6                           |            
| adminPass                            | w4zcTWdi69J8
| config_drive                         |               
| created                              | 2015-03-17T20:51:17Z
| flavor                               | m1.tiny (1)
| hostId                               |                
| id                                   | c87f8800-63c5-47fd-96c3-8d37dceba955     
| image                                | cirros-0.3.3-x86_64 (2d70875d-d07c-413c-8a6e-d521b21ac192)
| key_name                             | demo-key
| metadata                             | {}        
| name                                 | demo-instance1  
| os-extended-volumes:volumes_attached | []               
| progress                             | 0      
| security_groups                      | default         
| status                               | BUILD         
| tenant_id                            | 1cb52dc33f8142c69590b16bd6fa53d2
| updated                              | 2015-03-17T20:51:17Z     
| user_id                              | 3a6e30e6d1334f499ff13e00b65859a5
-------------------------------------------------------------------------------------------------

[root@controller ~]# nova list
| ID              | Name           | Status | Task State | Power State | Networks
| c87f8800-63c5-47fd-96c3-8d37dceba955 | demo-instance1 | ERROR  | -    | NOSTATE     | demo-net=10.1.7.2

From controller /var/log/nova/nova-conductor.log

2015-03-17 20:51:17.420 26007 INFO oslo.messaging._drivers.impl_rabbit [req-b3441565-61df-4c9c-ba79-71093f4b3d31 ] Connecting to AMQP server on localhost:5672

2015-03-17 20:51:17.446 26007 INFO oslo.messaging._drivers.impl_rabbit [req-b3441565-61df-4c9c-ba79-71093f4b3d31 ] Connected to AMQP server on localhost:5672

2015-03-17 20:51:36.891 26001 ERROR nova.scheduler.utils [req-b3441565-61df-4c9c-ba79-71093f4b3d31 None] [instance: c87f8800-63c5-47fd-96c3-8d37dceba955] Error from last host: compute2.osp (node compute2.osp): [u'Traceback (most recent call last):\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2033, in _do_build_and_run_instance\n    filter_properties)\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2164, in _build_and_run_instance\n    instance_uuid=instance.uuid, reason=six.text_type(e))\n', u"RescheduledException: Build of instance c87f8800-63c5-47fd-96c3-8d37dceba955 was re-scheduled: internal error: referenced filter 'no-mac-spoofing' is missing\n"]

2015-03-17 20:51:36.897 26001 INFO oslo.messaging._drivers.impl_rabbit [req-b3441565-61df-4c9c-ba79-71093f4b3d31 ] Connecting to AMQP server on localhost:5672

2015-03-17 20:51:36.922 26001 INFO oslo.messaging._drivers.impl_rabbit [req-b3441565-61df-4c9c-ba79-71093f4b3d31 ] Connected to AMQP server on localhost:5672

2015-03-17 20:51:43.437 26001 ERROR nova.scheduler.utils [req-b3441565-61df-4c9c-ba79-71093f4b3d31 None] [instance: c87f8800-63c5-47fd-96c3-8d37dceba955] Error from last host: compute3.osp (node compute3.osp): [u'Traceback (most recent call last):\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2033, in _do_build_and_run_instance\n    filter_properties)\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2164, in _build_and_run_instance\n    instance_uuid=instance.uuid, reason=six.text_type(e))\n', u"RescheduledException: Build of instance c87f8800-63c5-47fd-96c3-8d37dceba955 was re-scheduled: Cannot get interface MTU on 'br100': No such device\n"]

2015-03-17 20:51:48.958 25987 ERROR nova.scheduler.utils [req-b3441565-61df-4c9c-ba79-71093f4b3d31 None] [instance: c87f8800-63c5-47fd-96c3-8d37dceba955] Error from last host: compute5.osp (node compute5.osp): [u'Traceback (most recent call last):\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2033, in _do_build_and_run_instance\n    filter_properties)\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2164, in _build_and_run_instance\n    instance_uuid=instance.uuid, reason=six.text_type(e))\n', u"RescheduledException: Build of instance c87f8800-63c5-47fd-96c3-8d37dceba955 was re-scheduled: Cannot get interface MTU on 'br100': No such device\n"]

2015-03-17 20:51:48.960 25987 WARNING nova.scheduler.driver [req-b3441565-61df-4c9c-ba79-71093f4b3d31 None] [instance: c87f8800-63c5-47fd-96c3-8d37dceba955] NoValidHost exception with message: 'No valid host was found. Exceeded max scheduling attempts 3 for instance c87f8800-63c5-47fd-96c3-8d37dceba955. Last exception: [u'Traceback (most recent call last):\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2033, in _do_build_and_run_instance\n    filter_properties)\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2164, in _build_and_run_instance\n    instance_uuid=instance.uuid, reason=six.text_type(e))\n', u"RescheduledException: Build of instance c87f8800-63c5-47fd-96c3-8d37dceba955 was re-scheduled: Cannot get interface MTU on 'br100': No such device\n"]'

2015-03-17 20:51:48.960 25987 WARNING nova.scheduler.driver [req-b3441565-61df-4c9c-ba79-71093f4b3d31 None] [instance: c87f8800-63c5-47fd-96c3-8d37dceba955] Setting instance to ERROR state.

And from compute5:/var/log/nova/nova-network.log:

Command: sudo nova-rootwrap /etc/nova/rootwrap.conf env CONFIG_FILE=["/usr/share/nova/nova-dist.conf", "/etc/nova/nova.conf"] NETWORK_ID=3 dnsmasq --strict-order --bind-interfaces --conf-file= --pid-file=/var/lib/nova/networks/nova-br100.pid --dhcp-optsfile=/var/lib/nova/networks/nova-br100.opts --listen-address=10.1.7.1 --except-interface=lo --dhcp-range=set:demo-net2,10.1.7.2,static,255.255.255.0,86400s --dhcp-lease-max=256 --dhcp-hostsfile=/var/lib/nova/networks/nova-br100.conf --dhcp-script=/usr/bin/nova-dhcpbridge --no-hosts --leasefile-ro --domain=novalocal --addn-hosts=/var/lib/nova/networks/nova-br100.hosts
Exit code: 2
Stdout: u''
Stderr: u'\ndnsmasq: failed to create listening socket for 10.1.7.1: Cannot assign requested address\n'
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher Traceback (most recent call last):
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 134, in _dispatch_and_reply

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     incoming.message))

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-      packages/oslo/messaging/rpc/dispatcher.py", line 177, in _dispatch

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     return self._do_dispatch(endpoint, method, ctxt, args)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 123, in _do_dispatch

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     result = getattr(endpoint, method)(ctxt, **new_args)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/network/manager.py", line 222, in deallocate_fixed_ip

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     address, instance=instance)

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-
packages/nova/network/manager.py", line 1033, in deallocate_fixed_ip

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     self._teardown_network_on_host(context, network)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/network/manager.py", line 1837, in _teardown_network_on_host

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     self.driver.update_dhcp(elevated, dev, network)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/network/linux_net.py", line 1012, in update_dhcp

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     restart_dhcp(context, dev, network_ref, fixedips)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/openstack/common/lockutils.py", line 272, in inner

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     return f(*args, **kwargs)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/network/linux_net.py", line 1127, in restart_dhcp

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     _execute(*cmd, run_as_root=True)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/network/linux_net.py", line 1228, in _execute

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     return utils.execute(*cmd, **kwargs)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/utils.py", line 163, in execute
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     return processutils.execute(*cmd, **kwargs)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/openstack/common/processutils.py", line 203, in execute

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     cmd=sanitized_cmd)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher ProcessExecutionError: Unexpected error while running command.
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher Command: sudo nova-rootwrap /etc/nova/rootwrap.conf env CONFIG_FILE=["/usr/share/nova/nova-dist.conf", "/etc/nova/nova.conf"] NETWORK_ID=3 dnsmasq --strict-order --bind-interfaces --conf-file= --pid-file=/var/lib/nova/networks/nova-br100.pid --dhcp-optsfile=/var/lib/nova/networks/nova-br100.opts --listen-address=10.1.7.1 --except-interface=lo --dhcp-range=set:demo-net2,10.1.7.2,static,255.255.255.0,86400s --dhcp-lease-max=256 --dhcp-hostsfile=/var/lib/nova/networks/nova-br100.conf --dhcp-script=/usr/bin/nova-dhcpbridge --no-hosts --leasefile-ro --domain=novalocal --addn-hosts=/var/lib/nova/networks/nova-br100.hosts
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher Exit code: 2
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher Stdout: u''
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher Stderr: u'\ndnsmasq: failed to create listening socket for 10.1.7.1: Cannot assign requested address\n'
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher
2015-03-17 20:21:29.762 12661 ERROR oslo.messaging._drivers.common [req-a39517b6-2f21-4afb-8189-94381c553bf7 ] Returning exception Unexpected error while running command.
Command: sudo nova-rootwrap /etc/nova/rootwrap.conf env CONFIG_FILE=["/usr/share/nova/nova-dist.conf", "/etc/nova/nova.conf"] NETWORK_ID=3 dnsmasq --strict-order --bind-interfaces --conf-file= --pid-file=/var/lib/nova/networks/nova-br100.pid --dhcp-optsfile=/var/lib/nova/networks/nova-br100.opts --listen-address=10.1.7.1 --except-interface=lo --dhcp-range=set:demo-net2,10.1.7.2,static,255.255.255.0,86400s --dhcp-lease-max=256 --dhcp-hostsfile=/var/lib/nova/networks/nova-br100.conf --dhcp-script=/usr/bin/nova-dhcpbridge --no-hosts --leasefile-ro --domain=novalocal --addn-hosts=/var/lib/nova/networks/nova-br100.hosts
Exit code: 2
Stdout: u''
Stderr: u'\ndnsmasq: failed to create listening socket for 10.1.7.1: Cannot assign requested address\n' to caller

nova boot creates instance in error state: network bridge isn't created

This is my first go at Openstack. I'm following steps 1 - 7 from openstack Juno docshttp://docs.openstack.org/juno/install-guide/install/yum/content/launch-instance-nova.html

General:

  • RHEL 7.0
  • Juno
  • LEGACY Networking (Nova)
  • 8 compute nodes / 1 controller
  • NetworkManger off / disabled
  • iptables off / disabled
  • 1 network interface per node ( bond0 )

Issue: Every time I create an instance with nova boot, the result is a server with state: ERROR. Combing through the logs, nova-conductor.log has an error line that mentions "Cannot get interface MTU on 'br100': No such device". Looking at the node that the instance was created on, there is no bridge interface. The guide doesn't mention anything about manually creating the bridge.

My understanding is that it's meant to be done automatically at the moment the instance is created. Is that true? And if so, I'd appreciate any help diagnosing the cause.

Sorry in advance for the wall of text. I tried to make it as readable as I could.

Following http://docs.openstack.org/juno/install-guide/install/yum/content/launch-instance-nova.html , I run 

# nova boot --flavor m1.tiny --image cirros-0.3.3-x86_64 --nic net-id=8fed6262-d5d5-497d-996b-2c26922fcbcf  --security-group default --key-name demo-key demo-instance1

--------------------------------------------------------------------------------------------
| Property                             | Value
| OS-DCF:diskConfig                    | MANUAL
| OS-EXT-AZ:availability_zone          | nova
| OS-EXT-STS:power_state               | 0
| OS-EXT-STS:task_state                | scheduling
| OS-EXT-STS:vm_state                  | building
| OS-SRV-USG:launched_at               | - 
| OS-SRV-USG:terminated_at             | - 
| accessIPv4                           |           
| accessIPv6                           |            
| adminPass                            | w4zcTWdi69J8
| config_drive                         |               
| created                              | 2015-03-17T20:51:17Z
| flavor                               | m1.tiny (1)
| hostId                               |                
| id                                   | c87f8800-63c5-47fd-96c3-8d37dceba955     
| image                                | cirros-0.3.3-x86_64 (2d70875d-d07c-413c-8a6e-d521b21ac192)
| key_name                             | demo-key
| metadata                             | {}        
| name                                 | demo-instance1  
| os-extended-volumes:volumes_attached | []               
| progress                             | 0      
| security_groups                      | default         
| status                               | BUILD         
| tenant_id                            | 1cb52dc33f8142c69590b16bd6fa53d2
| updated                              | 2015-03-17T20:51:17Z     
| user_id                              | 3a6e30e6d1334f499ff13e00b65859a5
-------------------------------------------------------------------------------------------------

[root@controller ~]# nova list
| ID              | Name           | Status | Task State | Power State | Networks
| c87f8800-63c5-47fd-96c3-8d37dceba955 | demo-instance1 | ERROR  | -    | NOSTATE     | demo-net=10.1.7.2

From controller /var/log/nova/nova-conductor.log

2015-03-17 20:51:17.420 26007 INFO oslo.messaging._drivers.impl_rabbit [req-b3441565-61df-4c9c-ba79-71093f4b3d31 ] Connecting to AMQP server on localhost:5672

2015-03-17 20:51:17.446 26007 INFO oslo.messaging._drivers.impl_rabbit [req-b3441565-61df-4c9c-ba79-71093f4b3d31 ] Connected to AMQP server on localhost:5672

2015-03-17 20:51:36.891 26001 ERROR nova.scheduler.utils [req-b3441565-61df-4c9c-ba79-71093f4b3d31 None] [instance: c87f8800-63c5-47fd-96c3-8d37dceba955] Error from last host: compute2.osp (node compute2.osp): [u'Traceback (most recent call last):\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2033, in _do_build_and_run_instance\n    filter_properties)\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2164, in _build_and_run_instance\n    instance_uuid=instance.uuid, reason=six.text_type(e))\n', u"RescheduledException: Build of instance c87f8800-63c5-47fd-96c3-8d37dceba955 was re-scheduled: internal error: referenced filter 'no-mac-spoofing' is missing\n"]

2015-03-17 20:51:36.897 26001 INFO oslo.messaging._drivers.impl_rabbit [req-b3441565-61df-4c9c-ba79-71093f4b3d31 ] Connecting to AMQP server on localhost:5672

2015-03-17 20:51:36.922 26001 INFO oslo.messaging._drivers.impl_rabbit [req-b3441565-61df-4c9c-ba79-71093f4b3d31 ] Connected to AMQP server on localhost:5672

2015-03-17 20:51:43.437 26001 ERROR nova.scheduler.utils [req-b3441565-61df-4c9c-ba79-71093f4b3d31 None] [instance: c87f8800-63c5-47fd-96c3-8d37dceba955] Error from last host: compute3.osp (node compute3.osp): [u'Traceback (most recent call last):\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2033, in _do_build_and_run_instance\n    filter_properties)\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2164, in _build_and_run_instance\n    instance_uuid=instance.uuid, reason=six.text_type(e))\n', u"RescheduledException: Build of instance c87f8800-63c5-47fd-96c3-8d37dceba955 was re-scheduled: Cannot get interface MTU on 'br100': No such device\n"]

2015-03-17 20:51:48.958 25987 ERROR nova.scheduler.utils [req-b3441565-61df-4c9c-ba79-71093f4b3d31 None] [instance: c87f8800-63c5-47fd-96c3-8d37dceba955] Error from last host: compute5.osp (node compute5.osp): [u'Traceback (most recent call last):\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2033, in _do_build_and_run_instance\n    filter_properties)\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2164, in _build_and_run_instance\n    instance_uuid=instance.uuid, reason=six.text_type(e))\n', u"RescheduledException: Build of instance c87f8800-63c5-47fd-96c3-8d37dceba955 was re-scheduled: Cannot get interface MTU on 'br100': No such device\n"]

2015-03-17 20:51:48.960 25987 WARNING nova.scheduler.driver [req-b3441565-61df-4c9c-ba79-71093f4b3d31 None] [instance: c87f8800-63c5-47fd-96c3-8d37dceba955] NoValidHost exception with message: 'No valid host was found. Exceeded max scheduling attempts 3 for instance c87f8800-63c5-47fd-96c3-8d37dceba955. Last exception: [u'Traceback (most recent call last):\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2033, in _do_build_and_run_instance\n    filter_properties)\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2164, in _build_and_run_instance\n    instance_uuid=instance.uuid, reason=six.text_type(e))\n', u"RescheduledException: Build of instance c87f8800-63c5-47fd-96c3-8d37dceba955 was re-scheduled: Cannot get interface MTU on 'br100': No such device\n"]'

2015-03-17 20:51:48.960 25987 WARNING nova.scheduler.driver [req-b3441565-61df-4c9c-ba79-71093f4b3d31 None] [instance: c87f8800-63c5-47fd-96c3-8d37dceba955] Setting instance to ERROR state.

And from compute5:/var/log/nova/nova-network.log:

Command: sudo nova-rootwrap /etc/nova/rootwrap.conf env CONFIG_FILE=["/usr/share/nova/nova-dist.conf", "/etc/nova/nova.conf"] NETWORK_ID=3 dnsmasq --strict-order --bind-interfaces --conf-file= --pid-file=/var/lib/nova/networks/nova-br100.pid --dhcp-optsfile=/var/lib/nova/networks/nova-br100.opts --listen-address=10.1.7.1 --except-interface=lo --dhcp-range=set:demo-net2,10.1.7.2,static,255.255.255.0,86400s --dhcp-lease-max=256 --dhcp-hostsfile=/var/lib/nova/networks/nova-br100.conf --dhcp-script=/usr/bin/nova-dhcpbridge --no-hosts --leasefile-ro --domain=novalocal --addn-hosts=/var/lib/nova/networks/nova-br100.hosts
Exit code: 2
Stdout: u''
Stderr: u'\ndnsmasq: failed to create listening socket for 10.1.7.1: Cannot assign requested address\n'
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher Traceback (most recent call last):
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 134, in _dispatch_and_reply

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     incoming.message))

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-      packages/oslo/messaging/rpc/dispatcher.py", line 177, in _dispatch

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     return self._do_dispatch(endpoint, method, ctxt, args)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 123, in _do_dispatch

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     result = getattr(endpoint, method)(ctxt, **new_args)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/network/manager.py", line 222, in deallocate_fixed_ip

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     address, instance=instance)

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-
packages/nova/network/manager.py", line 1033, in deallocate_fixed_ip

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     self._teardown_network_on_host(context, network)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/network/manager.py", line 1837, in _teardown_network_on_host

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     self.driver.update_dhcp(elevated, dev, network)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/network/linux_net.py", line 1012, in update_dhcp

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     restart_dhcp(context, dev, network_ref, fixedips)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/openstack/common/lockutils.py", line 272, in inner

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     return f(*args, **kwargs)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/network/linux_net.py", line 1127, in restart_dhcp

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     _execute(*cmd, run_as_root=True)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/network/linux_net.py", line 1228, in _execute

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     return utils.execute(*cmd, **kwargs)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/utils.py", line 163, in execute
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     return processutils.execute(*cmd, **kwargs)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/openstack/common/processutils.py", line 203, in execute

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     cmd=sanitized_cmd)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher ProcessExecutionError: Unexpected error while running command.
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher Command: sudo nova-rootwrap /etc/nova/rootwrap.conf env CONFIG_FILE=["/usr/share/nova/nova-dist.conf", "/etc/nova/nova.conf"] NETWORK_ID=3 dnsmasq --strict-order --bind-interfaces --conf-file= --pid-file=/var/lib/nova/networks/nova-br100.pid --dhcp-optsfile=/var/lib/nova/networks/nova-br100.opts --listen-address=10.1.7.1 --except-interface=lo --dhcp-range=set:demo-net2,10.1.7.2,static,255.255.255.0,86400s --dhcp-lease-max=256 --dhcp-hostsfile=/var/lib/nova/networks/nova-br100.conf --dhcp-script=/usr/bin/nova-dhcpbridge --no-hosts --leasefile-ro --domain=novalocal --addn-hosts=/var/lib/nova/networks/nova-br100.hosts
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher Exit code: 2
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher Stdout: u''
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher Stderr: u'\ndnsmasq: failed to create listening socket for 10.1.7.1: Cannot assign requested address\n'
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher
2015-03-17 20:21:29.762 12661 ERROR oslo.messaging._drivers.common [req-a39517b6-2f21-4afb-8189-94381c553bf7 ] Returning exception Unexpected error while running command.
Command: sudo nova-rootwrap /etc/nova/rootwrap.conf env CONFIG_FILE=["/usr/share/nova/nova-dist.conf", "/etc/nova/nova.conf"] NETWORK_ID=3 dnsmasq --strict-order --bind-interfaces --conf-file= --pid-file=/var/lib/nova/networks/nova-br100.pid --dhcp-optsfile=/var/lib/nova/networks/nova-br100.opts --listen-address=10.1.7.1 --except-interface=lo --dhcp-range=set:demo-net2,10.1.7.2,static,255.255.255.0,86400s --dhcp-lease-max=256 --dhcp-hostsfile=/var/lib/nova/networks/nova-br100.conf --dhcp-script=/usr/bin/nova-dhcpbridge --no-hosts --leasefile-ro --domain=novalocal --addn-hosts=/var/lib/nova/networks/nova-br100.hosts
Exit code: 2
Stdout: u''
Stderr: u'\ndnsmasq: failed to create listening socket for 10.1.7.1: Cannot assign requested address\n' to caller

nova boot creates instance in error state: network bridge isn't created

This is my first go at Openstack. I'm following steps 1 - 7 from http://docs.openstack.org/juno/install-guide/install/yum/content/launch-instance-nova.html

General:

  • RHEL 7.0
  • Juno
  • LEGACY Networking (Nova)
  • 8 compute nodes / 1 controller
  • NetworkManger off / disabled
  • iptables off / disabled
  • 1 network interface per node ( bond0 )

Issue: Every time I create an instance with nova boot, the result is a server with state: ERROR. Combing through the logs, nova-conductor.log has an error line that mentions "Cannot get interface MTU on 'br100': No such device". Looking at the node that the instance was created on, there is no bridge interface. The guide doesn't mention anything about manually creating the bridge.

My understanding is that it's meant to be done automatically at the moment the instance is created. Is that true? And if so, I'd appreciate any help diagnosing the cause.

Sorry in advance for the wall of text. I tried to make it as readable as I could.

Following http://docs.openstack.org/juno/install-guide/install/yum/content/launch-instance-nova.html , I run 

# nova boot --flavor m1.tiny --image cirros-0.3.3-x86_64 --nic net-id=8fed6262-d5d5-497d-996b-2c26922fcbcf  --security-group default --key-name demo-key demo-instance1

--------------------------------------------------------------------------------------------
| Property                             | Value
| OS-DCF:diskConfig                    | MANUAL
| OS-EXT-AZ:availability_zone          | nova
| OS-EXT-STS:power_state               | 0
| OS-EXT-STS:task_state                | scheduling
| OS-EXT-STS:vm_state                  | building
| OS-SRV-USG:launched_at               | - 
| OS-SRV-USG:terminated_at             | - 
| accessIPv4                           |           
| accessIPv6                           |            
| adminPass                            | w4zcTWdi69J8
| config_drive                         |               
| created                              | 2015-03-17T20:51:17Z
| flavor                               | m1.tiny (1)
| hostId                               |                
| id                                   | c87f8800-63c5-47fd-96c3-8d37dceba955     
| image                                | cirros-0.3.3-x86_64 (2d70875d-d07c-413c-8a6e-d521b21ac192)
| key_name                             | demo-key
| metadata                             | {}        
| name                                 | demo-instance1  
| os-extended-volumes:volumes_attached | []               
| progress                             | 0      
| security_groups                      | default         
| status                               | BUILD         
| tenant_id                            | 1cb52dc33f8142c69590b16bd6fa53d2
| updated                              | 2015-03-17T20:51:17Z     
| user_id                              | 3a6e30e6d1334f499ff13e00b65859a5
-------------------------------------------------------------------------------------------------

[root@controller ~]# nova list
| ID              | Name           | Status | Task State | Power State | Networks
| c87f8800-63c5-47fd-96c3-8d37dceba955 | demo-instance1 | ERROR  | -    | NOSTATE     | demo-net=10.1.7.2

From controller /var/log/nova/nova-conductor.log

2015-03-17 20:51:17.420 26007 INFO oslo.messaging._drivers.impl_rabbit [req-b3441565-61df-4c9c-ba79-71093f4b3d31 ] Connecting to AMQP server on localhost:5672

2015-03-17 20:51:17.446 26007 INFO oslo.messaging._drivers.impl_rabbit [req-b3441565-61df-4c9c-ba79-71093f4b3d31 ] Connected to AMQP server on localhost:5672

2015-03-17 20:51:36.891 26001 ERROR nova.scheduler.utils [req-b3441565-61df-4c9c-ba79-71093f4b3d31 None] [instance: c87f8800-63c5-47fd-96c3-8d37dceba955] Error from last host: compute2.osp (node compute2.osp): [u'Traceback (most recent call last):\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2033, in _do_build_and_run_instance\n    filter_properties)\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2164, in _build_and_run_instance\n    instance_uuid=instance.uuid, reason=six.text_type(e))\n', u"RescheduledException: Build of instance c87f8800-63c5-47fd-96c3-8d37dceba955 was re-scheduled: internal error: referenced filter 'no-mac-spoofing' is missing\n"]

2015-03-17 20:51:36.897 26001 INFO oslo.messaging._drivers.impl_rabbit [req-b3441565-61df-4c9c-ba79-71093f4b3d31 ] Connecting to AMQP server on localhost:5672

2015-03-17 20:51:36.922 26001 INFO oslo.messaging._drivers.impl_rabbit [req-b3441565-61df-4c9c-ba79-71093f4b3d31 ] Connected to AMQP server on localhost:5672

2015-03-17 20:51:43.437 26001 ERROR nova.scheduler.utils [req-b3441565-61df-4c9c-ba79-71093f4b3d31 None] [instance: c87f8800-63c5-47fd-96c3-8d37dceba955] Error from last host: compute3.osp (node compute3.osp): [u'Traceback (most recent call last):\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2033, in _do_build_and_run_instance\n    filter_properties)\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2164, in _build_and_run_instance\n    instance_uuid=instance.uuid, reason=six.text_type(e))\n', u"RescheduledException: Build of instance c87f8800-63c5-47fd-96c3-8d37dceba955 was re-scheduled: Cannot get interface MTU on 'br100': No such device\n"]

2015-03-17 20:51:48.958 25987 ERROR nova.scheduler.utils [req-b3441565-61df-4c9c-ba79-71093f4b3d31 None] [instance: c87f8800-63c5-47fd-96c3-8d37dceba955] Error from last host: compute5.osp (node compute5.osp): [u'Traceback (most recent call last):\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2033, in _do_build_and_run_instance\n    filter_properties)\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2164, in _build_and_run_instance\n    instance_uuid=instance.uuid, reason=six.text_type(e))\n', u"RescheduledException: Build of instance c87f8800-63c5-47fd-96c3-8d37dceba955 was re-scheduled: Cannot get interface MTU on 'br100': No such device\n"]

2015-03-17 20:51:48.960 25987 WARNING nova.scheduler.driver [req-b3441565-61df-4c9c-ba79-71093f4b3d31 None] [instance: c87f8800-63c5-47fd-96c3-8d37dceba955] NoValidHost exception with message: 'No valid host was found. Exceeded max scheduling attempts 3 for instance c87f8800-63c5-47fd-96c3-8d37dceba955. Last exception: [u'Traceback (most recent call last):\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2033, in _do_build_and_run_instance\n    filter_properties)\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2164, in _build_and_run_instance\n    instance_uuid=instance.uuid, reason=six.text_type(e))\n', u"RescheduledException: Build of instance c87f8800-63c5-47fd-96c3-8d37dceba955 was re-scheduled: Cannot get interface MTU on 'br100': No such device\n"]'

2015-03-17 20:51:48.960 25987 WARNING nova.scheduler.driver [req-b3441565-61df-4c9c-ba79-71093f4b3d31 None] [instance: c87f8800-63c5-47fd-96c3-8d37dceba955] Setting instance to ERROR state.

And from compute5:/var/log/nova/nova-network.log:

Command: sudo nova-rootwrap /etc/nova/rootwrap.conf env CONFIG_FILE=["/usr/share/nova/nova-dist.conf", "/etc/nova/nova.conf"] NETWORK_ID=3 dnsmasq --strict-order --bind-interfaces --conf-file= --pid-file=/var/lib/nova/networks/nova-br100.pid --dhcp-optsfile=/var/lib/nova/networks/nova-br100.opts --listen-address=10.1.7.1 --except-interface=lo --dhcp-range=set:demo-net2,10.1.7.2,static,255.255.255.0,86400s --dhcp-lease-max=256 --dhcp-hostsfile=/var/lib/nova/networks/nova-br100.conf --dhcp-script=/usr/bin/nova-dhcpbridge --no-hosts --leasefile-ro --domain=novalocal --addn-hosts=/var/lib/nova/networks/nova-br100.hosts
Exit code: 2
Stdout: u''
Stderr: u'\ndnsmasq: failed to create listening socket for 10.1.7.1: Cannot assign requested address\n'
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher Traceback (most recent call last):
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 134, in _dispatch_and_reply

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     incoming.message))

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-      packages/oslo/messaging/rpc/dispatcher.py", line 177, in _dispatch

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     return self._do_dispatch(endpoint, method, ctxt, args)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 123, in _do_dispatch

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     result = getattr(endpoint, method)(ctxt, **new_args)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/network/manager.py", line 222, in deallocate_fixed_ip

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     address, instance=instance)

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-
packages/nova/network/manager.py", line 1033, in deallocate_fixed_ip

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     self._teardown_network_on_host(context, network)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/network/manager.py", line 1837, in _teardown_network_on_host

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     self.driver.update_dhcp(elevated, dev, network)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/network/linux_net.py", line 1012, in update_dhcp

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     restart_dhcp(context, dev, network_ref, fixedips)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/openstack/common/lockutils.py", line 272, in inner

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     return f(*args, **kwargs)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/network/linux_net.py", line 1127, in restart_dhcp

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     _execute(*cmd, run_as_root=True)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/network/linux_net.py", line 1228, in _execute

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     return utils.execute(*cmd, **kwargs)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/utils.py", line 163, in execute
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     return processutils.execute(*cmd, **kwargs)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/openstack/common/processutils.py", line 203, in execute

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     cmd=sanitized_cmd)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher ProcessExecutionError: Unexpected error while running command.
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher Command: sudo nova-rootwrap /etc/nova/rootwrap.conf env CONFIG_FILE=["/usr/share/nova/nova-dist.conf", "/etc/nova/nova.conf"] NETWORK_ID=3 dnsmasq --strict-order --bind-interfaces --conf-file= --pid-file=/var/lib/nova/networks/nova-br100.pid --dhcp-optsfile=/var/lib/nova/networks/nova-br100.opts --listen-address=10.1.7.1 --except-interface=lo --dhcp-range=set:demo-net2,10.1.7.2,static,255.255.255.0,86400s --dhcp-lease-max=256 --dhcp-hostsfile=/var/lib/nova/networks/nova-br100.conf --dhcp-script=/usr/bin/nova-dhcpbridge --no-hosts --leasefile-ro --domain=novalocal --addn-hosts=/var/lib/nova/networks/nova-br100.hosts
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher Exit code: 2
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher Stdout: u''
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher Stderr: u'\ndnsmasq: failed to create listening socket for 10.1.7.1: Cannot assign requested address\n'
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher
2015-03-17 20:21:29.762 12661 ERROR oslo.messaging._drivers.common [req-a39517b6-2f21-4afb-8189-94381c553bf7 ] Returning exception Unexpected error while running command.
Command: sudo nova-rootwrap /etc/nova/rootwrap.conf env CONFIG_FILE=["/usr/share/nova/nova-dist.conf", "/etc/nova/nova.conf"] NETWORK_ID=3 dnsmasq --strict-order --bind-interfaces --conf-file= --pid-file=/var/lib/nova/networks/nova-br100.pid --dhcp-optsfile=/var/lib/nova/networks/nova-br100.opts --listen-address=10.1.7.1 --except-interface=lo --dhcp-range=set:demo-net2,10.1.7.2,static,255.255.255.0,86400s --dhcp-lease-max=256 --dhcp-hostsfile=/var/lib/nova/networks/nova-br100.conf --dhcp-script=/usr/bin/nova-dhcpbridge --no-hosts --leasefile-ro --domain=novalocal --addn-hosts=/var/lib/nova/networks/nova-br100.hosts
Exit code: 2
Stdout: u''
Stderr: u'\ndnsmasq: failed to create listening socket for 10.1.7.1: Cannot assign requested address\n' to caller

From compute node's nova-compute.log:

2015-03-20 23:02:14.268 1885 ERROR nova.virt.libvirt.driver [-] Error launching a defined domain with XML: <domain type='kvm'>
  <name>instance-0000000c</name>
  <uuid>3f793b60-2cfb-4f05-bbd8-519c97e30e45</uuid>
  <metadata>
    <nova:instance xmlns:nova="http://openstack.org/xmlns/libvirt/nova/1.0">
      <nova:package version="2014.2.2-19.el7ost"/>
      <nova:name>demo-instance4</nova:name>
      <nova:creationTime>2015-03-20 23:02:13</nova:creationTime>
      <nova:flavor name="m1.tiny">
        <nova:memory>512</nova:memory>
        <nova:disk>1</nova:disk>
        <nova:swap>0</nova:swap>
        <nova:ephemeral>0</nova:ephemeral>
        <nova:vcpus>1</nova:vcpus>
      </nova:flavor>
      <nova:owner>
        <nova:user uuid="3a6e30e6d1334f499ff13e00b65859a5">demo</nova:user>
        <nova:project uuid="1cb52dc33f8142c69590b16bd6fa53d2">demo</nova:project>
      </nova:owner>
      <nova:root type="image" uuid="2d70875d-d07c-413c-8a6e-d521b21ac192"/>
    </nova:instance>
  </metadata>
  <memory unit='KiB'>524288</memory>
  <currentMemory unit='KiB'>524288</currentMemory>
  <vcpu placement='static' cpuset='0,2,4,6,8,10,12,14,16,18,20,22'>1</vcpu>
  <sysinfo type='smbios'>
    <system>
      <entry name='manufacturer'>Fedora Project</entry>
      <entry name='product'>OpenStack Nova</entry>
      <entry name='version'>2014.2.2-19.el7ost</entry>
      <entry name='serial'>b8b80cdb-4efe-4a9a-9875-26a8173a2966</entry>
      <entry name='uuid'>3f793b60-2cfb-4f05-bbd8-519c97e30e45</entry>
    </system>
  </sysinfo>
  <os>
    <type arch='x86_64' machine='pc-i440fx-rhel7.0.0'>hvm</type>
    <boot dev='hd'/>
    <smbios mode='sysinfo'/>
  </os>
  <features>
    <acpi/>
    <apic/>
  </features>
  <cpu mode='host-model'>
    <model fallback='allow'/>
    <topology sockets='1' cores='1' threads='1'/>
  </cpu>
  <clock offset='utc'>
    <timer name='pit' tickpolicy='delay'/>
    <timer name='rtc' tickpolicy='catchup'/>
    <timer name='hpet' present='no'/>
  </clock>
  <on_poweroff>destroy</on_poweroff>
  <on_reboot>restart</on_reboot>
  <on_crash>destroy</on_crash>
  <devices>
    <emulator>/usr/libexec/qemu-kvm</emulator>
    <disk type='file' device='disk'>
      <driver name='qemu' type='qcow2' cache='none'/>
      <source file='/var/lib/nova/instances/3f793b60-2cfb-4f05-bbd8-519c97e30e45/disk'/>
      <target dev='vda' bus='virtio'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x04' function='0x0'/>
    </disk>
    <controller type='usb' index='0'>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x01' function='0x2'/>
    </controller>
    <controller type='pci' index='0' model='pci-root'/>
    <interface type='bridge'>
      <mac address='fa:16:3e:c9:a5:c7'/>
      <source bridge='br100'/>
      <model type='virtio'/>
      <filterref filter='nova-instance-instance-0000000c-fa163ec9a5c7'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x03' function='0x0'/>
    </interface>
    <serial type='file'>
      <source path='/var/lib/nova/instances/3f793b60-2cfb-4f05-bbd8-519c97e30e45/console.log'/>
      <target port='0'/>
    </serial>
    <serial type='pty'>
      <target port='1'/>
    </serial>
    <console type='file'>
      <source path='/var/lib/nova/instances/3f793b60-2cfb-4f05-bbd8-519c97e30e45/console.log'/>
      <target type='serial' port='0'/>
    </console>
    <input type='tablet' bus='usb'/>
    <input type='mouse' bus='ps2'/>
    <graphics type='vnc' port='-1' autoport='yes' listen='0.0.0.0' keymap='en-us'>
      <listen type='address' address='0.0.0.0'/>
    </graphics>
    <video>
      <model type='cirrus' vram='9216' heads='1'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x02' function='0x0'/>
    </video>
    <memballoon model='virtio'>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x05' function='0x0'/>
      <stats period='10'/>
    </memballoon>
  </devices>
</domain>

2015-03-20 23:02:14.269 1885 ERROR nova.compute.manager [-] [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45] Instance failed to spawn
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45] Traceback (most recent call last):
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2252, in _build_resources
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]     yield resources
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2122, in _build_and_run_instance
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]     block_device_info=block_device_info)
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 2635, in spawn
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]     block_device_info, disk_info=disk_info)
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 4558, in _create_domain_and_network
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]     power_on=power_on)
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 4482, in _create_domain
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]     LOG.error(err)
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]   File "/usr/lib/python2.7/site-packages/nova/openstack/common/excutils.py", line 82, in __exit__
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]     six.reraise(self.type_, self.value, self.tb)
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 4472, in _create_domain
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]     domain.createWithFlags(launch_flags)
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]   File "/usr/lib/python2.7/site-packages/eventlet/tpool.py", line 183, in doit
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]     result = proxy_call(self._autowrap, f, *args, **kwargs)
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]   File "/usr/lib/python2.7/site-packages/eventlet/tpool.py", line 141, in proxy_call
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]     rv = execute(f, *args, **kwargs)
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]   File "/usr/lib/python2.7/site-packages/eventlet/tpool.py", line 122, in execute
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]     six.reraise(c, e, tb)
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]   File "/usr/lib/python2.7/site-packages/eventlet/tpool.py", line 80, in tworker
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]     rv = meth(*args, **kwargs)
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]   File "/usr/lib64/python2.7/site-packages/libvirt.py", line 728, in createWithFlags
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]     if ret == -1: raise libvirtError ('virDomainCreateWithFlags() failed', dom=self)
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45] libvirtError: Cannot get interface MTU on 'br100': No such device
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45] 
2015-03-20 23:02:14.277 1885 AUDIT nova.compute.manager [req-f47270bb-82de-43bc-92f8-b8e7b1902910 None] [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45] Terminating instance
2015-03-20 23:02:14.293 1885 INFO nova.virt.libvirt.driver [-] [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45] Instance destroyed successfully.
2015-03-20 23:02:14.778 1885 INFO nova.virt.libvirt.driver [-] [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45] Deleting instance files /var/lib/nova/instances/3f793b60-2cfb-4f05-bbd8-519c97e30e45_del
2015-03-20 23:02:14.779 1885 INFO nova.virt.libvirt.driver [-] [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45] Deletion of /var/lib/nova/instances/3f793b60-2cfb-4f05-bbd8-519c97e30e45_del complete
2015-03-20 23:02:14.959 1885 INFO nova.scheduler.client.report [-] Compute_service record updated for ('compute5.osp', 'compute5.osp')
2015-03-20 23:02:39.420 1885 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2015-03-20 23:02:40.055 1885 AUDIT nova.compute.resource_tracker [-] Total physical ram (MB): 64221, total allocated virtual ram (MB): 1024
2015-03-20 23:02:40.056 1885 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 163
2015-03-20 23:02:40.056 1885 AUDIT nova.compute.resource_tracker [-] Total usable vcpus: 24, total allocated vcpus: 0
2015-03-20 23:02:40.057 1885 AUDIT nova.compute.resource_tracker [-] PCI stats: []
2015-03-20 23:02:40.091 1885 INFO nova.scheduler.client.report [-] Compute_service record updated for ('compute5.osp', 'compute5.osp')
2015-03-20 23:02:40.092 1885 INFO nova.compute.resource_tracker [-] Compute_service record updated for compute5.osp:compute5.osp
2015-03-20 23:03:41.421 1885 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2015-03-20 23:03:42.024 1885 AUDIT nova.compute.resource_tracker [-] Total physical ram (MB): 64221, total allocated virtual ram (MB): 1024
2015-03-20 23:03:42.024 1885 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 163
2015-03-20 23:03:42.025 1885 AUDIT nova.compute.resource_tracker [-] Total usable vcpus: 24, total allocated vcpus: 0
2015-03-20 23:03:42.025 1885 AUDIT nova.compute.resource_tracker [-] PCI stats: []
2015-03-20 23:03:42.026 1885 INFO nova.compute.resource_tracker [-] Compute_service record updated for compute5.osp:compute5.osp
2015-03-20 23:04:41.878 1885 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2015-03-20 23:04:42.501 1885 AUDIT nova.compute.resource_tracker [-] Total physical ram (MB): 64221, total allocated virtual ram (MB): 1024
2015-03-20 23:04:42.502 1885 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 163
2015-03-20 23:04:42.502 1885 AUDIT nova.compute.resource_tracker [-] Total usable vcpus: 24, total allocated vcpus: 0
2015-03-20 23:04:42.503 1885 AUDIT nova.compute.resource_tracker [-] PCI stats: []
2015-03-20 23:04:42.503 1885 INFO nova.compute.resource_tracker [-] Compute_service record updated for compute5.osp:compute5.osp

nova boot creates instance in error state: network bridge isn't created

This is my first go at Openstack. I'm following steps 1 - 7 from http://docs.openstack.org/juno/install-guide/install/yum/content/launch-instance-nova.html

General:

  • RHEL 7.0
  • Juno
  • LEGACY Networking (Nova)
  • 8 compute nodes / 1 controller
  • NetworkManger off / disabled
  • iptables off / disabled
  • 1 network interface per node ( bond0 )

Issue: Every time I create an instance with nova boot, the result is a server with state: ERROR. Combing through the logs, nova-conductor.log has an error line that mentions "Cannot get interface MTU on 'br100': No such device". Looking at the node that the instance was created on, there is no bridge interface. The guide doesn't mention anything about manually creating the bridge.

My understanding is that it's meant to be done automatically at the moment the instance is created. Is that true? And if so, I'd appreciate any help diagnosing the cause.

Sorry in advance for the wall of text. I tried to make it as readable as I could.

Following http://docs.openstack.org/juno/install-guide/install/yum/content/launch-instance-nova.html , I run 

# nova boot --flavor m1.tiny --image cirros-0.3.3-x86_64 --nic net-id=8fed6262-d5d5-497d-996b-2c26922fcbcf  --security-group default --key-name demo-key demo-instance1

--------------------------------------------------------------------------------------------
| Property                             | Value
| OS-DCF:diskConfig                    | MANUAL
| OS-EXT-AZ:availability_zone          | nova
| OS-EXT-STS:power_state               | 0
| OS-EXT-STS:task_state                | scheduling
| OS-EXT-STS:vm_state                  | building
| OS-SRV-USG:launched_at               | - 
| OS-SRV-USG:terminated_at             | - 
| accessIPv4                           |           
| accessIPv6                           |            
| adminPass                            | w4zcTWdi69J8
| config_drive                         |               
| created                              | 2015-03-17T20:51:17Z
| flavor                               | m1.tiny (1)
| hostId                               |                
| id                                   | c87f8800-63c5-47fd-96c3-8d37dceba955     
| image                                | cirros-0.3.3-x86_64 (2d70875d-d07c-413c-8a6e-d521b21ac192)
| key_name                             | demo-key
| metadata                             | {}        
| name                                 | demo-instance1  
| os-extended-volumes:volumes_attached | []               
| progress                             | 0      
| security_groups                      | default         
| status                               | BUILD         
| tenant_id                            | 1cb52dc33f8142c69590b16bd6fa53d2
| updated                              | 2015-03-17T20:51:17Z     
| user_id                              | 3a6e30e6d1334f499ff13e00b65859a5
-------------------------------------------------------------------------------------------------

[root@controller ~]# nova list
| ID              | Name           | Status | Task State | Power State | Networks
| c87f8800-63c5-47fd-96c3-8d37dceba955 | demo-instance1 | ERROR  | -    | NOSTATE     | demo-net=10.1.7.2

From controller /var/log/nova/nova-conductor.log

2015-03-17 20:51:17.420 26007 INFO oslo.messaging._drivers.impl_rabbit [req-b3441565-61df-4c9c-ba79-71093f4b3d31 ] Connecting to AMQP server on localhost:5672

2015-03-17 20:51:17.446 26007 INFO oslo.messaging._drivers.impl_rabbit [req-b3441565-61df-4c9c-ba79-71093f4b3d31 ] Connected to AMQP server on localhost:5672

2015-03-17 20:51:36.891 26001 ERROR nova.scheduler.utils [req-b3441565-61df-4c9c-ba79-71093f4b3d31 None] [instance: c87f8800-63c5-47fd-96c3-8d37dceba955] Error from last host: compute2.osp (node compute2.osp): [u'Traceback (most recent call last):\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2033, in _do_build_and_run_instance\n    filter_properties)\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2164, in _build_and_run_instance\n    instance_uuid=instance.uuid, reason=six.text_type(e))\n', u"RescheduledException: Build of instance c87f8800-63c5-47fd-96c3-8d37dceba955 was re-scheduled: internal error: referenced filter 'no-mac-spoofing' is missing\n"]

2015-03-17 20:51:36.897 26001 INFO oslo.messaging._drivers.impl_rabbit [req-b3441565-61df-4c9c-ba79-71093f4b3d31 ] Connecting to AMQP server on localhost:5672

2015-03-17 20:51:36.922 26001 INFO oslo.messaging._drivers.impl_rabbit [req-b3441565-61df-4c9c-ba79-71093f4b3d31 ] Connected to AMQP server on localhost:5672

2015-03-17 20:51:43.437 26001 ERROR nova.scheduler.utils [req-b3441565-61df-4c9c-ba79-71093f4b3d31 None] [instance: c87f8800-63c5-47fd-96c3-8d37dceba955] Error from last host: compute3.osp (node compute3.osp): [u'Traceback (most recent call last):\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2033, in _do_build_and_run_instance\n    filter_properties)\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2164, in _build_and_run_instance\n    instance_uuid=instance.uuid, reason=six.text_type(e))\n', u"RescheduledException: Build of instance c87f8800-63c5-47fd-96c3-8d37dceba955 was re-scheduled: Cannot get interface MTU on 'br100': No such device\n"]

2015-03-17 20:51:48.958 25987 ERROR nova.scheduler.utils [req-b3441565-61df-4c9c-ba79-71093f4b3d31 None] [instance: c87f8800-63c5-47fd-96c3-8d37dceba955] Error from last host: compute5.osp (node compute5.osp): [u'Traceback (most recent call last):\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2033, in _do_build_and_run_instance\n    filter_properties)\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2164, in _build_and_run_instance\n    instance_uuid=instance.uuid, reason=six.text_type(e))\n', u"RescheduledException: Build of instance c87f8800-63c5-47fd-96c3-8d37dceba955 was re-scheduled: Cannot get interface MTU on 'br100': No such device\n"]

2015-03-17 20:51:48.960 25987 WARNING nova.scheduler.driver [req-b3441565-61df-4c9c-ba79-71093f4b3d31 None] [instance: c87f8800-63c5-47fd-96c3-8d37dceba955] NoValidHost exception with message: 'No valid host was found. Exceeded max scheduling attempts 3 for instance c87f8800-63c5-47fd-96c3-8d37dceba955. Last exception: [u'Traceback (most recent call last):\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2033, in _do_build_and_run_instance\n    filter_properties)\n', u'  File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2164, in _build_and_run_instance\n    instance_uuid=instance.uuid, reason=six.text_type(e))\n', u"RescheduledException: Build of instance c87f8800-63c5-47fd-96c3-8d37dceba955 was re-scheduled: Cannot get interface MTU on 'br100': No such device\n"]'

2015-03-17 20:51:48.960 25987 WARNING nova.scheduler.driver [req-b3441565-61df-4c9c-ba79-71093f4b3d31 None] [instance: c87f8800-63c5-47fd-96c3-8d37dceba955] Setting instance to ERROR state.

And from compute5:/var/log/nova/nova-network.log:

Command: sudo nova-rootwrap /etc/nova/rootwrap.conf env CONFIG_FILE=["/usr/share/nova/nova-dist.conf", "/etc/nova/nova.conf"] NETWORK_ID=3 dnsmasq --strict-order --bind-interfaces --conf-file= --pid-file=/var/lib/nova/networks/nova-br100.pid --dhcp-optsfile=/var/lib/nova/networks/nova-br100.opts --listen-address=10.1.7.1 --except-interface=lo --dhcp-range=set:demo-net2,10.1.7.2,static,255.255.255.0,86400s --dhcp-lease-max=256 --dhcp-hostsfile=/var/lib/nova/networks/nova-br100.conf --dhcp-script=/usr/bin/nova-dhcpbridge --no-hosts --leasefile-ro --domain=novalocal --addn-hosts=/var/lib/nova/networks/nova-br100.hosts
Exit code: 2
Stdout: u''
Stderr: u'\ndnsmasq: failed to create listening socket for 10.1.7.1: Cannot assign requested address\n'
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher Traceback (most recent call last):
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 134, in _dispatch_and_reply

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     incoming.message))

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-      packages/oslo/messaging/rpc/dispatcher.py", line 177, in _dispatch

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     return self._do_dispatch(endpoint, method, ctxt, args)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo/messaging/rpc/dispatcher.py", line 123, in _do_dispatch

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     result = getattr(endpoint, method)(ctxt, **new_args)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/network/manager.py", line 222, in deallocate_fixed_ip

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     address, instance=instance)

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-
packages/nova/network/manager.py", line 1033, in deallocate_fixed_ip

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     self._teardown_network_on_host(context, network)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/network/manager.py", line 1837, in _teardown_network_on_host

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     self.driver.update_dhcp(elevated, dev, network)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/network/linux_net.py", line 1012, in update_dhcp

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     restart_dhcp(context, dev, network_ref, fixedips)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/openstack/common/lockutils.py", line 272, in inner

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     return f(*args, **kwargs)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/network/linux_net.py", line 1127, in restart_dhcp

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     _execute(*cmd, run_as_root=True)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/network/linux_net.py", line 1228, in _execute

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     return utils.execute(*cmd, **kwargs)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/utils.py", line 163, in execute
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     return processutils.execute(*cmd, **kwargs)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/openstack/common/processutils.py", line 203, in execute

2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher     cmd=sanitized_cmd)
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher ProcessExecutionError: Unexpected error while running command.
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher Command: sudo nova-rootwrap /etc/nova/rootwrap.conf env CONFIG_FILE=["/usr/share/nova/nova-dist.conf", "/etc/nova/nova.conf"] NETWORK_ID=3 dnsmasq --strict-order --bind-interfaces --conf-file= --pid-file=/var/lib/nova/networks/nova-br100.pid --dhcp-optsfile=/var/lib/nova/networks/nova-br100.opts --listen-address=10.1.7.1 --except-interface=lo --dhcp-range=set:demo-net2,10.1.7.2,static,255.255.255.0,86400s --dhcp-lease-max=256 --dhcp-hostsfile=/var/lib/nova/networks/nova-br100.conf --dhcp-script=/usr/bin/nova-dhcpbridge --no-hosts --leasefile-ro --domain=novalocal --addn-hosts=/var/lib/nova/networks/nova-br100.hosts
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher Exit code: 2
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher Stdout: u''
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher Stderr: u'\ndnsmasq: failed to create listening socket for 10.1.7.1: Cannot assign requested address\n'
2015-03-17 20:21:29.761 12661 TRACE oslo.messaging.rpc.dispatcher
2015-03-17 20:21:29.762 12661 ERROR oslo.messaging._drivers.common [req-a39517b6-2f21-4afb-8189-94381c553bf7 ] Returning exception Unexpected error while running command.
Command: sudo nova-rootwrap /etc/nova/rootwrap.conf env CONFIG_FILE=["/usr/share/nova/nova-dist.conf", "/etc/nova/nova.conf"] NETWORK_ID=3 dnsmasq --strict-order --bind-interfaces --conf-file= --pid-file=/var/lib/nova/networks/nova-br100.pid --dhcp-optsfile=/var/lib/nova/networks/nova-br100.opts --listen-address=10.1.7.1 --except-interface=lo --dhcp-range=set:demo-net2,10.1.7.2,static,255.255.255.0,86400s --dhcp-lease-max=256 --dhcp-hostsfile=/var/lib/nova/networks/nova-br100.conf --dhcp-script=/usr/bin/nova-dhcpbridge --no-hosts --leasefile-ro --domain=novalocal --addn-hosts=/var/lib/nova/networks/nova-br100.hosts
Exit code: 2
Stdout: u''
Stderr: u'\ndnsmasq: failed to create listening socket for 10.1.7.1: Cannot assign requested address\n' to caller

From compute node's nova-compute.log:

2015-03-20 23:02:14.268 1885 ERROR nova.virt.libvirt.driver [-] Error launching a defined domain with XML: <domain type='kvm'>
  <name>instance-0000000c</name>
  <uuid>3f793b60-2cfb-4f05-bbd8-519c97e30e45</uuid>
  <metadata>
    <nova:instance xmlns:nova="http://openstack.org/xmlns/libvirt/nova/1.0">
      <nova:package version="2014.2.2-19.el7ost"/>
      <nova:name>demo-instance4</nova:name>
      <nova:creationTime>2015-03-20 23:02:13</nova:creationTime>
      <nova:flavor name="m1.tiny">
        <nova:memory>512</nova:memory>
        <nova:disk>1</nova:disk>
        <nova:swap>0</nova:swap>
        <nova:ephemeral>0</nova:ephemeral>
        <nova:vcpus>1</nova:vcpus>
      </nova:flavor>
      <nova:owner>
        <nova:user uuid="3a6e30e6d1334f499ff13e00b65859a5">demo</nova:user>
        <nova:project uuid="1cb52dc33f8142c69590b16bd6fa53d2">demo</nova:project>
      </nova:owner>
      <nova:root type="image" uuid="2d70875d-d07c-413c-8a6e-d521b21ac192"/>
    </nova:instance>
  </metadata>
  <memory unit='KiB'>524288</memory>
  <currentMemory unit='KiB'>524288</currentMemory>
  <vcpu placement='static' cpuset='0,2,4,6,8,10,12,14,16,18,20,22'>1</vcpu>
  <sysinfo type='smbios'>
    <system>
      <entry name='manufacturer'>Fedora Project</entry>
      <entry name='product'>OpenStack Nova</entry>
      <entry name='version'>2014.2.2-19.el7ost</entry>
      <entry name='serial'>b8b80cdb-4efe-4a9a-9875-26a8173a2966</entry>
      <entry name='uuid'>3f793b60-2cfb-4f05-bbd8-519c97e30e45</entry>
    </system>
  </sysinfo>
  <os>
    <type arch='x86_64' machine='pc-i440fx-rhel7.0.0'>hvm</type>
    <boot dev='hd'/>
    <smbios mode='sysinfo'/>
  </os>
  <features>
    <acpi/>
    <apic/>
  </features>
  <cpu mode='host-model'>
    <model fallback='allow'/>
    <topology sockets='1' cores='1' threads='1'/>
  </cpu>
  <clock offset='utc'>
    <timer name='pit' tickpolicy='delay'/>
    <timer name='rtc' tickpolicy='catchup'/>
    <timer name='hpet' present='no'/>
  </clock>
  <on_poweroff>destroy</on_poweroff>
  <on_reboot>restart</on_reboot>
  <on_crash>destroy</on_crash>
  <devices>
    <emulator>/usr/libexec/qemu-kvm</emulator>
    <disk type='file' device='disk'>
      <driver name='qemu' type='qcow2' cache='none'/>
      <source file='/var/lib/nova/instances/3f793b60-2cfb-4f05-bbd8-519c97e30e45/disk'/>
      <target dev='vda' bus='virtio'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x04' function='0x0'/>
    </disk>
    <controller type='usb' index='0'>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x01' function='0x2'/>
    </controller>
    <controller type='pci' index='0' model='pci-root'/>
    <interface type='bridge'>
      <mac address='fa:16:3e:c9:a5:c7'/>
      <source bridge='br100'/>
      <model type='virtio'/>
      <filterref filter='nova-instance-instance-0000000c-fa163ec9a5c7'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x03' function='0x0'/>
    </interface>
    <serial type='file'>
      <source path='/var/lib/nova/instances/3f793b60-2cfb-4f05-bbd8-519c97e30e45/console.log'/>
      <target port='0'/>
    </serial>
    <serial type='pty'>
      <target port='1'/>
    </serial>
    <console type='file'>
      <source path='/var/lib/nova/instances/3f793b60-2cfb-4f05-bbd8-519c97e30e45/console.log'/>
      <target type='serial' port='0'/>
    </console>
    <input type='tablet' bus='usb'/>
    <input type='mouse' bus='ps2'/>
    <graphics type='vnc' port='-1' autoport='yes' listen='0.0.0.0' keymap='en-us'>
      <listen type='address' address='0.0.0.0'/>
    </graphics>
    <video>
      <model type='cirrus' vram='9216' heads='1'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x02' function='0x0'/>
    </video>
    <memballoon model='virtio'>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x05' function='0x0'/>
      <stats period='10'/>
    </memballoon>
  </devices>
</domain>

2015-03-20 23:02:14.269 1885 ERROR nova.compute.manager [-] [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45] Instance failed to spawn
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45] Traceback (most recent call last):
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2252, in _build_resources
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]     yield resources
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2122, in _build_and_run_instance
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]     block_device_info=block_device_info)
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 2635, in spawn
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]     block_device_info, disk_info=disk_info)
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 4558, in _create_domain_and_network
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]     power_on=power_on)
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 4482, in _create_domain
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]     LOG.error(err)
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]   File "/usr/lib/python2.7/site-packages/nova/openstack/common/excutils.py", line 82, in __exit__
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]     six.reraise(self.type_, self.value, self.tb)
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 4472, in _create_domain
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]     domain.createWithFlags(launch_flags)
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]   File "/usr/lib/python2.7/site-packages/eventlet/tpool.py", line 183, in doit
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]     result = proxy_call(self._autowrap, f, *args, **kwargs)
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]   File "/usr/lib/python2.7/site-packages/eventlet/tpool.py", line 141, in proxy_call
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]     rv = execute(f, *args, **kwargs)
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]   File "/usr/lib/python2.7/site-packages/eventlet/tpool.py", line 122, in execute
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]     six.reraise(c, e, tb)
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]   File "/usr/lib/python2.7/site-packages/eventlet/tpool.py", line 80, in tworker
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]     rv = meth(*args, **kwargs)
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]   File "/usr/lib64/python2.7/site-packages/libvirt.py", line 728, in createWithFlags
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45]     if ret == -1: raise libvirtError ('virDomainCreateWithFlags() failed', dom=self)
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45] libvirtError: Cannot get interface MTU on 'br100': No such device
2015-03-20 23:02:14.269 1885 TRACE nova.compute.manager [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45] 
2015-03-20 23:02:14.277 1885 AUDIT nova.compute.manager [req-f47270bb-82de-43bc-92f8-b8e7b1902910 None] [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45] Terminating instance
2015-03-20 23:02:14.293 1885 INFO nova.virt.libvirt.driver [-] [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45] Instance destroyed successfully.
2015-03-20 23:02:14.778 1885 INFO nova.virt.libvirt.driver [-] [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45] Deleting instance files /var/lib/nova/instances/3f793b60-2cfb-4f05-bbd8-519c97e30e45_del
2015-03-20 23:02:14.779 1885 INFO nova.virt.libvirt.driver [-] [instance: 3f793b60-2cfb-4f05-bbd8-519c97e30e45] Deletion of /var/lib/nova/instances/3f793b60-2cfb-4f05-bbd8-519c97e30e45_del complete
2015-03-20 23:02:14.959 1885 INFO nova.scheduler.client.report [-] Compute_service record updated for ('compute5.osp', 'compute5.osp')
2015-03-20 23:02:39.420 1885 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2015-03-20 23:02:40.055 1885 AUDIT nova.compute.resource_tracker [-] Total physical ram (MB): 64221, total allocated virtual ram (MB): 1024
2015-03-20 23:02:40.056 1885 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 163
2015-03-20 23:02:40.056 1885 AUDIT nova.compute.resource_tracker [-] Total usable vcpus: 24, total allocated vcpus: 0
2015-03-20 23:02:40.057 1885 AUDIT nova.compute.resource_tracker [-] PCI stats: []
2015-03-20 23:02:40.091 1885 INFO nova.scheduler.client.report [-] Compute_service record updated for ('compute5.osp', 'compute5.osp')
2015-03-20 23:02:40.092 1885 INFO nova.compute.resource_tracker [-] Compute_service record updated for compute5.osp:compute5.osp
2015-03-20 23:03:41.421 1885 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2015-03-20 23:03:42.024 1885 AUDIT nova.compute.resource_tracker [-] Total physical ram (MB): 64221, total allocated virtual ram (MB): 1024
2015-03-20 23:03:42.024 1885 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 163
2015-03-20 23:03:42.025 1885 AUDIT nova.compute.resource_tracker [-] Total usable vcpus: 24, total allocated vcpus: 0
2015-03-20 23:03:42.025 1885 AUDIT nova.compute.resource_tracker [-] PCI stats: []
2015-03-20 23:03:42.026 1885 INFO nova.compute.resource_tracker [-] Compute_service record updated for compute5.osp:compute5.osp
2015-03-20 23:04:41.878 1885 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources
2015-03-20 23:04:42.501 1885 AUDIT nova.compute.resource_tracker [-] Total physical ram (MB): 64221, total allocated virtual ram (MB): 1024
2015-03-20 23:04:42.502 1885 AUDIT nova.compute.resource_tracker [-] Free disk (GB): 163
2015-03-20 23:04:42.502 1885 AUDIT nova.compute.resource_tracker [-] Total usable vcpus: 24, total allocated vcpus: 0
2015-03-20 23:04:42.503 1885 AUDIT nova.compute.resource_tracker [-] PCI stats: []
2015-03-20 23:04:42.503 1885 INFO nova.compute.resource_tracker [-] Compute_service record updated for compute5.osp:compute5.osp