xenstore.py inadequate exception handling

Bug #769096 reported by Armando Migliaccio
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
OpenStack Compute (nova)
Fix Released
Medium
Johannes Erdfelt

Bug Description

Revision 989 (Cactus).

I have got an exception during the launch of an instance. I get the following stacktrace in nova-compute.log:

2011-04-21 22:47:12,887 DEBUG nova [-] injecting network info to xs for vm: |OpaqueRef:31c1cdee-b215-470a-8a93-07599fb4ab28| from (pid=2349) _inject_network_info /usr/lib/python2.6/site-packages/nova/virt/xenapi/vmops.py:859
2011-04-21 22:47:13,606 WARNING nova.virt.xenapi [-] Task [Async.host.call_plugin] OpaqueRef:6897e357-a275-828b-fe22-74ffe95df056 status: failure ['XENAPI_PLUGIN_FAILURE', 'non-zero exit', '', '']
2011-04-21 22:47:13,612 ERROR nova.compute.manager [58X1QE5AKBX4UWIBNJRX dashboard dashboard] Instance '1' failed to spawn. Is virtualization enabled in the BIOS?
(nova.compute.manager): TRACE: Traceback (most recent call last):
(nova.compute.manager): TRACE: File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 234, in run_instance
(nova.compute.manager): TRACE: self.driver.spawn(instance_ref)
(nova.compute.manager): TRACE: File "/usr/lib/python2.6/site-packages/nova/virt/xenapi_conn.py", line 188, in spawn
(nova.compute.manager): TRACE: self._vmops.spawn(instance)
(nova.compute.manager): TRACE: File "/usr/lib/python2.6/site-packages/nova/virt/xenapi/vmops.py", line 118, in spawn
(nova.compute.manager): TRACE: vm_ref = self._create_vm(instance, vdi_uuid, network_info)
(nova.compute.manager): TRACE: File "/usr/lib/python2.6/site-packages/nova/virt/xenapi/vmops.py", line 179, in _create_vm
(nova.compute.manager): TRACE: self.inject_network_info(instance, network_info, vm_ref)
(nova.compute.manager): TRACE: File "/usr/lib/python2.6/site-packages/nova/virt/xenapi/vmops.py", line 850, in inject_network_info
(nova.compute.manager): TRACE: self._inject_network_info(instance, network_info, vm_ref)
(nova.compute.manager): TRACE: File "/usr/lib/python2.6/site-packages/nova/virt/xenapi/vmops.py", line 875, in _inject_network_info
(nova.compute.manager): TRACE: vm_ref)
(nova.compute.manager): TRACE: File "/usr/lib/python2.6/site-packages/nova/virt/xenapi/vmops.py", line 977, in _make_plugin_call
(nova.compute.manager): TRACE: err_msg = err_trace.splitlines()[-1]
(nova.compute.manager): TRACE: IndexError: list index out of range
(nova.compute.manager): TRACE:

Two points here:

1) "Instance '1' failed to spawn. Is virtualization enabled in the BIOS?" as error message is misleading and does not really a clue of what's going on
2) There's an unhandled exception within the catch block in vmops.py:977

As for /var/log/messages on the host, I get:

Apr 22 03:00:39 localhost fe: 20110422T03:00:39.664Z||5861|Args after replacement = [/etc/xapi.d/plugins/xenstore.py;<methodCall><methodName>write_record</methodName><params><param><value>OpaqueRef:8985f82c-2c1a-bf2f-d452-8d19b2589b3e</value></param><param><value><struct><member><name>path</name><value>vm-data/networking/02163e0e00b9</value></member><member><name>dom_id</name><value>-1</value></member><member><name>value</name><value>{&quot;label&quot;: &quot;public&quot;, &quot;broadcast&quot;: &quot;10.0.0.31&quot;, &quot;ips&quot;: [{&quot;ip&quot;: &quot;10.0.0.2&quot;, &quot;netmask&quot;: &quot;255.255.255.224&quot;, &quot;enabled&quot;: &quot;1&quot;}], &quot;mac&quot;: &quot;02:16:3e:0e:00:b9&quot;, &quot;dns&quot;: [&quot;192.168.1.1&quot;], &quot;gateway&quot;: &quot;10.0.0.1&quot;}</value></member></struct></value></param></params></methodCall>]
Apr 22 03:00:39 localhost fe: 20110422T03:00:39.664Z||5861|I've received the following fds: [2;1]
Apr 22 03:00:39 localhost fe: 20110422T03:00:39.666Z||5862|Caught unexpected exception: Unix.Unix_error(1, "execve", "/etc/xapi.d/plugins/xenstore.py")
Apr 22 03:00:39 localhost fe: 5862 (/etc/xapi.d/plugins/xenstore.py <methodCall><methodName>write_record</methodN...) exitted with code 1

