yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1531212] [NEW] "Cannot find device" during _create_veth_pair

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Alexis Lee <alexisl@xxxxxx>
Date: Tue, 05 Jan 2016 16:58:39 -0000
Reply-to: Bug 1531212 <1531212@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Public bug reported:

While running Kilo in a scale test, my colleague observed a stack trace
on a compute host which boils down to:

    Cannot find device "qvbcdc5cf8d-ad"

Checking the log, I found:

    CMD "sudo nova-rootwrap /opt/stack/service/nova-compute/etc/nova/rootwrap.conf ip link add qvb59fd2beb-0c type veth peer name qvo59fd2beb-0c" returned: 0 in 0.091s
    CMD "sudo nova-rootwrap /opt/stack/service/nova-compute/etc/nova/rootwrap.conf ip link set qvb59fd2beb-0c up" returned: 1 in 0.092s

There was also a stack trace pointing to line 1357 of
nova/network/linux_net.py, which is in _create_veth_pair. The code here
is very simple: it deletes the devices if they exist, runs `ip link add
...` then `ip link set ...`. The code has not changed since Kilo.

So it seems like either `ip link add ...` should have returned nonzero
and didn't; or another thread (maybe of another process) managed to
delete the devices in between the two commands. Neither seem
particularly likely, 'ip' is presumably pretty robust and the device
names are randomly generated so a collision seems curious.


Full stack trace:

2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup Traceback (most recent call last):
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "nova/openstack/common/threadgroup.py", line 145, in wait
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     x.wait()
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "nova/openstack/common/threadgroup.py", line 47, in wait
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     return self.thread.wait()
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "eventlet/greenthread.py", line 175, in wait
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     return self._exit_event.wait()
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "eventlet/event.py", line 121, in wait
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     return hubs.get_hub().switch()
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "eventlet/hubs/hub.py", line 294, in switch
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     return self.greenlet.switch()
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "eventlet/greenthread.py", line 214, in main
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     result = function(*args, **kwargs)
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "nova/openstack/common/service.py", line 502, in run_service
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     service.start()
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "nova/service.py", line 164, in start
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     self.manager.init_host()
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "nova/compute/manager.py", line 1298, in init_host
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     self._init_instance(context, instance)
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "nova/compute/manager.py", line 1133, in _init_instance
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     self.driver.plug_vifs(instance, net_info)
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "nova/virt/libvirt/driver.py", line 604, in plug_vifs
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     self.vif_driver.plug(instance, vif)
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "nova/virt/libvirt/vif.py", line 609, in plug
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     func(instance, vif)
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "nova/virt/libvirt/vif.py", line 447, in plug_ovs
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     self.plug_ovs_hybrid(instance, vif)
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "nova/virt/libvirt/vif.py", line 443, in plug_ovs_hybrid
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     self._plug_bridge_with_port(instance, vif, port='ovs')
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "nova/virt/libvirt/vif.py", line 424, in _plug_bridge_with_port
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     linux_net._create_veth_pair(v1_name, v2_name)
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "nova/network/linux_net.py", line 1352, in _create_veth_pair
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     utils.execute('ip', 'link', 'set', dev, 'up', run_as_root=True)
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "nova/utils.py", line 207, in execute
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     return processutils.execute(*cmd, **kwargs)
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "oslo_concurrency/processutils.py", line 266, in execute
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     cmd=sanitized_cmd)
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup ProcessExecutionError: Unexpected error while running command.
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup Command: sudo nova-rootwrap /etc/nova/rootwrap.conf ip link set qvb59fd2beb-0c up
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup Exit code: 1
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup Stdout: u''
2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup Stderr: u'Cannot find device "qvb59fd2beb-0c"\n'

** Affects: nova
     Importance: Undecided
         Status: New


** Tags: libvirt network

-- 
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/1531212

Title:
  "Cannot find device" during _create_veth_pair

Status in OpenStack Compute (nova):
  New

Bug description:
  While running Kilo in a scale test, my colleague observed a stack
  trace on a compute host which boils down to:

      Cannot find device "qvbcdc5cf8d-ad"

  Checking the log, I found:

      CMD "sudo nova-rootwrap /opt/stack/service/nova-compute/etc/nova/rootwrap.conf ip link add qvb59fd2beb-0c type veth peer name qvo59fd2beb-0c" returned: 0 in 0.091s
      CMD "sudo nova-rootwrap /opt/stack/service/nova-compute/etc/nova/rootwrap.conf ip link set qvb59fd2beb-0c up" returned: 1 in 0.092s

  There was also a stack trace pointing to line 1357 of
  nova/network/linux_net.py, which is in _create_veth_pair. The code
  here is very simple: it deletes the devices if they exist, runs `ip
  link add ...` then `ip link set ...`. The code has not changed since
  Kilo.

  So it seems like either `ip link add ...` should have returned nonzero
  and didn't; or another thread (maybe of another process) managed to
  delete the devices in between the two commands. Neither seem
  particularly likely, 'ip' is presumably pretty robust and the device
  names are randomly generated so a collision seems curious.

  
  Full stack trace:

  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup Traceback (most recent call last):
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "nova/openstack/common/threadgroup.py", line 145, in wait
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     x.wait()
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "nova/openstack/common/threadgroup.py", line 47, in wait
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     return self.thread.wait()
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "eventlet/greenthread.py", line 175, in wait
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     return self._exit_event.wait()
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "eventlet/event.py", line 121, in wait
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     return hubs.get_hub().switch()
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "eventlet/hubs/hub.py", line 294, in switch
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     return self.greenlet.switch()
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "eventlet/greenthread.py", line 214, in main
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     result = function(*args, **kwargs)
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "nova/openstack/common/service.py", line 502, in run_service
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     service.start()
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "nova/service.py", line 164, in start
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     self.manager.init_host()
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "nova/compute/manager.py", line 1298, in init_host
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     self._init_instance(context, instance)
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "nova/compute/manager.py", line 1133, in _init_instance
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     self.driver.plug_vifs(instance, net_info)
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "nova/virt/libvirt/driver.py", line 604, in plug_vifs
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     self.vif_driver.plug(instance, vif)
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "nova/virt/libvirt/vif.py", line 609, in plug
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     func(instance, vif)
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "nova/virt/libvirt/vif.py", line 447, in plug_ovs
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     self.plug_ovs_hybrid(instance, vif)
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "nova/virt/libvirt/vif.py", line 443, in plug_ovs_hybrid
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     self._plug_bridge_with_port(instance, vif, port='ovs')
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "nova/virt/libvirt/vif.py", line 424, in _plug_bridge_with_port
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     linux_net._create_veth_pair(v1_name, v2_name)
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "nova/network/linux_net.py", line 1352, in _create_veth_pair
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     utils.execute('ip', 'link', 'set', dev, 'up', run_as_root=True)
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "nova/utils.py", line 207, in execute
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     return processutils.execute(*cmd, **kwargs)
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup   File "oslo_concurrency/processutils.py", line 266, in execute
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup     cmd=sanitized_cmd)
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup ProcessExecutionError: Unexpected error while running command.
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup Command: sudo nova-rootwrap /etc/nova/rootwrap.conf ip link set qvb59fd2beb-0c up
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup Exit code: 1
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup Stdout: u''
  2015-12-13 18:34:58.876 1069 TRACE nova.openstack.common.threadgroup Stderr: u'Cannot find device "qvb59fd2beb-0c"\n'

To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1531212/+subscriptions
Follow ups

[Bug 1531212] Re: "Cannot find device" during _create_veth_pair
From: Sean Dague, 2017-07-25