Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.

Bug 918113

Summary: nova: When attempting to attach more than 27 volumes to 1 instance the 'nova attach-volume' command fails with no error.
Product: Red Hat OpenStack Reporter: Omri Hochman <ohochman>
Component: openstack-novaAssignee: Brent Eagles <beagles>
Status: CLOSED NOTABUG QA Contact: Yaniv Kaul <ykaul>
Severity: medium Docs Contact:
Priority: medium    
Version: 2.0 (Folsom)CC: beagles, jkt, ndipanov, ohochman
Target Milestone: asyncKeywords: Triaged
Target Release: 2.1   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2013-04-29 19:44:19 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
compute.log
none
api.log none

Description Omri Hochman 2013-03-05 14:05:26 UTC
nova: When attempting to attach more than 27 volumes to 1 instance the 'nova attach-volume' command fails with no error. 

Environment:
------------
openstack-nova-compute-2012.2.3-4.el6ost.noarch
openstack-nova-cert-2012.2.3-4.el6ost.noarch
openstack-nova-console-2012.2.3-4.el6ost.noarch
openstack-nova-common-2012.2.3-4.el6ost.noarch
openstack-cinder-2012.2.3-4.el6ost.noarch
openstack-nova-api-2012.2.3-4.el6ost.noarch
libvirt-0.10.2-18.el6.x86_64

Scenario:
----------
1) Create 1 Instance. 
2) Create 28 volumes. 
3) Attach 28 volumes to 1 instance.


Results: 
--------
The 'nova attach-volume' command seems to work properly,  It produce no error, but  it fails on : limitation number of available PCI addresses.
the error can be found in compute.log. 

------------------------------------------
[root@puma01 ~(keystone_admin)]$ nova volume-attach 1ac4e403-d2b6-4ba5-8004-a8558f09420d f81e6cc5-ba70-41bd-b7bb-48e4798f3509 auto

+----------+--------------------------------------+
| Property | Value                                |
+----------+--------------------------------------+
| device   | /dev/vdab                            |
| id       | f81e6cc5-ba70-41bd-b7bb-48e4798f3509 |
| serverId | 1ac4e403-d2b6-4ba5-8004-a8558f09420d |
| volumeId | f81e6cc5-ba70-41bd-b7bb-48e4798f3509 |
+----------+--------------------------------------+

/var/log/nova/compute.log:
-----------------------------
013-03-05 15:30:51 ERROR nova.compute.manager [req-98eaeb09-45a1-41f2-a5db-2f52ebf3e540 8e03c4d9eeb948fb9f35b76b223ddf86 00833be6f4534e1b9212bb8984979956] [instance: 1ac
4e403-d2b6-4ba5-8004-a8558f09420d] Failed to attach volume f81e6cc5-ba70-41bd-b7bb-48e4798f3509 at /dev/vdab
2013-03-05 15:30:51 7796 TRACE nova.compute.manager [instance: 1ac4e403-d2b6-4ba5-8004-a8558f09420d] Traceback (most recent call last):
2013-03-05 15:30:51 7796 TRACE nova.compute.manager [instance: 1ac4e403-d2b6-4ba5-8004-a8558f09420d]   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", li
ne 2046, in _attach_volume
2013-03-05 15:30:51 7796 TRACE nova.compute.manager [instance: 1ac4e403-d2b6-4ba5-8004-a8558f09420d]     mountpoint)
2013-03-05 15:30:51 7796 TRACE nova.compute.manager [instance: 1ac4e403-d2b6-4ba5-8004-a8558f09420d]   File "/usr/lib/python2.6/site-packages/nova/exception.py", line 117
, in wrapped
2013-03-05 15:30:51 7796 TRACE nova.compute.manager [instance: 1ac4e403-d2b6-4ba5-8004-a8558f09420d]     temp_level, payload)
2013-03-05 15:30:51 7796 TRACE nova.compute.manager [instance: 1ac4e403-d2b6-4ba5-8004-a8558f09420d]   File "/usr/lib64/python2.6/contextlib.py", line 23, in __exit__
2013-03-05 15:30:51 7796 TRACE nova.compute.manager [instance: 1ac4e403-d2b6-4ba5-8004-a8558f09420d]     self.gen.next()
2013-03-05 15:30:51 7796 TRACE nova.compute.manager [instance: 1ac4e403-d2b6-4ba5-8004-a8558f09420d]   File "/usr/lib/python2.6/site-packages/nova/exception.py", line 92,
 in wrapped
