yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1449742] Re: InvalidUUID exception after vifs plug failed

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Thierry Carrez <thierry.carrez+lp@xxxxxxxxx>
Date: Tue, 28 Jul 2015 09:08:23 -0000
Reply-to: Bug 1449742 <1449742@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
** Changed in: nova
       Status: Fix Committed => Fix Released

** Changed in: nova
    Milestone: None => liberty-2

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to OpenStack Compute (nova).
https://bugs.launchpad.net/bugs/1449742

Title:
  InvalidUUID exception after vifs plug failed

Status in OpenStack Compute (nova):
  Fix Released
Status in OpenStack Compute (nova) icehouse series:
  Fix Released
Status in nova package in Ubuntu:
  Fix Released

Bug description:
  An openstack deployment under Ubuntu 14.04 which was upgraded all the
  way from havana. After a recent upgrade of nova-compute from
  2014.1.3-0ubuntu2 to 2014.1.4-0ubuntu2, nova-compute doesn't start
  anymore on one of the compute nodes.

  My guess is that the root cause here is missing data in network_info
  for this particular instance. However, nova-compute should not exit in
  this case.

  2015-04-28 22:25:05.021 10017 AUDIT nova.service [-] Starting compute node (version 2014.1.4)
  2015-04-28 22:25:05.022 10017 DEBUG nova.virt.libvirt.driver [-] Connecting to libvirt: qemu:///system _get_new_connection /usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py:672
  2015-04-28 22:25:05.058 10017 DEBUG nova.virt.libvirt.driver [-] Registering for lifecycle events <nova.virt.libvirt.driver.LibvirtDriver object at 0x7fa1e5978e90> _get_new_connection /usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py:688
  2015-04-28 22:25:05.061 10017 DEBUG nova.virt.libvirt.driver [-] Registering for connection events: <nova.virt.libvirt.driver.LibvirtDriver object at 0x7fa1e5978e90> _get_new_connection /usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py:700
  2015-04-28 22:25:05.079 10017 DEBUG nova.virt.libvirt.config [-] Generated XML ('<cpu>\n  <arch>x86_64</arch>\n  <model>SandyBridge</model>\n  <vendor>Intel</vendor>\n  <topology sockets="1" cores="8" threads="2"/>\n  <feature name="acpi"/>\n  <feature name="dca"/>\n  <feature name="ds"/>\n  <feature name="ds_cpl"/>\n  <feature name="dtes64"/>\n  <feature name="est"/>\n  <feature name="ht"/>\n  <feature name="monitor"/>\n  <feature name="osxsave"/>\n  <feature name="pbe"/>\n  <feature name="pcid"/>\n  <feature name="pdcm"/>\n  <feature name="pdpe1gb"/>\n  <feature name="smx"/>\n  <feature name="ss"/>\n  <feature name="tm"/>\n  <feature name="tm2"/>\n  <feature name="vme"/>\n  <feature name="vmx"/>\n  <feature name="xtpr"/>\n</cpu>\n',)  to_xml /usr/lib/python2.7/dist-packages/nova/virt/libvirt/config.py:71
  2015-04-28 22:25:05.086 10017 DEBUG nova.virt.libvirt.driver [-] Starting native event thread _init_events /usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py:625
  2015-04-28 22:25:05.087 10017 DEBUG nova.virt.libvirt.driver [-] Starting green dispatch thread _init_events /usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py:630
  2015-04-28 22:25:05.290 10017 DEBUG nova.compute.manager [-] [instance: 6c33e4b2-009b-49f3-8b7a-8b1dd5cce344] Checking state _get_power_state /usr/lib/python2.7/dist-packages/nova/compute/manager.py:1088
  2015-04-28 22:25:05.296 10017 DEBUG nova.compute.manager [-] [instance: 6c33e4b2-009b-49f3-8b7a-8b1dd5cce344] Checking state _get_power_state /usr/lib/python2.7/dist-packages/nova/compute/manager.py:1088
  2015-04-28 22:25:05.302 10017 DEBUG nova.virt.libvirt.vif [-] vif_type=ovs instance=<nova.objects.instance.Instance object at 0x7fa1e573b0d0> vif=VIF({'ovs_interfaceid': u'61c90c3f-24fc-4a58-8f6f-a7caf485fe50', 'network': Network({'bridge': u'br-int', 'subnets': [Subnet({'ips': [FixedIP({'meta': {}, 'version': 4, 'type': u'fixed', 'floating_ips': [], 'address': u'10.27.72.8'})], 'version': 4, 'meta': {u'dhcp_server': u'10.27.72.11'}, 'dns': [IP({'meta': {}, 'version': 4, 'type': u'dns', 'address': u'10.26.10.1'}), IP({'meta': {}, 'version': 4, 'type': u'dns', 'address': u'10.27.21.2'})], 'routes': [], 'cidr': u'10.27.72.0/24', 'gateway': IP({'meta': {}, 'version': 4, 'type': u'gateway', 'address': u'10.27.72.1'})})], 'meta': {u'injected': False, u'tenant_id': u'6966cc471a354147901586eed21e4c4e'}, 'id': u'1e5a7f58-a380-4636-9857-4e707e608530', 'label': u'c2c-vlan72'}), 'devname': u'tap61c90c3f-24', 'qbh_params': None, 'meta': {}, 'details': {}, 'address': u'fa:16:3e:a4:d0:75', 'active': True, 'type': u'ovs', 'id': u'61c90c3f-24fc-4a58-8f6f-a7caf485fe50', 'qbg_params': None}) plug /usr/lib/python2.7/dist-packages/nova/virt/libvirt/vif.py:592
  2015-04-28 22:25:05.306 10017 DEBUG nova.compute.manager [-] [instance: 6c33e4b2-009b-49f3-8b7a-8b1dd5cce344] Checking state _get_power_state /usr/lib/python2.7/dist-packages/nova/compute/manager.py:1088
  2015-04-28 22:25:05.313 10017 DEBUG nova.compute.manager [-] [instance: 6c33e4b2-009b-49f3-8b7a-8b1dd5cce344] Current state is 1, state in DB is 1. _init_instance /usr/lib/python2.7/dist-packages/nova/compute/manager.py:966
  2015-04-28 22:25:05.314 10017 DEBUG nova.compute.manager [-] [instance: 08991862-8385-41fa-9ac8-b59dea1e8e61] Checking state _get_power_state /usr/lib/python2.7/dist-packages/nova/compute/manager.py:1088
  2015-04-28 22:25:05.320 10017 DEBUG nova.compute.manager [-] [instance: 08991862-8385-41fa-9ac8-b59dea1e8e61] Checking state _get_power_state /usr/lib/python2.7/dist-packages/nova/compute/manager.py:1088
  2015-04-28 22:25:05.327 10017 DEBUG nova.virt.libvirt.vif [-] vif_type=None instance=<nova.objects.instance.Instance object at 0x7fa1e57bc450> vif=VIF({'ovs_interfaceid': None, 'network': Network({'bridge': None, 'subnets': [Subnet({'ips': [FixedIP({'meta': {}, 'version': 4, 'type': u'fixed', 'floating_ips': [], 'address': u'10.27.71.16'})], 'version': 4, 'meta': {u'dhcp_server': u'10.27.71.23'}, 'dns': [IP({'meta': {}, 'version': 4, 'type': u'dns', 'address': u'10.26.10.1'}), IP({'meta': {}, 'version': 4, 'type': u'dns', 'address': u'10.27.21.2'})], 'routes': [], 'cidr': u'10.27.71.0/24', 'gateway': IP({'meta': {}, 'version': 4, 'type': u'gateway', 'address': u'10.27.71.1'})})], 'meta': {u'injected': False, u'tenant_id': u'445ed83efc894d11963d10be98d6c2ab'}, 'id': u'05bdb9ac-4cbc-467d-b355-269c4b6f9733', 'label': u'c2c-vlan71'}), 'devname': u'tape3e7ac16-33', 'qbh_params': None, 'meta': {}, 'details': {}, 'address': u'fa:16:3e:d8:b7:3d', 'active': True, 'type': None, 'id': u'e3e7ac16-3333-4fd2-a182-0996d2a6a1d1', 'qbg_params': None}) plug /usr/lib/python2.7/dist-packages/nova/virt/libvirt/vif.py:592
  2015-04-28 22:25:05.328 10017 ERROR nova.compute.manager [-] [instance: 08991862-8385-41fa-9ac8-b59dea1e8e61] Vifs plug failed
  2015-04-28 22:25:05.328 10017 TRACE nova.compute.manager [instance: 08991862-8385-41fa-9ac8-b59dea1e8e61] Traceback (most recent call last):
  2015-04-28 22:25:05.328 10017 TRACE nova.compute.manager [instance: 08991862-8385-41fa-9ac8-b59dea1e8e61]   File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 924, in _init_instance
  2015-04-28 22:25:05.328 10017 TRACE nova.compute.manager [instance: 08991862-8385-41fa-9ac8-b59dea1e8e61]     self.driver.plug_vifs(instance, net_info)
  2015-04-28 22:25:05.328 10017 TRACE nova.compute.manager [instance: 08991862-8385-41fa-9ac8-b59dea1e8e61]   File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py", line 861, in plug_vifs
  2015-04-28 22:25:05.328 10017 TRACE nova.compute.manager [instance: 08991862-8385-41fa-9ac8-b59dea1e8e61]     self.vif_driver.plug(instance, vif)
  2015-04-28 22:25:05.328 10017 TRACE nova.compute.manager [instance: 08991862-8385-41fa-9ac8-b59dea1e8e61]   File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/vif.py", line 596, in plug
  2015-04-28 22:25:05.328 10017 TRACE nova.compute.manager [instance: 08991862-8385-41fa-9ac8-b59dea1e8e61]     _("vif_type parameter must be present "
  2015-04-28 22:25:05.328 10017 TRACE nova.compute.manager [instance: 08991862-8385-41fa-9ac8-b59dea1e8e61] VirtualInterfacePlugException: vif_type parameter must be present for this vif_driver implementation
  2015-04-28 22:25:05.328 10017 TRACE nova.compute.manager [instance: 08991862-8385-41fa-9ac8-b59dea1e8e61] 
  2015-04-28 22:25:05.347 10017 ERROR nova.openstack.common.threadgroup [-] <nova.objects.instance.Instance object at 0x7fb928cd1ed0>
  Traceback (most recent call last):

    File "/usr/lib/python2.7/dist-packages/oslo/messaging/rpc/server.py", line 139, in inner
      return func(*args, **kwargs)

    File "/usr/lib/python2.7/dist-packages/nova/conductor/manager.py", line 130, in instance_update
      context, instance_uuid, updates)

    File "/usr/lib/python2.7/dist-packages/nova/db/api.py", line 742, in instance_update_and_get_original
      columns_to_join=columns_to_join)

    File "/usr/lib/python2.7/dist-packages/nova/db/sqlalchemy/api.py", line 164, in wrapper
      return f(*args, **kwargs)

    File "/usr/lib/python2.7/dist-packages/nova/db/sqlalchemy/api.py", line 2216, in instance_update_and_get_original
      columns_to_join=columns_to_join)

    File "/usr/lib/python2.7/dist-packages/nova/db/sqlalchemy/api.py", line 202, in wrapped
      return f(*args, **kwargs)

    File "/usr/lib/python2.7/dist-packages/nova/db/sqlalchemy/api.py", line 2250, in _instance_update
      raise exception.InvalidUUID(instance_uuid)

  InvalidUUID: <nova.objects.instance.Instance object at 0x7fb928cd1ed0>
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup Traceback (most recent call last):
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup   File "/usr/lib/python2.7/dist-packages/nova/openstack/common/threadgroup.py", line 117, in wait
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup     x.wait()
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup   File "/usr/lib/python2.7/dist-packages/nova/openstack/common/threadgroup.py", line 49, in wait
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup     return self.thread.wait()
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup   File "/usr/lib/python2.7/dist-packages/eventlet/greenthread.py", line 168, in wait
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup     return self._exit_event.wait()
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup   File "/usr/lib/python2.7/dist-packages/eventlet/event.py", line 116, in wait
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup     return hubs.get_hub().switch()
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup   File "/usr/lib/python2.7/dist-packages/eventlet/hubs/hub.py", line 187, in switch
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup     return self.greenlet.switch()
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup   File "/usr/lib/python2.7/dist-packages/eventlet/greenthread.py", line 194, in main
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup     result = function(*args, **kwargs)
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup   File "/usr/lib/python2.7/dist-packages/nova/openstack/common/service.py", line 483, in run_service
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup     service.start()
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup   File "/usr/lib/python2.7/dist-packages/nova/service.py", line 163, in start
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup     self.manager.init_host()
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup   File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 1071, in init_host
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup     self._init_instance(context, instance)
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup   File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 930, in _init_instance
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup     self._set_instance_error_state(context, instance)
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup   File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 653, in _set_instance_error_state
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup     vm_state=vm_states.ERROR)
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup   File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 645, in _instance_update
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup     **kwargs)
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup   File "/usr/lib/python2.7/dist-packages/nova/conductor/api.py", line 364, in instance_update
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup     updates, 'conductor')
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup   File "/usr/lib/python2.7/dist-packages/nova/conductor/rpcapi.py", line 161, in instance_update
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup     service=service)
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup   File "/usr/lib/python2.7/dist-packages/oslo/messaging/rpc/client.py", line 150, in call
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup     wait_for_reply=True, timeout=timeout)
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup   File "/usr/lib/python2.7/dist-packages/oslo/messaging/transport.py", line 90, in _send
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup     timeout=timeout)
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup   File "/usr/lib/python2.7/dist-packages/oslo/messaging/_drivers/amqpdriver.py", line 412, in send
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup     return self._send(target, ctxt, message, wait_for_reply, timeout)
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup   File "/usr/lib/python2.7/dist-packages/oslo/messaging/_drivers/amqpdriver.py", line 405, in _send
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup     raise result
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup InvalidUUID_Remote: <nova.objects.instance.Instance object at 0x7fb928cd1ed0>
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup Traceback (most recent call last):
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup 
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup   File "/usr/lib/python2.7/dist-packages/oslo/messaging/rpc/server.py", line 139, in inner
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup     return func(*args, **kwargs)
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup 
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup   File "/usr/lib/python2.7/dist-packages/nova/conductor/manager.py", line 130, in instance_update
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup     context, instance_uuid, updates)
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup 
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup   File "/usr/lib/python2.7/dist-packages/nova/db/api.py", line 742, in instance_update_and_get_original
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup     columns_to_join=columns_to_join)
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup 
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup   File "/usr/lib/python2.7/dist-packages/nova/db/sqlalchemy/api.py", line 164, in wrapper
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup     return f(*args, **kwargs)
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup 
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup   File "/usr/lib/python2.7/dist-packages/nova/db/sqlalchemy/api.py", line 2216, in instance_update_and_get_original
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup     columns_to_join=columns_to_join)
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup 
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup   File "/usr/lib/python2.7/dist-packages/nova/db/sqlalchemy/api.py", line 202, in wrapped
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup     return f(*args, **kwargs)
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup 
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup   File "/usr/lib/python2.7/dist-packages/nova/db/sqlalchemy/api.py", line 2250, in _instance_update
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup     raise exception.InvalidUUID(instance_uuid)
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup 
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup InvalidUUID: <nova.objects.instance.Instance object at 0x7fb928cd1ed0>
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup 
  2015-04-28 22:25:05.347 10017 TRACE nova.openstack.common.threadgroup

To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1449742/+subscriptions
References

[Bug 1449742] [NEW] InvalidUUID exception after vifs plug failed
From: Francois Deppierraz, 2015-04-28