OpenStack Compute (nova)

check-grenade-dsvm-partial-ncpu breaks on libguestfs

Bug #1287354 reported by Joe Gordon
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
OpenStack Compute (nova)
Opinion
Undecided
Unassigned
OpenStack Compute (nova) next
devstack
Invalid
Undecided
Unassigned

Bug Description

http://logs.openstack.org/65/41265/40/check/check-grenade-dsvm-partial-ncpu/5db5bcf/logs/old/screen-n-cpu.txt.gz?level=AUDIT

http://logs.openstack.org/65/41265/40/check/check-grenade-dsvm-partial-ncpu/5db5bcf/

http://logs.openstack.org/65/41265/40/check/check-grenade-dsvm-partial-ncpu/5db5bcf/logs/testr_results.html.gz

2014-03-03 18:35:59.215 6130 TRACE nova.servicegroup.drivers.db exc.info, real_topic, msg.get('method'))
2014-03-03 18:35:59.215 6130 TRACE nova.servicegroup.drivers.db Timeout: Timeout while waiting on RPC response - topic: "conductor", RPC method: "service_update" info: "<unknown>"
2014-03-03 18:35:59.215 6130 TRACE nova.servicegroup.drivers.db
2014-03-03 18:35:59.216 6130 WARNING nova.openstack.common.loopingcall [-] task run outlasted interval by 50.01159 sec
2014-03-03 18:36:38.563 6130 ERROR nova.openstack.common.periodic_task [-] Error during ComputeManager.update_available_resource: Timeout while waiting on RPC response - topic: "conductor", RPC method: "object_class_action" info: "<unknown>"
2014-03-03 18:36:38.563 6130 TRACE nova.openstack.common.periodic_task Traceback (most recent call last):
2014-03-03 18:36:38.563 6130 TRACE nova.openstack.common.periodic_task File "/opt/stack/old/nova/nova/openstack/common/periodic_task.py", line 180, in run_periodic_tasks
2014-03-03 18:36:38.563 6130 TRACE nova.openstack.common.periodic_task task(self, context)
2014-03-03 18:36:38.563 6130 TRACE nova.openstack.common.periodic_task File "/opt/stack/old/nova/nova/compute/manager.py", line 4881, in update_available_resource
2014-03-03 18:36:38.563 6130 TRACE nova.openstack.common.periodic_task rt.update_available_resource(context)
2014-03-03 18:36:38.563 6130 TRACE nova.openstack.common.periodic_task File "/opt/stack/old/nova/nova/openstack/common/lockutils.py", line 246, in inner
2014-03-03 18:36:38.563 6130 TRACE nova.openstack.common.periodic_task return f(*args, **kwargs)
2014-03-03 18:36:38.563 6130 TRACE nova.openstack.common.periodic_task File "/opt/stack/old/nova/nova/compute/resource_tracker.py", line 296, in update_available_resource
2014-03-03 18:36:38.563 6130 TRACE nova.openstack.common.periodic_task context, self.host, self.nodename)
2014-03-03 18:36:38.563 6130 TRACE nova.openstack.common.periodic_task File "/opt/stack/old/nova/nova/objects/base.py", line 106, in wrapper
2014-03-03 18:36:38.563 6130 TRACE nova.openstack.common.periodic_task args, kwargs)
2014-03-03 18:36:38.563 6130 TRACE nova.openstack.common.periodic_task File "/opt/stack/old/nova/nova/conductor/rpcapi.py", line 492, in object_class_action
2014-03-03 18:36:38.563 6130 TRACE nova.openstack.common.periodic_task objver=objver, args=args, kwargs=kwargs)
2014-03-03 18:36:38.563 6130 TRACE nova.openstack.common.periodic_task File "/opt/stack/old/nova/nova/rpcclient.py", line 85, in call
2014-03-03 18:36:38.563 6130 TRACE nova.openstack.common.periodic_task return self._invoke(self.proxy.call, ctxt, method, **kwargs)
2014-03-03 18:36:38.563 6130 TRACE nova.openstack.common.periodic_task File "/opt/stack/old/nova/nova/rpcclient.py", line 63, in _invoke
2014-03-03 18:36:38.563 6130 TRACE nova.openstack.common.periodic_task return cast_or_call(ctxt, msg, **self.kwargs)
2014-03-03 18:36:38.563 6130 TRACE nova.openstack.common.periodic_task File "/opt/stack/old/nova/nova/openstack/common/rpc/proxy.py", line 130, in call
2014-03-03 18:36:38.563 6130 TRACE nova.openstack.common.periodic_task exc.info, real_topic, msg.get('method'))
2014-03-03 18:36:38.563 6130 TRACE nova.openstack.common.periodic_task Timeout: Timeout while waiting on RPC response - topic: "conductor", RPC method: "object_class_action" info: "<unknown>"
2014-03-03 18:36:38.563 6130 TRACE nova.openstack.common.periodic_task

Joe Gordon (jogo)
Changed in nova:
milestone: none → icehouse-rc1
Joe Gordon (jogo)
Changed in nova:
milestone: icehouse-rc1 → icehouse-3
Thierry Carrez (ttx)
Changed in nova:
milestone: icehouse-3 → icehouse-rc1
Revision history for this message
Joe Gordon (jogo) wrote :
Download full text (3.3 KiB)

