Booting VM from cinder volume fails

Bug #1155284 reported by Aleksandr Orlov
10
This bug affects 2 people
Affects Status Importance Assigned to Milestone
Cinder
Fix Released
High
John Griffith

Bug Description

I'm trying to launch instance from cinder volume
both image and volume are available
root@vm0:~# glance image-list
+--------------------------------------+-----------+-------------+------------------+-----------+--------+
| ID | Name | Disk Format | Container Format | Size | Status |
+--------------------------------------+-----------+-------------+------------------+-----------+--------+
| d9cb5380-30c7-4785-9537-e03452634f54 | Ubuntu 12 | qcow2 | bare | 251068416 | active |
+--------------------------------------+-----------+-------------+------------------+-----------+--------+
root@vm0:~# cinder list
+--------------------------------------+-----------+--------------+------+-------------+----------+-------------+
| ID | Status | Display Name | Size | Volume Type | Bootable | Attached to |
+--------------------------------------+-----------+--------------+------+-------------+----------+-------------+
| ba7cbc34-f07a-4514-be69-8a49ce8b5fa4 | available | Ubuntu 12 | 6 | root | true | |
+--------------------------------------+-----------+--------------+------+-------------+----------+-------------+

but when executing
nova boot --flavor 1 --image d9cb5380-30c7-4785-9537-e03452634f54 --block-device-mapping vda=ba7cbc34-f07a-4514-be69-8a49ce8b5fa4 --security_groups=default --key_name default DEMO_VM0

i'm getting the following error in cinder logs (nova logs says that server not capable of perform the operation (HTTP 500))

2013-03-13 02:21:01.341 INFO cinder.api.openstack.wsgi [req-f3a5b935-8003-4d4f-b53e-0326e8fb858d 2cd01fb6c2e0438688c486069a991c3b 8fe12af3d57b4968b33d819ee82646f4] POST http://192.168.10.103:8776/v1/8fe12af3d57b4968b33d819ee82646f4/volumes/ba7cbc34-f07a-4514-be69-8a49ce8b5fa4/action
2013-03-13 02:21:01.383 ERROR cinder.api.middleware.fault [req-f3a5b935-8003-4d4f-b53e-0326e8fb858d 2cd01fb6c2e0438688c486069a991c3b 8fe12af3d57b4968b33d819ee82646f4] Caught error: Remote error: IOError [Errno 13] Permission denied: u'/usr/lib/python2.7/dist-packages/cinder/openstack/cinder-ba7cbc34-f07a-4514-be69-8a49ce8b5fa4'
[u'Traceback (most recent call last):\n', u' File "/usr/lib/python2.7/dist-packages/cinder/openstack/common/rpc/amqp.py", line 275, in _process_data\n rval = self.proxy.dispatch(ctxt, version, method, **args)\n', u' File "/usr/lib/python2.7/dist-packages/cinder/openstack/common/rpc/dispatcher.py", line 145, in dispatch\n return getattr(proxyobj, method)(ctxt, **kwargs)\n', u' File "/usr/lib/python2.7/dist-packages/cinder/volume/manager.py", line 526, in attach_volume\n return do_attach()\n', u' File "/usr/lib/python2.7/dist-packages/cinder/openstack/common/lockutils.py", line 214, in inner\n with lock:\n', u' File "/usr/lib/python2.7/dist-packages/cinder/openstack/common/lockutils.py", line 74, in __enter__\n self.lockfile = open(self.fname, \'w\')\n', u"IOError: [Errno 13] Permission denied: u'/usr/lib/python2.7/dist-packages/cinder/openstack/cinder-ba7cbc34-f07a-4514-be69-8a49ce8b5fa4'\n"].
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault Traceback (most recent call last):
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/cinder/api/middleware/fault.py", line 73, in __call__
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault return req.get_response(self.application)
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/webob/request.py", line 1296, in send
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault application, catch_exc_info=False)
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/webob/request.py", line 1260, in call_application
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault app_iter = application(self.environ, start_response)
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault return resp(environ, start_response)
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/keystoneclient/middleware/auth_token.py", line 328, in __call__
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault return self.app(env, start_response)
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault return resp(environ, start_response)
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault return resp(environ, start_response)
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/routes/middleware.py", line 131, in __call__
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault response = self.app(environ, start_response)
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault return resp(environ, start_response)
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 130, in __call__
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault resp = self.call_func(req, *args, **self.kwargs)
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/webob/dec.py", line 195, in call_func
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault return self.func(req, *args, **kwargs)
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/cinder/api/openstack/wsgi.py", line 803, in __call__
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault content_type, body, accept)
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/cinder/api/openstack/wsgi.py", line 851, in _process_stack
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault action_result = self.dispatch(meth, request, action_args)
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/cinder/api/openstack/wsgi.py", line 927, in dispatch
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault return method(req=request, **action_args)
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/cinder/api/contrib/volume_actions.py", line 86, in _attach
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault instance_uuid, mountpoint)
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/cinder/volume/api.py", line 63, in wrapped
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault return func(self, context, target_obj, *args, **kwargs)
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/cinder/volume/api.py", line 465, in attach
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault mountpoint)
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/cinder/volume/rpcapi.py", line 93, in attach_volume
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault volume['host']))
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/cinder/openstack/common/rpc/proxy.py", line 80, in call
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault return rpc.call(context, self._get_topic(topic), msg, timeout)
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/cinder/openstack/common/rpc/__init__.py", line 108, in call
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault return _get_impl().call(cfg.CONF, context, topic, msg, timeout)
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/cinder/openstack/common/rpc/impl_kombu.py", line 753, in call
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault rpc_amqp.get_connection_pool(conf, Connection))
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/cinder/openstack/common/rpc/amqp.py", line 368, in call
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault rv = list(rv)
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/cinder/openstack/common/rpc/amqp.py", line 336, in __iter__
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault raise result
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault RemoteError: Remote error: IOError [Errno 13] Permission denied: u'/usr/lib/python2.7/dist-packages/cinder/openstack/cinder-ba7cbc34-f07a-4514-be69-8a49ce8b5fa4'
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault [u'Traceback (most recent call last):\n', u' File "/usr/lib/python2.7/dist-packages/cinder/openstack/common/rpc/amqp.py", line 275, in _process_data\n rval = self.proxy.dispatch(ctxt, version, method, **args)\n', u' File "/usr/lib/python2.7/dist-packages/cinder/openstack/common/rpc/dispatcher.py", line 145, in dispatch\n return getattr(proxyobj, method)(ctxt, **kwargs)\n', u' File "/usr/lib/python2.7/dist-packages/cinder/volume/manager.py", line 526, in attach_volume\n return do_attach()\n', u' File "/usr/lib/python2.7/dist-packages/cinder/openstack/common/lockutils.py", line 214, in inner\n with lock:\n', u' File "/usr/lib/python2.7/dist-packages/cinder/openstack/common/lockutils.py", line 74, in __enter__\n self.lockfile = open(self.fname, \'w\')\n', u"IOError: [Errno 13] Permission denied: u'/usr/lib/python2.7/dist-packages/cinder/openstack/cinder-ba7cbc34-f07a-4514-be69-8a49ce8b5fa4'\n"].
2013-03-13 02:21:01.383 1549 TRACE cinder.api.middleware.fault
2013-03-13 02:21:01.385 INFO cinder.api.middleware.fault [req-f3a5b935-8003-4d4f-b53e-0326e8fb858d 2cd01fb6c2e0438688c486069a991c3b 8fe12af3d57b4968b33d819ee82646f4] http://192.168.10.103:8776/v1/8fe12af3d57b4968b33d819ee82646f4/volumes/ba7cbc34-f07a-4514-be69-8a49ce8b5fa4/action returned with HTTP 500

