ERROR when trying to launch instance on remote node

Asked by Don Mize

I can get a single node cloud working with the ESSEX release on 12.04, but am having trouble when it tries to launch on a second node. I've installed nova-compute and nova-network on the second node and get happy :-) faces in my service list. However when I launch, it builds then ERRORs out.

+--------------------------------------+---------+--------+----------------------+
| ID | Name | Status | Networks |
+--------------------------------------+---------+--------+----------------------+
| 3c616cad-c6b7-4def-aeee-898bb7fd43c9 | server2 | ERROR | novanet=172.17.87.11 |
| 9db8f77c-f32c-4a86-90d8-dffe8852aaa0 | server1 | ACTIVE | novanet=172.17.87.9 |
+--------------------------------------+---------+--------+----------------------+

In the nova-compute.log on the second node I see the below.

2012-04-30 18:52:52 DEBUG nova.utils [req-28864db1-b886-4648-8b89-201f5d169990 519756814c9a46828593713c60da9cc4 f08711b7261742f99e02f40b28b4ce5a] Running cmd (subprocess): sudo nova-rootwrap qemu-nbd -d /dev/nbd15 from (pid=1280) execute /usr/lib/python2.7/dist-packages/nova/utils.py:219
2012-04-30 18:52:57 ERROR nova.compute.manager [req-28864db1-b886-4648-8b89-201f5d169990 519756814c9a46828593713c60da9cc4 f08711b7261742f99e02f40b28b4ce5a] [instance: 3c616cad-c6b7-4def-aeee-898bb7fd43c9] Instance failed to spawn
2012-04-30 18:52:57 TRACE nova.compute.manager [instance: 3c616cad-c6b7-4def-aeee-898bb7fd43c9] Traceback (most recent call last):
2012-04-30 18:52:57 TRACE nova.compute.manager [instance: 3c616cad-c6b7-4def-aeee-898bb7fd43c9] File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 592, in _spawn
2012-04-30 18:52:57 TRACE nova.compute.manager [instance: 3c616cad-c6b7-4def-aeee-898bb7fd43c9] self._legacy_nw_info(network_info), block_device_info)
2012-04-30 18:52:57 TRACE nova.compute.manager [instance: 3c616cad-c6b7-4def-aeee-898bb7fd43c9] File "/usr/lib/python2.7/dist-packages/nova/exception.py", line 114, in wrapped
2012-04-30 18:52:57 TRACE nova.compute.manager [instance: 3c616cad-c6b7-4def-aeee-898bb7fd43c9] return f(*args, **kw)
2012-04-30 18:52:57 TRACE nova.compute.manager [instance: 3c616cad-c6b7-4def-aeee-898bb7fd43c9] File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/connection.py", line 922, in spawn
2012-04-30 18:52:57 TRACE nova.compute.manager [instance: 3c616cad-c6b7-4def-aeee-898bb7fd43c9] self._create_new_domain(xml)
2012-04-30 18:52:57 TRACE nova.compute.manager [instance: 3c616cad-c6b7-4def-aeee-898bb7fd43c9] File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/connection.py", line 1575, in _create_new_domain
2012-04-30 18:52:57 TRACE nova.compute.manager [instance: 3c616cad-c6b7-4def-aeee-898bb7fd43c9] domain.createWithFlags(launch_flags)
2012-04-30 18:52:57 TRACE nova.compute.manager [instance: 3c616cad-c6b7-4def-aeee-898bb7fd43c9] File "/usr/lib/python2.7/dist-packages/libvirt.py", line 581, in createWithFlags
2012-04-30 18:52:57 TRACE nova.compute.manager [instance: 3c616cad-c6b7-4def-aeee-898bb7fd43c9] if ret == -1: raise libvirtError ('virDomainCreateWithFlags() failed', dom=self)
2012-04-30 18:52:57 TRACE nova.compute.manager [instance: 3c616cad-c6b7-4def-aeee-898bb7fd43c9] libvirtError: Unable to read from monitor: Connection reset by peer
2012-04-30 18:52:57 TRACE nova.compute.manager [instance: 3c616cad-c6b7-4def-aeee-898bb7fd43c9]
2012-04-30 18:52:57 DEBUG nova.compute.manager [req-28864db1-b886-4648-8b89-201f5d169990 519756814c9a46828593713c60da9cc4 f08711b7261742f99e02f40b28b4ce5a] [instance: 3c616cad-c6b7-4def-aeee-898bb7fd43c9] Deallocating network for instance from (pid=1280) _deallocate_network /usr/lib/python2.7/dist-packages/nova/compute/manager.py:616
2012-04-30 18:52:57 DEBUG nova.rpc.amqp [req-28864db1-b886-4648-8b89-201f5d169990 519756814c9a46828593713c60da9cc4 f08711b7261742f99e02f40b28b4ce5a] Making asynchronous cast on network... from (pid=1280) cast /usr/lib/python2.7/dist-packages/nova/rpc/amqp.py:346
2012-04-30 18:52:57 ERROR nova.rpc.amqp [req-28864db1-b886-4648-8b89-201f5d169990 519756814c9a46828593713c60da9cc4 f08711b7261742f99e02f40b28b4ce5a] Exception during message handling
2012-04-30 18:52:57 TRACE nova.rpc.amqp Traceback (most recent call last):
2012-04-30 18:52:57 TRACE nova.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/rpc/amqp.py", line 252, in _process_data
2012-04-30 18:52:57 TRACE nova.rpc.amqp rval = node_func(context=ctxt, **node_args)
2012-04-30 18:52:57 TRACE nova.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/exception.py", line 114, in wrapped
2012-04-30 18:52:57 TRACE nova.rpc.amqp return f(*args, **kw)
2012-04-30 18:52:57 TRACE nova.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 177, in decorated_function
2012-04-30 18:52:57 TRACE nova.rpc.amqp sys.exc_info())
2012-04-30 18:52:57 TRACE nova.rpc.amqp File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-04-30 18:52:57 TRACE nova.rpc.amqp self.gen.next()
2012-04-30 18:52:57 TRACE nova.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 171, in decorated_function
2012-04-30 18:52:57 TRACE nova.rpc.amqp return function(self, context, instance_uuid, *args, **kwargs)
2012-04-30 18:52:57 TRACE nova.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 651, in run_instance
2012-04-30 18:52:57 TRACE nova.rpc.amqp do_run_instance()
2012-04-30 18:52:57 TRACE nova.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/utils.py", line 945, in inner
2012-04-30 18:52:57 TRACE nova.rpc.amqp retval = f(*args, **kwargs)
2012-04-30 18:52:57 TRACE nova.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 650, in do_run_instance
2012-04-30 18:52:57 TRACE nova.rpc.amqp self._run_instance(context, instance_uuid, **kwargs)
2012-04-30 18:52:57 TRACE nova.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 451, in _run_instance
2012-04-30 18:52:57 TRACE nova.rpc.amqp self._set_instance_error_state(context, instance_uuid)
2012-04-30 18:52:57 TRACE nova.rpc.amqp File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-04-30 18:52:57 TRACE nova.rpc.amqp self.gen.next()
2012-04-30 18:52:57 TRACE nova.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 432, in _run_instance
2012-04-30 18:52:57 TRACE nova.rpc.amqp self._deallocate_network(context, instance)
2012-04-30 18:52:57 TRACE nova.rpc.amqp File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-04-30 18:52:57 TRACE nova.rpc.amqp self.gen.next()
2012-04-30 18:52:57 TRACE nova.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 429, in _run_instance
2012-04-30 18:52:57 TRACE nova.rpc.amqp injected_files, admin_password)
2012-04-30 18:52:57 TRACE nova.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 592, in _spawn
2012-04-30 18:52:57 TRACE nova.rpc.amqp self._legacy_nw_info(network_info), block_device_info)
2012-04-30 18:52:57 TRACE nova.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/exception.py", line 114, in wrapped
2012-04-30 18:52:57 TRACE nova.rpc.amqp return f(*args, **kw)
2012-04-30 18:52:57 TRACE nova.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/connection.py", line 922, in spawn
2012-04-30 18:52:57 TRACE nova.rpc.amqp self._create_new_domain(xml)
2012-04-30 18:52:57 TRACE nova.rpc.amqp File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/connection.py", line 1575, in _create_new_domain
2012-04-30 18:52:57 TRACE nova.rpc.amqp domain.createWithFlags(launch_flags)
2012-04-30 18:52:57 TRACE nova.rpc.amqp File "/usr/lib/python2.7/dist-packages/libvirt.py", line 581, in createWithFlags
2012-04-30 18:52:57 TRACE nova.rpc.amqp if ret == -1: raise libvirtError ('virDomainCreateWithFlags() failed', dom=self)
2012-04-30 18:52:57 TRACE nova.rpc.amqp libvirtError: Unable to read from monitor: Connection reset by peer
2012-04-30 18:52:57 TRACE nova.rpc.amqp
2012-04-30 18:53:27 DEBUG nova.manager [-] Running periodic task ComputeManager._publish_service_capabilities from (pid=1280) periodic_tasks /usr/lib/python2.7/dist-packages/nova/manager.py:152
2012-04-30 18:53:27 DEBUG nova.manager [-] Notifying Schedulers of capabilities ... from (pid=1280) _publish_service_capabilities /usr/lib/python2.7/dist-packages/nova/manager.py:203
2012-04-30 18:53:27 DEBUG nova.rpc.amqp [-] Making asynchronous fanout cast... from (pid=1280) fanout_cast /usr/lib/python2.7/dist-packages/nova/rpc/amqp.py:354
2012-04-30 18:53:27 DEBUG nova.manager [-] Running periodic task ComputeManager._poll_rescued_instances from (pid=1280) periodic_tasks /usr/lib/python2.7/dist-packages/nova/manager.py:152
2012-04-30 18:53:27 DEBUG nova.manager [-] Running periodic task ComputeManager._sync_power_states from (pid=1280) periodic_tasks /usr/lib/python2.7/dist-packages/nova/manager.py:152

