yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1530847] Re: TypeError attaching volume to instance

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Matt Riedemann <mriedem@xxxxxxxxxx>
Date: Wed, 06 Jan 2016 20:09:45 -0000
Reply-to: Bug 1530847 <1530847@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
I'm noticing that shortly before this fails, there are a lot of iscsiadm
sessions:

http://logs.openstack.org/64/263664/5/check/gate-manila-tempest-dsvm-
neutron/835bf51/logs/screen-n-cpu.txt.gz#_2016-01-06_14_05_11_976

I'm also seeing a bunch of this in the n-cpu logs:

2016-01-06 14:05:11.495 DEBUG nova.virt.libvirt.driver [req-a08d2d27
-328a-4da6-b852-66c78ea505ce None None] skipping disk /dev/disk/by-
path/ip-158.69.74.121:3260-iscsi-iqn.2010-10.org.openstack:volume-
f1b24b44-cd61-4050-982a-22c191cabd0f-lun-1 (vdb) - unable to determine
if volume _get_instance_disk_info
/opt/stack/new/nova/nova/virt/libvirt/driver.py:6551

I noticed it in the libvirtd logs first, but if you look at the n-cpu
logs, os-attach is called many times (so many that we exhaust the
devices to use).

But os-detach is only called twice:

http://logs.openstack.org/64/263664/5/check/gate-manila-tempest-dsvm-
neutron/835bf51/logs/screen-n-cpu.txt.gz#_2016-01-06_13_58_01_522

And here:

http://logs.openstack.org/64/263664/5/check/gate-manila-tempest-dsvm-
neutron/835bf51/logs/screen-n-cpu.txt.gz#_2016-01-06_14_13_13_062

So the devices aren't getting detached.

It looks like the tests are never calling detach besides those 2 times,
but keep doing attach, and eventually that blows up.

So I'm thinking this is some issue with the way the manila job/tests are
configured with tempest and running in parallel without tenant
isolation, and they aren't doing the detach as expected.


** Changed in: nova
       Status: In Progress => Invalid

** Also affects: manila
   Importance: Undecided
       Status: New

** Summary changed:

- TypeError attaching volume to instance
+ Gate jobs are not detaching volumes and eventually fail with no devices left

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

Title:
  Gate jobs are not detaching volumes and eventually fail with no
  devices left

Status in Manila:
  New
Status in OpenStack Compute (nova):
  Invalid