2013-03-05 15:30:51 7796 TRACE nova.compute.manager [instance: 1ac4e403-d2b6-4ba5-8004-a8558f09420d]     return f(*args, **kw)
2013-03-05 15:30:51 7796 TRACE nova.compute.manager [instance: 1ac4e403-d2b6-4ba5-8004-a8558f09420d]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py"
, line 677, in attach_volume

2013-03-05 15:30:51 7796 TRACE nova.compute.manager [instance: 1ac4e403-d2b6-4ba5-8004-a8558f09420d]     mount_device)
2013-03-05 15:30:51 7796 TRACE nova.compute.manager [instance: 1ac4e403-d2b6-4ba5-8004-a8558f09420d]   File "/usr/lib64/python2.6/contextlib.py", line 23, in __exit__
2013-03-05 15:30:51 7796 TRACE nova.compute.manager [instance: 1ac4e403-d2b6-4ba5-8004-a8558f09420d]     self.gen.next()
2013-03-05 15:30:51 7796 TRACE nova.compute.manager [instance: 1ac4e403-d2b6-4ba5-8004-a8558f09420d]   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 664, in attach_volume
2013-03-05 15:30:51 7796 TRACE nova.compute.manager [instance: 1ac4e403-d2b6-4ba5-8004-a8558f09420d]     virt_dom.attachDeviceFlags(conf.to_xml(), flags)
2013-03-05 15:30:51 7796 TRACE nova.compute.manager [instance: 1ac4e403-d2b6-4ba5-8004-a8558f09420d]   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 187, in doit
2013-03-05 15:30:51 7796 TRACE nova.compute.manager [instance: 1ac4e403-d2b6-4ba5-8004-a8558f09420d]     result = proxy_call(self._autowrap, f, *args, **kwargs)
2013-03-05 15:30:51 7796 TRACE nova.compute.manager [instance: 1ac4e403-d2b6-4ba5-8004-a8558f09420d]   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 147, in proxy_call
2013-03-05 15:30:51 7796 TRACE nova.compute.manager [instance: 1ac4e403-d2b6-4ba5-8004-a8558f09420d]     rv = execute(f,*args,**kwargs)
2013-03-05 15:30:51 7796 TRACE nova.compute.manager [instance: 1ac4e403-d2b6-4ba5-8004-a8558f09420d]   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 76, in tworker
2013-03-05 15:30:51 7796 TRACE nova.compute.manager [instance: 1ac4e403-d2b6-4ba5-8004-a8558f09420d]     rv = meth(*args,**kwargs)
2013-03-05 15:30:51 7796 TRACE nova.compute.manager [instance: 1ac4e403-d2b6-4ba5-8004-a8558f09420d]   File "/usr/lib64/python2.6/site-packages/libvirt.py", line 419, in attachDeviceFlags
2013-03-05 15:30:51 7796 TRACE nova.compute.manager [instance: 1ac4e403-d2b6-4ba5-8004-a8558f09420d]     if ret == -1: raise libvirtError ('virDomainAttachDeviceFlags() failed', dom=self)
2013-03-05 15:30:51 7796 TRACE nova.compute.manager [instance: 1ac4e403-d2b6-4ba5-8004-a8558f09420d] libvirtError: internal error No more available PCI addresses
2013-03-05 15:30:51 7796 TRACE nova.compute.manager [instance: 1ac4e403-d2b6-4ba5-8004-a8558f09420d] 
2013-03-05 15:30:51 7796 ERROR nova.openstack.common.rpc.amqp [-] Exception during message handling
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp Traceback (most recent call last):
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/openstack/common/rpc/amqp.py", line 276, in _process_data
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp     rval = self.proxy.dispatch(ctxt, version, method, **args)
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/openstack/common/rpc/dispatcher.py", line 145, in dispatch
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp     return getattr(proxyobj, method)(ctxt, **kwargs)
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/exception.py", line 117, in wrapped
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp     temp_level, payload)
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib64/python2.6/contextlib.py", line 23, in __exit__
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp     self.gen.next()
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/exception.py", line 92, in wrapped
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp     return f(*args, **kw)