My nova.conf file for both nodes is:
# LOGS/STATE
--verbose=True
--logdir=/var/log/nova
--lock_path=/var/lock/nova
--state_path=/var/lib/nova
# AUTHENTICATION
--auth_strategy=keystone
# SCHEDULER
--compute_scheduler_driver=nova.scheduler.filter_scheduler.FilterScheduler
# VOLUMES
--volume_group=nova-volumes
--volume_name_template=volume-%08x
--iscsi_helper=tgtadm
--root_helper=sudo nova-rootwrap
# DATABASE
--sql_connection=mysql://nova:nova@172.17.86.8/nova
# COMPUTE
--libvirt_type=kvm
--connection_type=libvirt
--instance_name_template=instance-%08x
--api_paste_config=/etc/nova/api-paste.ini
--allow_resize_to_same_host=True
# APIS
--osapi_compute_extension=nova.api.openstack.compute.contrib.standard_extensions
--ec2_dmz_host=172.17.86.8
--s3_host=172.17.86.8
# RABBITMQ
--rabbit_host=172.17.86.8
--rabbit_password=guest
# GLANCE
--image_service=nova.image.glance.GlanceImageService
--glance_api_servers=172.17.86.8:9292
# NETWORK
--force_dhcp_release=True
--dhcpbridge_flagfile=/etc/nova/nova.conf
--firewall_driver=nova.virt.libvirt.firewall.IptablesFirewallDriver
--my_ip=172.17.86.8
--public_interface=eth0
--vlan_interface=eth0
--fixed_range=172.17.80.0/16
--network_size=8
# NOVNC CONSOLE
--novncproxy_base_url=http://172.17.86.8:6080/vnc_auto.html
--vncserver_proxyclient_address=172.17.86.8
--vncserver_listen=172.17.86.8