my cinder.conf
[DEFAULT]
rootwrap_config = /etc/cinder/rootwrap.conf
sql_connection = mysql://cinder:cinder@192.168.10.101:3306/cinder
api_paste_confg = /etc/cinder/api-paste.ini

iscsi_helper = tgtadm
volume_name_template = volume-%s
volume_group = cinder-volumes
verbose = True
auth_strategy = keystone
state_path = /var/lib/cinder
volumes_dir = /var/lib/cinder/volumes

rabbit_host = 192.168.10.102
glance_host = 192.168.10.103

and cinder-related part of nova.conf

enabled_apis=ec2,osapi_compute,metadata
# Cinder #
volume_api_class=nova.volume.cinder.API
volume_group=cinder-volumes
volume_name_template=volume-%s
osapi_volume_listen_port=5900
state_path = /var/lib/cinder
volumes_dir = /var/lib/cinder/volumes

I'm not sure whether this is a real bug

Revision history for this message
John Griffith (john-griffith) wrote :

Try setting lock_path in your cinder.conf file to a directory you have access to and see if that addresses the issue.

Revision history for this message
John Griffith (john-griffith) wrote :

Looks like we need to pull in the latest lockutils code from oslo incubator, the version we have now uses the conf file default setting of the python dist install.

Changed in cinder:
status: New → Triaged
importance: Undecided → High
assignee: nobody → John Griffith (john-griffith)
milestone: none → grizzly-rc2
Revision history for this message
Aleksandr Orlov (vulzscht) wrote :
Download full text (10.9 KiB)

i have set lock_path as /var/lib/cinder
and got rid of this exception