2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 175, in decorated_function
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp     pass
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib64/python2.6/contextlib.py", line 23, in __exit__
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp     self.gen.next()
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 161, in decorated_function
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp     return function(self, context, *args, **kwargs)
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 196, in decorated_function
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp     kwargs['instance']['uuid'], e, sys.exc_info())
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib64/python2.6/contextlib.py", line 23, in __exit__
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp     self.gen.next()
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 190, in decorated_function
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp     return function(self, context, *args, **kwargs)
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 2020, in attach_volume
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp     context, instance.get('uuid'), mountpoint)
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib64/python2.6/contextlib.py", line 23, in __exit__
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp     self.gen.next()
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 2016, in attach_volume
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp     mountpoint, instance)
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 2055, in _attach_volume
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp     connector)
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib64/python2.6/contextlib.py", line 23, in __exit__
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp     self.gen.next()
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/compute/manager.py", line 2046, in _attach_volume
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp     mountpoint)
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/exception.py", line 117, in wrapped
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp     temp_level, payload)
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib64/python2.6/contextlib.py", line 23, in __exit__
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp     self.gen.next()
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/exception.py", line 92, in wrapped
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp     return f(*args, **kw)
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 677, in attach_volume
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp     mount_device)
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib64/python2.6/contextlib.py", line 23, in __exit__

2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp     self.gen.next()
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/nova/virt/libvirt/driver.py", line 664, in attach_volume
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp     virt_dom.attachDeviceFlags(conf.to_xml(), flags)
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 187, in doit
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp     result = proxy_call(self._autowrap, f, *args, **kwargs)
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 147, in proxy_call
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp     rv = execute(f,*args,**kwargs)
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib/python2.6/site-packages/eventlet/tpool.py", line 76, in tworker
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp     rv = meth(*args,**kwargs)
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp   File "/usr/lib64/python2.6/site-packages/libvirt.py", line 419, in attachDeviceFlags
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp     if ret == -1: raise libvirtError ('virDomainAttachDeviceFlags() failed', dom=self)
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp libvirtError: internal error No more available PCI addresses
2013-03-05 15:30:51 7796 TRACE nova.openstack.common.rpc.amqp 


/var/log/nova/api.log:
-----------------------
2013-03-05 15:30:34 INFO nova.api.openstack.wsgi [req-f138a994-148b-4ec7-be3c-1e25f9f6191c 8e03c4d9eeb948fb9f35b76b223ddf86 00833be6f4534e1b9212bb8984979956] POST http://10.35.160.11:8774/v2/00833be6f4534e1b9212bb8984979956/servers/1ac4e403-d2b6-4ba5-8004-a8558f09420d/os-volume_attachments
2013-03-05 15:30:34 AUDIT nova.api.openstack.compute.contrib.volumes [req-f138a994-148b-4ec7-be3c-1e25f9f6191c 8e03c4d9eeb948fb9f35b76b223ddf86 00833be6f4534e1b9212bb8984979956] Attach volume 6564d3a2-6a67-4ddb-a044-b5fe45b1b391 to instance 1ac4e403-d2b6-4ba5-8004-a8558f09420d at None
2013-03-05 15:30:34 INFO nova.api.openstack.wsgi [req-f138a994-148b-4ec7-be3c-1e25f9f6191c 8e03c4d9eeb948fb9f35b76b223ddf86 00833be6f4534e1b9212bb8984979956] http://10.35.160.11:8774/v2/00833be6f4534e1b9212bb8984979956/servers/1ac4e403-d2b6-4ba5-8004-a8558f09420d/os-volume_attachments returned with HTTP 400
2013-03-05 15:30:34 INFO nova.osapi_compute.wsgi.server [req-f138a994-148b-4ec7-be3c-1e25f9f6191c 8e03c4d9eeb948fb9f35b76b223ddf86 00833be6f4534e1b9212bb8984979956] 10.35.160.11 - - [05/Mar/2013 15:30:34] "POST /v2/00833be6f4534e1b9212bb8984979956/servers/1ac4e403-d2b6-4ba5-8004-a8558f09420d/os-volume_attachments HTTP/1.1" 400 269 0.294114