Any ideas?

Thanks!
Don

Question information

Language:
English Edit question
Status:
Solved
For:
OpenStack Compute (nova) Edit question
Assignee:
No assignee Edit question
Solved by:
Don Mize
Solved:
Last query:
Last reply:
Revision history for this message
Vish Ishaya (vishvananda) said :
#1

This looks like a libvirt failure. Is it possible that you don't have VT-extensions turned on in the bios on the second node? If it is enabled, you might try restarting libvirt-bin and restarting nova-compute. Also, look for Apparmor denied in syslog

Revision history for this message
Don Mize (donald-mize) said :
#2

VT is enabled, and I don't see anything about apparmor being denied. The syslog output on the second node for the attempt is below.
May 1 10:31:37 xnode9 dnsmasq[29835]: read /etc/hosts - 8 addresses
May 1 10:31:37 xnode9 dnsmasq-dhcp[29835]: read /var/lib/nova/networks/nova-br_6.conf
May 1 10:31:39 xnode9 kernel: [57038.677727] nbd15: unknown partition table
May 1 10:31:39 xnode9 kernel: [57038.733455] kjournald starting. Commit interval 5 seconds
May 1 10:31:39 xnode9 kernel: [57038.919485] EXT3-fs (nbd15): using internal journal
May 1 10:31:39 xnode9 kernel: [57038.919493] EXT3-fs (nbd15): mounted filesystem with ordered data mode
May 1 10:31:40 xnode9 kernel: [57039.860352] block nbd15: NBD_DISCONNECT
May 1 10:31:40 xnode9 kernel: [57039.860587] block nbd15: Receive control failed (result -32)
May 1 10:31:40 xnode9 kernel: [57039.860947] block nbd15: queue cleared
May 1 10:31:42 xnode9 kernel: [57041.662777] type=1400 audit(1335886302.165:29): apparmor="STATUS" operation="profile_load" name="libvirt-a64c1314-1e36-4985-9794-662d890dd646" pid=30414 comm="apparmor_parser"
May 1 10:31:42 xnode9 kernel: [57042.373171] device vnet0 entered promiscuous mode
May 1 10:31:42 xnode9 kernel: [57042.411030] br_6: port 2(vnet0) entering forwarding state
May 1 10:31:42 xnode9 kernel: [57042.411036] br_6: port 2(vnet0) entering forwarding state
May 1 10:31:44 xnode9 kernel: [57043.846926] br_6: port 2(vnet0) entering forwarding state
May 1 10:31:44 xnode9 kernel: [57043.848053] device vnet0 left promiscuous mode
May 1 10:31:44 xnode9 kernel: [57043.848057] br_6: port 2(vnet0) entering disabled state
May 1 10:31:44 xnode9 kernel: [57044.411663] type=1400 audit(1335886304.913:30): apparmor="STATUS" operation="profile_remove" name="libvirt-a64c1314-1e36-4985-9794-662d890dd646" pid=30664 comm="apparmor_parser"
May 1 10:31:45 xnode9 dnsmasq[29835]: read /etc/hosts - 8 addresses
May 1 10:31:45 xnode9 dnsmasq-dhcp[29835]: read /var/lib/nova/networks/nova-br_6.conf
May 1 10:31:45 xnode9 dnsmasq-dhcp[29835]: DHCPRELEASE(br_6) 172.17.87.11 fa:16:3e:68:fe:7f unknown lease

