yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1357476] Re: Timeout waiting for vif plugging callback for instance

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Adam Gandelman <1357476@xxxxxxxxxxxxxxxxxx>
Date: Mon, 29 Sep 2014 19:59:15 -0000
Reply-to: Bug 1357476 <1357476@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
** Also affects: nova/icehouse
   Importance: Undecided
       Status: New

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to neutron.
https://bugs.launchpad.net/bugs/1357476

Title:
  Timeout waiting for vif plugging callback for instance

Status in OpenStack Neutron (virtual network service):
  Confirmed
Status in OpenStack Compute (Nova):
  Confirmed
Status in OpenStack Compute (nova) icehouse series:
  New

Bug description:
  n-cpu times out while waiting for neutron.

  
  Logstash
  ========
  http://logstash.openstack.org/#eyJzZWFyY2giOiIgbWVzc2FnZTogXCJUaW1lb3V0IHdhaXRpbmcgZm9yIHZpZiBwbHVnZ2luZyBjYWxsYmFjayBmb3IgaW5zdGFuY2VcIiBBTkQgdGFnczpcInNjcmVlbi1uLWNwdS50eHRcIiIsImZpZWxkcyI6W10sIm9mZnNldCI6MCwidGltZWZyYW1lIjoiNjA0ODAwIiwiZ3JhcGhtb2RlIjoiY291bnQiLCJ0aW1lIjp7InVzZXJfaW50ZXJ2YWwiOjB9LCJzdGFtcCI6MTQwODEyMjI1NjY2NiwibW9kZSI6IiIsImFuYWx5emVfZmllbGQiOiIifQ==

  message: "Timeout waiting for vif plugging callback for instance" AND
  tags:"screen-n-cpu.txt"

  
  Logs
  ++++
  http://logs.openstack.org/09/108909/4/gate/check-tempest-dsvm-neutron-full/628138b/logs/screen-n-cpu.txt.gz#_2014-08-13_21_14_53_453

  2014-08-13 21:14:53.453 WARNING nova.virt.libvirt.driver [req-
  0974eac5-f261-472e-a2c3-f96514e4131c ServerActionsTestXML-650848250
  ServerActionsTestXML-1011304525] Timeout waiting for vif plugging
  callback for instance 794ceb8c-a08b-4b02-bdcb-4ad5632f7744

  2014-08-13 21:14:55.408 ERROR nova.compute.manager [req-0974eac5-f261-472e-a2c3-f96514e4131c ServerActionsTestXML-650848250 ServerActionsTestXML-1011304525] [instance: 794ceb8c-a08b-4b02-bdcb-4ad5632f7744] Setting instance vm_state to ERROR
  2014-08-13 21:14:55.408 29002 TRACE nova.compute.manager [instance: 794ceb8c-a08b-4b02-bdcb-4ad5632f7744] Traceback (most recent call last):
  2014-08-13 21:14:55.408 29002 TRACE nova.compute.manager [instance: 794ceb8c-a08b-4b02-bdcb-4ad5632f7744]   File "/opt/stack/new/nova/nova/compute/manager.py", line 3714, in finish_resize
  2014-08-13 21:14:55.408 29002 TRACE nova.compute.manager [instance: 794ceb8c-a08b-4b02-bdcb-4ad5632f7744]     disk_info, image)
  2014-08-13 21:14:55.408 29002 TRACE nova.compute.manager [instance: 794ceb8c-a08b-4b02-bdcb-4ad5632f7744]   File "/opt/stack/new/nova/nova/compute/manager.py", line 3682, in _finish_resize
  2014-08-13 21:14:55.408 29002 TRACE nova.compute.manager [instance: 794ceb8c-a08b-4b02-bdcb-4ad5632f7744]     old_instance_type, sys_meta)
  2014-08-13 21:14:55.408 29002 TRACE nova.compute.manager [instance: 794ceb8c-a08b-4b02-bdcb-4ad5632f7744]   File "/opt/stack/new/nova/nova/openstack/common/excutils.py", line 82, in __exit__
  2014-08-13 21:14:55.408 29002 TRACE nova.compute.manager [instance: 794ceb8c-a08b-4b02-bdcb-4ad5632f7744]     six.reraise(self.type_, self.value, self.tb)
  2014-08-13 21:14:55.408 29002 TRACE nova.compute.manager [instance: 794ceb8c-a08b-4b02-bdcb-4ad5632f7744]   File "/opt/stack/new/nova/nova/compute/manager.py", line 3677, in _finish_resize
  2014-08-13 21:14:55.408 29002 TRACE nova.compute.manager [instance: 794ceb8c-a08b-4b02-bdcb-4ad5632f7744]     block_device_info, power_on)
  2014-08-13 21:14:55.408 29002 TRACE nova.compute.manager [instance: 794ceb8c-a08b-4b02-bdcb-4ad5632f7744]   File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 5302, in finish_migration
  2014-08-13 21:14:55.408 29002 TRACE nova.compute.manager [instance: 794ceb8c-a08b-4b02-bdcb-4ad5632f7744]     block_device_info, power_on)
  2014-08-13 21:14:55.408 29002 TRACE nova.compute.manager [instance: 794ceb8c-a08b-4b02-bdcb-4ad5632f7744]   File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 3792, in _create_domain_and_network
  2014-08-13 21:14:55.408 29002 TRACE nova.compute.manager [instance: 794ceb8c-a08b-4b02-bdcb-4ad5632f7744]     raise exception.VirtualInterfaceCreateException()
  2014-08-13 21:14:55.408 29002 TRACE nova.compute.manager [instance: 794ceb8c-a08b-4b02-bdcb-4ad5632f7744] VirtualInterfaceCreateException: Virtual Interface creation failed
  2014-08-13 21:14:55.408 29002 TRACE nova.compute.manager [instance: 794ceb8c-a08b-4b02-bdcb-4ad5632f7744] 

  2014-08-13 21:14:56.138 ERROR oslo.messaging.rpc.dispatcher [req-0974eac5-f261-472e-a2c3-f96514e4131c ServerActionsTestXML-650848250 ServerActionsTestXML-1011304525] Exception during message handling: Virtual Interface creation failed
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher Traceback (most recent call last):
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher   File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 134, in _dispatch_and_reply
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher     incoming.message))
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher   File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 177, in _dispatch
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher     return self._do_dispatch(endpoint, method, ctxt, args)
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher   File "/usr/local/lib/python2.7/dist-packages/oslo/messaging/rpc/dispatcher.py", line 123, in _do_dispatch
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher     result = getattr(endpoint, method)(ctxt, **new_args)
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/new/nova/nova/exception.py", line 88, in wrapped
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher     payload)
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/new/nova/nova/openstack/common/excutils.py", line 82, in __exit__
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher     six.reraise(self.type_, self.value, self.tb)
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/new/nova/nova/exception.py", line 71, in wrapped
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher     return f(self, context, *args, **kw)
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/new/nova/nova/compute/manager.py", line 292, in decorated_function
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher     pass
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/new/nova/nova/openstack/common/excutils.py", line 82, in __exit__
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher     six.reraise(self.type_, self.value, self.tb)
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/new/nova/nova/compute/manager.py", line 278, in decorated_function
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher     return function(self, context, *args, **kwargs)
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/new/nova/nova/compute/manager.py", line 342, in decorated_function
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher     return function(self, context, *args, **kwargs)
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/new/nova/nova/compute/manager.py", line 266, in decorated_function
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher     migration.instance_uuid, exc_info=True)
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/new/nova/nova/openstack/common/excutils.py", line 82, in __exit__
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher     six.reraise(self.type_, self.value, self.tb)
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/new/nova/nova/compute/manager.py", line 253, in decorated_function
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher     return function(self, context, *args, **kwargs)
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/new/nova/nova/compute/manager.py", line 320, in decorated_function
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher     kwargs['instance'], e, sys.exc_info())
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/new/nova/nova/openstack/common/excutils.py", line 82, in __exit__
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher     six.reraise(self.type_, self.value, self.tb)
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/new/nova/nova/compute/manager.py", line 308, in decorated_function
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher     return function(self, context, *args, **kwargs)
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/new/nova/nova/compute/manager.py", line 3726, in finish_resize
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher     self._set_instance_error_state(context, instance)
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/new/nova/nova/openstack/common/excutils.py", line 82, in __exit__
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher     six.reraise(self.type_, self.value, self.tb)
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/new/nova/nova/compute/manager.py", line 3714, in finish_resize
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher     disk_info, image)
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/new/nova/nova/compute/manager.py", line 3682, in _finish_resize
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher     old_instance_type, sys_meta)
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/new/nova/nova/openstack/common/excutils.py", line 82, in __exit__
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher     six.reraise(self.type_, self.value, self.tb)
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/new/nova/nova/compute/manager.py", line 3677, in _finish_resize
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher     block_device_info, power_on)
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 5302, in finish_migration
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher     block_device_info, power_on)
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher   File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 3792, in _create_domain_and_network
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher     raise exception.VirtualInterfaceCreateException()
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher VirtualInterfaceCreateException: Virtual Interface creation failed
  2014-08-13 21:14:56.138 29002 TRACE oslo.messaging.rpc.dispatcher

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

[Bug 1357476] [NEW] Timeout waiting for vif plugging callback for instance
From: Attila Fazekas, 2014-08-15