No exception handling, that let us get a clue of what's going on.

Any idea of what might have gone wrong?
Thanks,
Armando

summary: - xenstore.py inadequate exception
+ xenstore.py inadequate exception handling
Revision history for this message
Armando Migliaccio (armando-migliaccio) wrote :

The root of the problem is with the fact that xenstore.py was not executable.

Revision history for this message
Thierry Carrez (ttx) wrote :

So is that a packaging issue ?

Changed in nova:
status: New → Incomplete
Revision history for this message
Armando Migliaccio (armando-migliaccio) wrote :

Thierry,

apart from the fact that xenstore.py was not executable (which, as you said it's a packaging problem), I see two problems here:

1) 'Is virtualization enabled in the BIOS?' error message does give misleading information (in my case it wasn't related to the BIOS at all, and it took me a while to figure out what was going on).
2) There's an unhandled exception within the catch block in vmops.py:977, which means that the catch block raises an exception because of a bug in dealing with this line:

(nova.compute.manager): TRACE: err_msg = err_trace.splitlines()[-1]

Changed in nova:
status: Incomplete → New
Revision history for this message
Thierry Carrez (ttx) wrote :

@Armando: could you raise a separate bug against the Ubuntu packaging explaining that xenstore.py should be executable (and why) ? Follow https://bugs.launchpad.net/ubuntu/+source/nova/+filebug

Changed in nova:
importance: Undecided → Medium
status: New → Confirmed
Revision history for this message
Armando Migliaccio (armando-migliaccio) wrote :

Thierry,

I am not very familiar with the Nova/Ubuntu packaging, but I believe that this is not a packaging problem specific to Nova/Ubuntu, but rather a packaging problem that one can experience when plugin files are to be packaged/installed on a XenServer/XCP host.

By the way, the url you specified above seems to be invalid.

Hope this help!
Thanks,
Armando

Revision history for this message
Thierry Carrez (ttx) wrote :

Then we can open bug tasks against all the packaging downstreams... My point is that it's not something that can be fixed in nova code, hence the need for a separate bug to track it. The link works for me... If all else fails try clicking "Report a bug" on:

https://bugs.launchpad.net/ubuntu/+source/nova

Revision history for this message
Johannes Erdfelt (johannes.erdfelt) wrote :

FWIW, the permissions in the tree made stumbling upon this bug fairly easy. I got a change merged a couple of months ago to fix the permissions and make it harder to stumble upon it.

http://bazaar.launchpad.net/~nova-core/nova/github/revision/1287

That said, this bug probably should be closed. Any other problems are probably packaging problems.

Revision history for this message
Johannes Erdfelt (johannes.erdfelt) wrote :

I'll just close this out now since my change to fix the permissions in the tree has been merged for a few months.

Changed in nova:
status: Confirmed → Fix Committed
Thierry Carrez (ttx)
Changed in nova:
milestone: none → essex-1
Thierry Carrez (ttx)
Changed in nova:
status: Fix Committed → Fix Released
Mark McLoughlin (markmc)
Changed in nova:
assignee: nobody → Johannes Erdfelt (johannes.erdfelt)
Thierry Carrez (ttx)
Changed in nova:
milestone: essex-1 → 2012.1
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

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