2013-03-05 15:30:49 INFO nova.api.openstack.wsgi [req-4dc6ba9e-cc90-4b90-8c5a-2264c77e3776 8e03c4d9eeb948fb9f35b76b223ddf86 00833be6f4534e1b9212bb8984979956] GET http://10.35.160.11:8774/v2/00833be6f4534e1b9212bb8984979956/servers/1ac4e403-d2b6-4ba5-8004-a8558f09420d
2013-03-05 15:30:49 INFO nova.api.openstack.wsgi [req-4dc6ba9e-cc90-4b90-8c5a-2264c77e3776 8e03c4d9eeb948fb9f35b76b223ddf86 00833be6f4534e1b9212bb8984979956] http://10.35.160.11:8774/v2/00833be6f4534e1b9212bb8984979956/servers/1ac4e403-d2b6-4ba5-8004-a8558f09420d returned with HTTP 200
2013-03-05 15:30:49 INFO nova.osapi_compute.wsgi.server [req-4dc6ba9e-cc90-4b90-8c5a-2264c77e3776 8e03c4d9eeb948fb9f35b76b223ddf86 00833be6f4534e1b9212bb8984979956] 10.35.160.11 - - [05/Mar/2013 15:30:49] "GET /v2/00833be6f4534e1b9212bb8984979956/servers/1ac4e403-d2b6-4ba5-8004-a8558f09420d HTTP/1.1" 200 1653 0.088950

2013-03-05 15:30:49 INFO nova.api.openstack.wsgi [req-98eaeb09-45a1-41f2-a5db-2f52ebf3e540 8e03c4d9eeb948fb9f35b76b223ddf86 00833be6f4534e1b9212bb8984979956] POST http://10.35.160.11:8774/v2/00833be6f4534e1b9212bb8984979956/servers/1ac4e403-d2b6-4ba5-8004-a8558f09420d/os-volume_attachments
2013-03-05 15:30:49 AUDIT nova.api.openstack.compute.contrib.volumes [req-98eaeb09-45a1-41f2-a5db-2f52ebf3e540 8e03c4d9eeb948fb9f35b76b223ddf86 00833be6f4534e1b9212bb8984979956] Attach volume f81e6cc5-ba70-41bd-b7bb-48e4798f3509 to instance 1ac4e403-d2b6-4ba5-8004-a8558f09420d at None
2013-03-05 15:30:49 INFO nova.api.openstack.wsgi [req-98eaeb09-45a1-41f2-a5db-2f52ebf3e540 8e03c4d9eeb948fb9f35b76b223ddf86 00833be6f4534e1b9212bb8984979956] http://10.35.160.11:8774/v2/00833be6f4534e1b9212bb8984979956/servers/1ac4e403-d2b6-4ba5-8004-a8558f09420d/os-volume_attachments returned with HTTP 200
2013-03-05 15:30:49 INFO nova.osapi_compute.wsgi.server [req-98eaeb09-45a1-41f2-a5db-2f52ebf3e540 8e03c4d9eeb948fb9f35b76b223ddf86 00833be6f4534e1b9212bb8984979956] 10.35.160.11 - - [05/Mar/2013 15:30:49] "POST /v2/00833be6f4534e1b9212bb8984979956/servers/1ac4e403-d2b6-4ba5-8004-a8558f09420d/os-volume_attachments HTTP/1.1" 200 368 0.48199

Comment 2 Omri Hochman 2013-03-05 14:53:08 UTC
Created attachment 705490 [details]
compute.log

Comment 3 Omri Hochman 2013-03-05 14:53:49 UTC
Created attachment 705491 [details]
api.log

Comment 4 Brent Eagles 2013-03-11 17:42:14 UTC
I'm assuming that no one has issue with the limitation itself in this case but the problem is that the error does not make it back to the client. This is, at least in part, that the attachment of the volume is asynchronous by design. This is probably one of those instances where there is a conceptual mismatch with what the nova client is meant to provide, what the typical user would expect it to do and what the provided APIs can do. A more lofty admin tool might wait for some kind of notification of the result, but in this case altering the API to be synchronous would be hazardous.

Comment 5 Brent Eagles 2013-04-29 19:44:19 UTC
Considering that this bug implies a behavior that is outside of the implied current scope of the command line admin tool. I'm closing this bug.