-----Original Message-----
From: <email address hidden> [mailto:<email address hidden>] On Behalf Of Vish Ishaya
Sent: Monday, April 30, 2012 7:16 PM
To: Mize, Donald
Subject: Re: [Question #195465]: ERROR when trying to launch instance on remote node

Your question #195465 on OpenStack Compute (nova) changed:
https://answers.launchpad.net/nova/+question/195465

    Status: Open => Answered

Vish Ishaya proposed the following answer:
This looks like a libvirt failure. Is it possible that you don't have
VT-extensions turned on in the bios on the second node? If it is
enabled, you might try restarting libvirt-bin and restarting nova-
compute. Also, look for Apparmor denied in syslog

--
If this answers your question, please go to the following page to let us
know that it is solved:
https://answers.launchpad.net/nova/+question/195465/+confirm?answer_id=0

If you still need help, you can reply to this email or go to the
following page to enter your feedback:
https://answers.launchpad.net/nova/+question/195465

You received this question notification because you asked the question.

Revision history for this message
Don Mize (donald-mize) said :
#3

I found the issue!!! :-)

On the remote or second node I had this section originally set with the IP of the main node. Once I changed the IPs to that of the remote node, VMs run on the multi-node setup just fine!

# NOVNC CONSOLE
--novncproxy_base_url=http://172.17.86.9:6080/vnc_auto.html
--vncserver_proxyclient_address=172.17.86.9
--vncserver_listen=172.17.86.9

Revision history for this message
Don Mize (donald-mize) said :
#4

I found the issue!!! :-)

On the remote or second node I had this section originally set with the IP of the main node. Once I changed the IPs to that of the remote node, VMs run on the multi-node setup just fine!

# NOVNC CONSOLE
--novncproxy_base_url=http://172.17.86.9:6080/vnc_auto.html
--vncserver_proxyclient_address=172.17.86.9
--vncserver_listen=172.17.86.9