It turns out the waiting for waiting for conductor is when the conductor is being upgraded.

The real bug was file injection was enabled by default in havana. It would silently error out when libguestfs isn't installed (as its not in in havana). but when we upgrade libguestfs get installed and nova dynamically loads it.

2014-03-03 18:41:39.708 ERROR nova.virt.libvirt.driver [req-fc92fbbf-acd4-40a5-8d74-a8bdd263c297 ServersTestManualDisk-834103425 ServersTestManualDisk-1514739295] [instance: a9a923e6-5748-465e-8ad3-84077b15447e] Error injecting data into image cf82ca56-7fda-4e29-ae75-96be49f2a059 (Error mounting /opt/stack/data/nova/instances/a9a923e6-5748-465e-8ad3-84077b15447e/disk with libguestfs (external command failed, see earlier error messages))
2014-03-03 18:41:39.709 ERROR nova.compute.manager [req-fc92fbbf-acd4-40a5-8d74-a8bdd263c297 ServersTestManualDisk-834103425 ServersTestManualDisk-1514739295] [instance: a9a923e6-5748-465e-8ad3-84077b15447e] Instance failed to spawn
2014-03-03 18:41:39.709 6130 TRACE nova.compute.manager [instance: a9a923e6-5748-465e-8ad3-84077b15447e] Traceback (most recent call last):
2014-03-03 18:41:39.709 6130 TRACE nova.compute.manager [instance: a9a923e6-5748-465e-8ad3-84077b15447e] File "/opt/stack/old/nova/nova/compute/manager.py", line 1423, in _spawn
2014-03-03 18:41:39.709 6130 TRACE nova.compute.manager [instance: a9a923e6-5748-465e-8ad3-84077b15447e] block_device_info)
2014-03-03 18:41:39.709 6130 TRACE nova.compute.manager [instance: a9a923e6-5748-465e-8ad3-84077b15447e] File "/opt/stack/old/nova/nova/virt/libvirt/driver.py", line 2084, in spawn
2014-03-03 18:41:39.709 6130 TRACE nova.compute.manager [instance: a9a923e6-5748-465e-8ad3-84077b15447e] admin_pass=admin_password)
2014-03-03 18:41:39.709 6130 TRACE nova.compute.manager [instance: a9a923e6-5748-465e-8ad3-84077b15447e] File "/opt/stack/old/nova/nova/virt/libvirt/driver.py", line 2514, in _create_image
2014-03-03 18:41:39.709 6130 TRACE nova.compute.manager [instance: a9a923e6-5748-465e-8ad3-84077b15447e] instance=instance)
2014-03-03 18:41:39.709 6130 TRACE nova.compute.manager [instance: a9a923e6-5748-465e-8ad3-84077b15447e] File "/opt/stack/old/nova/nova/virt/libvirt/driver.py", line 2508, in _create_image
2014-03-03 18:41:39.709 6130 TRACE nova.compute.manager [instance: a9a923e6-5748-465e-8ad3-84077b15447e] mandatory=('files',))
2014-03-03 18:41:39.709 6130 TRACE nova.compute.manager [instance: a9a923e6-5748-465e-8ad3-84077b15447e] File "/opt/stack/old/nova/nova/virt/disk/api.py", line 329, in inject_data
2014-03-03 18:41:39.709 6130 TRACE nova.compute.manager [instance: a9a923e6-5748-465e-8ad3-84077b15447e] fs.setup()
2014-03-03 18:41:39.709 6130 TRACE nova.compute.manager [instance: a9a923e6-5748-465e-8ad3-84077b15447e] File "/opt/stack/old/nova/nova/virt/disk/vfs/guestfs.py", line 129, in setup
2014-03-03 18:41:39.709 6130 TRACE nova.compute.manager [instance: a9a923e6-5748-465e-8ad3-84077b15447e] {'imgfile': self.imgfile, 'e': e})
2014-03-03 18:41:39.709 6130 TRACE nova.compute.manager [instance: a9a923e6-5748-465e-8ad3-84077b15447e] NovaException: Error mounting /opt/stack/data/nova/instan...

Read more...

Joe Gordon (jogo)
summary: - check-grenade-dsvm-partial-ncpu breaks waiting while waiting for
- conductor
+ check-grenade-dsvm-partial-ncpu breaks on libguestfs
Tracy Jones (tjones-i)
tags: added: testing
Tracy Jones (tjones-i)
Changed in nova:
milestone: icehouse-rc1 → next
tags: added: icehouse-rc-potential
Revision history for this message
Joe Gordon (jogo) wrote :

Fixed in https://review.openstack.org/#/c/78828/

Changed in nova:
status: New → Fix Committed
importance: Undecided → Medium
Changed in devstack:
status: New → Fix Committed
Changed in nova:
status: Fix Committed → Opinion
importance: Medium → Undecided
Thierry Carrez (ttx)
tags: added: icehouse-backport-potential
removed: icehouse-rc-potential
Revision history for this message
Sean Dague (sdague) wrote :

This devstack bug was last updated over 180 days ago, as devstack
is a fast moving project and we'd like to get the tracker down to
currently actionable bugs, this is getting marked as Invalid. If the
issue still exists, please feel free to reopen it.

Changed in devstack:
status: Fix Committed → Invalid
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.
Subscribing...

Other bug subscribers

Remote bug watches

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