2013-03-20 16:42:03.772 26480 DEBUG cinder.volume.drivers.lvm [-] Updating volume status _update_volume_status /usr/lib/python2.7/dist-packages/cinder/volume/drivers/lvm.py:548
2013-03-20 16:42:03.773 26480 DEBUG cinder.utils [-] Running cmd (subprocess): sudo cinder-rootwrap /etc/cinder/rootwrap.conf vgs --noheadings --nosuffix --unit=G -o name,size,free cinder-volumes execute /usr/lib/python2.7/dist-packages/cinder/utils.py:166
2013-03-20 16:42:26.937 26480 DEBUG cinder.openstack.common.rpc.amqp [-] received {u'_context_roles': [u'admin', u'Member'], u'_msg_id': u'78e07759035a440abca7ca4bfd012018', u'_context_quota_class': None, u'_context_request_id': u'req-d2bce6cb-7c4f-4907-8151-3f513b7af7fb', u'_con
text_read_deleted': u'no', u'args': {u'connector': {u'ip': u'192.168.10.4', u'initiator': u'iqn.1993-08.org.debian:01:95a39e617950', u'host': u'vm0.lan.lo'}, u'volume_id': u'ba7cbc34-f07a-4514-be69-8a49ce8b5fa4'}, u'_context_tenant': u'8fe12af3d57b4968b33d819ee82646f4', u'_contex
t_auth_token': '<SANITIZED>', u'_context_is_admin': True, u'version': u'1.0', u'_context_project_id': u'8fe12af3d57b4968b33d819ee82646f4', u'_context_timestamp': u'2013-03-20T12:42:26.889525', u'_context_user': u'2cd01fb6c2e0438688c486069a991c3b', u'_context_user_id': u'2cd01fb6c
2e0438688c486069a991c3b', u'method': u'initialize_connection', u'_context_remote_address': u'192.168.10.4'} _safe_log /usr/lib/python2.7/dist-packages/cinder/openstack/common/rpc/common.py:195
2013-03-20 16:42:26.937 26480 DEBUG cinder.openstack.common.rpc.amqp [-] unpacked context: {'user_id': u'2cd01fb6c2e0438688c486069a991c3b', 'roles': [u'admin', u'Member'], 'timestamp': u'2013-03-20T12:42:26.889525', 'auth_token': '<SANITIZED>', 'remote_address': u'192.168.10.4',
'quota_class': None, 'is_admin': True, 'user': u'2cd01fb6c2e0438688c486069a991c3b', 'request_id': u'req-d2bce6cb-7c4f-4907-8151-3f513b7af7fb', 'project_id': u'8fe12af3d57b4968b33d819ee82646f4', 'read_deleted': u'no', 'tenant': u'8fe12af3d57b4968b33d819ee82646f4'} _safe_log /usr/l
ib/python2.7/dist-packages/cinder/openstack/common/rpc/common.py:195
2013-03-20 16:42:26.986 26480 DEBUG cinder.openstack.common.rpc.amqp [-] received {u'_context_roles': [u'admin', u'Member'], u'_msg_id': u'3fafe32f72d84925ab22596dec54f829', u'_context_quota_class': None, u'_context_request_id': u'req-90a18d70-dccd-45d7-ba80-ec3797a62a29', u'_con
text_read_deleted': u'no', u'args': {u'instance_uuid': u'16e4baf3-e091-4b86-b33a-dcdf7c516bfb', u'mountpoint': u'vda', u'volume_id': u'ba7cbc34-f07a-4514-be69-8a49ce8b5fa4'}, u'_context_tenant': u'8fe12af3d57b4968b33d819ee82646f4', u'_context_auth_token': '<SANITIZED>', u'_contex
t_is_admin': True, u'version': u'1.0', u'_context_project_id': u'8fe12af3d57b4968b33d819ee82646f4', u'_context_timestamp': u'2013-03-20T12:42:26.964279', u'_context_user': u'2cd01fb6c2e0438688c486069a991c3b', u'_context_user_id': u'2cd01fb6c2e0438688c486069a991c3b', u'method': u'
attach_volume', u'_context_remote_address': u'192.168.10.4'} _safe_log /usr/lib/python2.7/dist-packages/cinder/openstack/common/rpc/common.py:195
2013-03-20 16:42:26.987 26480 DEBUG cin...

Revision history for this message
John Griffith (john-griffith) wrote :

This has been fixed so that the default lock_path is an accessible tmp dir. Fixed with the update of OSLO.lockutils

https://review.openstack.org/#/c/24933/

Changed in cinder:
status: Triaged → In Progress
Mike Perez (thingee)
Changed in cinder:
status: In Progress → Fix Committed
Thierry Carrez (ttx)
Changed in cinder:
status: Fix Committed → Fix Released
Thierry Carrez (ttx)
Changed in cinder:
milestone: grizzly-rc2 → 2013.1
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Related questions

Remote bug watches

Bug watches keep track of this bug in other bug trackers.