-----Original Message-----
From: <email address hidden> [mailto:<email address hidden>] On Behalf Of Don Mize
Sent: Tuesday, May 01, 2012 10:41 AM
To: Mize, Donald
Subject: Re: [Question #195465]: ERROR when trying to launch instance on remote node

Your question #195465 on OpenStack Compute (nova) changed:
https://answers.launchpad.net/nova/+question/195465

    Status: Answered => Open

You are still having a problem:
VT is enabled, and I don't see anything about apparmor being denied. The syslog output on the second node for the attempt is below.
May 1 10:31:37 xnode9 dnsmasq[29835]: read /etc/hosts - 8 addresses
May 1 10:31:37 xnode9 dnsmasq-dhcp[29835]: read /var/lib/nova/networks/nova-br_6.conf
May 1 10:31:39 xnode9 kernel: [57038.677727] nbd15: unknown partition table
May 1 10:31:39 xnode9 kernel: [57038.733455] kjournald starting. Commit interval 5 seconds
May 1 10:31:39 xnode9 kernel: [57038.919485] EXT3-fs (nbd15): using internal journal
May 1 10:31:39 xnode9 kernel: [57038.919493] EXT3-fs (nbd15): mounted filesystem with ordered data mode
May 1 10:31:40 xnode9 kernel: [57039.860352] block nbd15: NBD_DISCONNECT
May 1 10:31:40 xnode9 kernel: [57039.860587] block nbd15: Receive control failed (result -32)
May 1 10:31:40 xnode9 kernel: [57039.860947] block nbd15: queue cleared
May 1 10:31:42 xnode9 kernel: [57041.662777] type=1400 audit(1335886302.165:29): apparmor="STATUS" operation="profile_load" name="libvirt-a64c1314-1e36-4985-9794-662d890dd646" pid=30414 comm="apparmor_parser"
May 1 10:31:42 xnode9 kernel: [57042.373171] device vnet0 entered promiscuous mode
May 1 10:31:42 xnode9 kernel: [57042.411030] br_6: port 2(vnet0) entering forwarding state
May 1 10:31:42 xnode9 kernel: [57042.411036] br_6: port 2(vnet0) entering forwarding state
May 1 10:31:44 xnode9 kernel: [57043.846926] br_6: port 2(vnet0) entering forwarding state
May 1 10:31:44 xnode9 kernel: [57043.848053] device vnet0 left promiscuous mode
May 1 10:31:44 xnode9 kernel: [57043.848057] br_6: port 2(vnet0) entering disabled state
May 1 10:31:44 xnode9 kernel: [57044.411663] type=1400 audit(1335886304.913:30): apparmor="STATUS" operation="profile_remove" name="libvirt-a64c1314-1e36-4985-9794-662d890dd646" pid=30664 comm="apparmor_parser"
May 1 10:31:45 xnode9 dnsmasq[29835]: read /etc/hosts - 8 addresses
May 1 10:31:45 xnode9 dnsmasq-dhcp[29835]: read /var/lib/nova/networks/nova-br_6.conf
May 1 10:31:45 xnode9 dnsmasq-dhcp[29835]: DHCPRELEASE(br_6) 172.17.87.11 fa:16:3e:68:fe:7f unknown lease

-----Original Message-----
From: <email address hidden> [mailto:<email address hidden>] On Behalf Of Vish Ishaya
Sent: Monday, April 30, 2012 7:16 PM
To: Mize, Donald
Subject: Re: [Question #195465]: ERROR when trying to launch instance on remote node

Your question #195465 on OpenStack Compute (nova) changed:
https://answers.launchpad.net/nova/+question/195465

    Status: Open => Answered

Vish Ishaya proposed the following answer:
This looks like a libvirt failure. Is it possible that you don't have
VT-extensions turned on in the bios on the second node? If it is
enabled, you might try restarting libvirt-bin and restarting nova-
compute. Also, look for Apparmor denied in syslog

--
If this answers your question, please go to the following page to let us
know that it is solved:
https://answers.launchpad.net/nova/+question/195465/+confirm?answer_id=0

If you still need help, you can reply to this email or go to the
following page to enter your feedback:
https://answers.launchpad.net/nova/+question/195465

You received this question notification because you asked the question.

You received this question notification because you asked the question.