Bug description:
  Manila project has been facing following error since "2016, january 3,
  ~16:00+" of ZUUL's timezone:

  Paste: http://paste.openstack.org/show/482932/

  Logs: http://logs.openstack.org/07/263207/1/check/gate-manila-tempest-
  dsvm-neutron-no-share-servers-
  multibackend/6717bb8/logs/screen-n-api.txt.gz?level=TRACE#_2016-01-04_11_47_11_087

  Raw:
  2016-01-04 11:47:11.087 ERROR nova.api.openstack.extensions [req-d3ea820b-5b7e-4174-aa92-60b5d6283ee9 nova service] Unexpected exception in API method
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions Traceback (most recent call last):
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions   File "/opt/stack/new/nova/nova/api/openstack/extensions.py", line 478, in wrapped
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions     return f(*args, **kwargs)
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions   File "/opt/stack/new/nova/nova/api/validation/__init__.py", line 73, in wrapper
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions     return func(*args, **kwargs)
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions   File "/opt/stack/new/nova/nova/api/openstack/compute/volumes.py", line 283, in create
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions     volume_id, device)
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions   File "/opt/stack/new/nova/nova/compute/api.py", line 235, in wrapped
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions     return func(self, context, target, *args, **kwargs)
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions   File "/opt/stack/new/nova/nova/compute/api.py", line 224, in inner
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions     return function(self, context, instance, *args, **kwargs)
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions   File "/opt/stack/new/nova/nova/compute/api.py", line 205, in inner
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions     return f(self, context, instance, *args, **kw)
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions   File "/opt/stack/new/nova/nova/compute/api.py", line 3082, in attach_volume
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions     disk_bus, device_type)
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions   File "/opt/stack/new/nova/nova/compute/api.py", line 3055, in _attach_volume
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions     device_type=device_type)
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions   File "/opt/stack/new/nova/nova/compute/rpcapi.py", line 813, in reserve_block_device_name
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions     volume_bdm = cctxt.call(ctxt, 'reserve_block_device_name', **kw)
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/client.py", line 158, in call
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions     retry=self.retry)
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/transport.py", line 90, in _send
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions     timeout=timeout, retry=retry)
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py", line 464, in send
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions     retry=retry)
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py", line 455, in _send
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions     raise result
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions TypeError: __init__() takes at most 2 arguments (3 given)
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions Traceback (most recent call last):
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 143, in _dispatch_and_reply
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions     executor_callback))
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 189, in _dispatch
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions     executor_callback)
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions   File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 130, in _do_dispatch
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions     result = func(ctxt, **new_args)
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions   File "/opt/stack/new/nova/nova/exception.py", line 110, in wrapped
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions     payload)
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions   File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 204, in __exit__
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions     six.reraise(self.type_, self.value, self.tb)
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions   File "/opt/stack/new/nova/nova/exception.py", line 89, in wrapped
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions     return f(self, context, *args, **kw)
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions   File "/opt/stack/new/nova/nova/compute/manager.py", line 355, in decorated_function
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions     LOG.warning(msg, e, instance=instance)
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions   File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 204, in __exit__
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions     six.reraise(self.type_, self.value, self.tb)
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions   File "/opt/stack/new/nova/nova/compute/manager.py", line 328, in decorated_function
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions     return function(self, context, *args, **kwargs)
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions   File "/opt/stack/new/nova/nova/compute/manager.py", line 383, in decorated_function
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions     kwargs['instance'], e, sys.exc_info())
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions   File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 204, in __exit__
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions     six.reraise(self.type_, self.value, self.tb)
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions   File "/opt/stack/new/nova/nova/compute/manager.py", line 371, in decorated_function
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions     return function(self, context, *args, **kwargs)
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions   File "/opt/stack/new/nova/nova/compute/manager.py", line 4649, in reserve_block_device_name
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions     return do_reserve()
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions   File "/usr/local/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py", line 271, in inner
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions     return f(*args, **kwargs)
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions   File "/opt/stack/new/nova/nova/compute/manager.py", line 4643, in do_reserve
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions     instance, bdms, new_bdm)
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions   File "/opt/stack/new/nova/nova/compute/manager.py", line 1663, in _get_device_name_for_instance
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions     instance, bdms, block_device_obj)
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions   File "/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 7249, in get_device_name_for_instance
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions     block_device_obj, mapping=instance_info['mapping'])
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions   File "/opt/stack/new/nova/nova/virt/libvirt/blockinfo.py", line 397, in get_info_from_bdm
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions     device_name = find_disk_dev_for_disk_bus(padded_mapping, bdm_bus)
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions   File "/opt/stack/new/nova/nova/virt/libvirt/blockinfo.py", line 201, in find_disk_dev_for_disk_bus
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions     dev_prefix)
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions
  2016-01-04 11:47:11.087 26423 ERROR nova.api.openstack.extensions TypeError: __init__() takes at most 2 arguments (3 given)

  Currently observed things:

  1) Manila project has no recent changes that could cause it.
  2) Error appears on attempt to attach Cinder volume to Nova VM.
  3) Amount of attachments increased comparing to "ok" results of other runs before error appearance. Example: was 55, became 98 and then job timeout reached, so, it is not final count of attach attempts.
  4) Nova fails to dedicate device ID for volume starting from 26th device. This limit should not have been reached in normal situation.

  Suspect cause: reserved device IDs for Nova are not released as it was
  and expected. Nova has bug handling case when device ID cannot be
  reserved.

  https://github.com/openstack/nova/commit/9f9711578f6cca05b3b50b934d261f9b50a1e377
  ?

  How to reproduce:
  1) Create instance
  And then perform following in cycle 26 times:
  2) Create volume
  3) Attach volume to instance (1)
  4) Detach volume (2)

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

[Bug 1530847] [NEW] TypeError attaching volume to instance
From: Valeriy Ponomaryov, 2016-01-04