openstack team mailing list archive

Thread
Date

[Folsom] [Cinder] Error when creating volumes

To: openstack <openstack@xxxxxxxxxxxxxxxxxxx>
From: Nikola Pajtic <salgeras@xxxxxxxxx>
Date: Tue, 20 Nov 2012 13:12:50 +0100

Hi all.

I have a problem with Cinder and Horizon, I was hoping someone could help
me.

When I try to create new volume from Horizon, it does create it but with
status "Error". When I check cinder database, I can see new volume entry in
cinder.volumes.

Attached below you will find all of the cinder-* logs, as well as apache
error_log from Horizon server. That's what happens when I click "Create
volume".

Besides the Horizon, I can also create volume from CLI, using:

#> cinder --os-username nova --os-password openstack --os-tenant-name
service --os-auth-url http://localhost:5000/v2.0 create --display_name test
1

But, with the same errors in log files. As far as I can tell, error which
causes this problem is from cinder-scheduler:

TRACE cinder.openstack.common.rpc.amqp NoValidHost: No valid host was
found. Is the appropriate service running?

On the other hand, Apache log throws:

[error] unable to retrieve service catalog with token


Is it possible that problem lies in Keystone db? This is how I created
end-point for Cinder:

{"adminurl": "http://192.168.0.12:8776/v1/$(tenant_id)s", "internalurl": "
http://192.168.0.12:8776/v1/$(tenant_id)s", "publicurl": "
http://192.168.0.12:8776/v1/$(tenant_id)s"}

If you need more info, I'd be happy to provide.

Thank you all in advance!

==> cinder-api.log <==
2012-11-20 11:02:18 INFO cinder.api.openstack.wsgi [req-63d985ca-e789-457d-a4ab-1e786f43ffa0 ed04d6e1628c4f43a6b20829f7910720 934fb5ed6e9a4accac8a24531b8238f1] GET http://192.168.0.12:8776/v1/934fb5ed6e9a4accac8a24531b8238f1/snapshots/detail
2012-11-20 11:02:18 DEBUG cinder.api.openstack.wsgi [req-63d985ca-e789-457d-a4ab-1e786f43ffa0 ed04d6e1628c4f43a6b20829f7910720 934fb5ed6e9a4accac8a24531b8238f1] Unrecognized Content-Type provided in request get_body /usr/lib/python2.7/dist-packages/cinder/api/openstack/wsgi.py:695
2012-11-20 11:02:18 DEBUG cinder.api.openstack.volume.volumes [req-63d985ca-e789-457d-a4ab-1e786f43ffa0 ed04d6e1628c4f43a6b20829f7910720 934fb5ed6e9a4accac8a24531b8238f1] Removing options '' from query remove_invalid_options /usr/lib/python2.7/dist-packages/cinder/api/openstack/volume/volumes.py:356
2012-11-20 11:02:18 INFO cinder.api.openstack.wsgi [req-63d985ca-e789-457d-a4ab-1e786f43ffa0 ed04d6e1628c4f43a6b20829f7910720 934fb5ed6e9a4accac8a24531b8238f1] http://192.168.0.12:8776/v1/934fb5ed6e9a4accac8a24531b8238f1/snapshots/detail returned with HTTP 200
2012-11-20 11:02:18 INFO cinder.api.openstack.wsgi [req-ccb91184-7a54-43db-8589-e0c470ae9e33 ed04d6e1628c4f43a6b20829f7910720 934fb5ed6e9a4accac8a24531b8238f1] GET http://192.168.0.12:8776/v1/934fb5ed6e9a4accac8a24531b8238f1/volumes/detail
2012-11-20 11:02:18 DEBUG cinder.api.openstack.wsgi [req-ccb91184-7a54-43db-8589-e0c470ae9e33 ed04d6e1628c4f43a6b20829f7910720 934fb5ed6e9a4accac8a24531b8238f1] Unrecognized Content-Type provided in request get_body /usr/lib/python2.7/dist-packages/cinder/api/openstack/wsgi.py:695
2012-11-20 11:02:18 DEBUG cinder.api.openstack.volume.volumes [req-ccb91184-7a54-43db-8589-e0c470ae9e33 ed04d6e1628c4f43a6b20829f7910720 934fb5ed6e9a4accac8a24531b8238f1] Removing options '' from query remove_invalid_options /usr/lib/python2.7/dist-packages/cinder/api/openstack/volume/volumes.py:356
2012-11-20 11:02:18 INFO cinder.api.openstack.wsgi [req-ccb91184-7a54-43db-8589-e0c470ae9e33 ed04d6e1628c4f43a6b20829f7910720 934fb5ed6e9a4accac8a24531b8238f1] http://192.168.0.12:8776/v1/934fb5ed6e9a4accac8a24531b8238f1/volumes/detail returned with HTTP 200
2012-11-20 11:02:18 INFO cinder.api.openstack.wsgi [req-5c8303ce-54a5-419a-afc4-b8f06add9489 ed04d6e1628c4f43a6b20829f7910720 934fb5ed6e9a4accac8a24531b8238f1] POST http://192.168.0.12:8776/v1/934fb5ed6e9a4accac8a24531b8238f1/volumes
2012-11-20 11:02:18 AUDIT cinder.api.openstack.volume.volumes [req-5c8303ce-54a5-419a-afc4-b8f06add9489 ed04d6e1628c4f43a6b20829f7910720 934fb5ed6e9a4accac8a24531b8238f1] Create volume of 5 GB
2012-11-20 11:02:18 DEBUG cinder.quota [req-5c8303ce-54a5-419a-afc4-b8f06add9489 ed04d6e1628c4f43a6b20829f7910720 934fb5ed6e9a4accac8a24531b8238f1] Created reservations ['f16c93bb-4e0e-4279-a315-fc22708bc544', 'c423f91b-9ea4-4d6f-a2a1-b101c784c083'] reserve /usr/lib/python2.7/dist-packages/cinder/quota.py:663
2012-11-20 11:02:18 1472 DEBUG cinder.openstack.common.rpc.amqp [-] Making asynchronous cast on cinder-scheduler... cast /usr/lib/python2.7/dist-packages/cinder/openstack/common/rpc/amqp.py:377
2012-11-20 11:02:18 1472 DEBUG cinder.openstack.common.rpc.amqp [-] Pool creating new connection create /usr/lib/python2.7/dist-packages/cinder/openstack/common/rpc/amqp.py:58
2012-11-20 11:02:18 1472 INFO cinder.openstack.common.rpc.common [-] Connected to AMQP server on localhost:5672

==> cinder-scheduler.log <==
2012-11-20 11:02:18 1473 DEBUG cinder.openstack.common.rpc.amqp [-] received {u'_context_roles': [u'Member', u'anotherrole', u'admin'], u'_context_request_id': u'req-5c8303ce-54a5-419a-afc4-b8f06add9489', u'_context_quota_class': None, u'args': {u'topic': u'cinder-volume', u'image_id': None, u'snapshot_id': None, u'volume_id': u'e997a477-3e13-43d6-a089-0c4f135aa446'}, u'_context_auth_token': '<SANITIZED>', u'_context_is_admin': False, u'_context_project_id': u'934fb5ed6e9a4accac8a24531b8238f1', u'_context_timestamp': u'2012-11-20T10:02:18.492531', u'_context_read_deleted': u'no', u'_context_user_id': u'ed04d6e1628c4f43a6b20829f7910720', u'method': u'create_volume', u'_context_remote_address': u'192.168.0.13'} _safe_log /usr/lib/python2.7/dist-packages/cinder/openstack/common/rpc/common.py:195

==> cinder-api.log <==
2012-11-20 11:02:18 AUDIT cinder.api.openstack.volume.volumes [req-5c8303ce-54a5-419a-afc4-b8f06add9489 ed04d6e1628c4f43a6b20829f7910720 934fb5ed6e9a4accac8a24531b8238f1] vol={'availability_zone': 'nova', 'terminated_at': None, 'updated_at': None, 'provider_auth': None, 'snapshot_id': None, 'ec2_id': None, 'mountpoint': None, 'deleted_at': None, 'id': 'e997a477-3e13-43d6-a089-0c4f135aa446', 'size': 5, 'user_id': u'ed04d6e1628c4f43a6b20829f7910720', 'attach_time': None, 'display_description': u'', 'project_id': u'934fb5ed6e9a4accac8a24531b8238f1', 'launched_at': None, 'scheduled_at': None, 'status': 'creating', 'volume_type_id': None, 'deleted': False, 'provider_location': None, 'host': None, 'display_name': u'test_vol1', 'instance_uuid': None, 'created_at': datetime.datetime(2012, 11, 20, 10, 2, 18, 612451), 'attach_status': 'detached'}

==> cinder-scheduler.log <==
2012-11-20 11:02:18 1473 DEBUG cinder.openstack.common.rpc.amqp [-] unpacked context: {'user_id': u'ed04d6e1628c4f43a6b20829f7910720', 'roles': [u'Member', u'anotherrole', u'admin'], 'timestamp': u'2012-11-20T10:02:18.492531', 'auth_token': '<SANITIZED>', 'remote_address': u'192.168.0.13', 'quota_class': None, 'is_admin': False, 'request_id': u'req-5c8303ce-54a5-419a-afc4-b8f06add9489', 'project_id': u'934fb5ed6e9a4accac8a24531b8238f1', 'read_deleted': u'no'} _safe_log /usr/lib/python2.7/dist-packages/cinder/openstack/common/rpc/common.py:195

==> cinder-api.log <==
2012-11-20 11:02:18 INFO cinder.api.openstack.wsgi [req-5c8303ce-54a5-419a-afc4-b8f06add9489 ed04d6e1628c4f43a6b20829f7910720 934fb5ed6e9a4accac8a24531b8238f1] http://192.168.0.12:8776/v1/934fb5ed6e9a4accac8a24531b8238f1/volumes returned with HTTP 200

==> cinder-scheduler.log <==
2012-11-20 11:02:18 1473 ERROR cinder.openstack.common.rpc.amqp [-] Exception during message handling
2012-11-20 11:02:18 1473 TRACE cinder.openstack.common.rpc.amqp Traceback (most recent call last):
2012-11-20 11:02:18 1473 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.7/dist-packages/cinder/openstack/common/rpc/amqp.py", line 276, in _process_data
2012-11-20 11:02:18 1473 TRACE cinder.openstack.common.rpc.amqp     rval = self.proxy.dispatch(ctxt, version, method, **args)
2012-11-20 11:02:18 1473 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.7/dist-packages/cinder/openstack/common/rpc/dispatcher.py", line 145, in dispatch
2012-11-20 11:02:18 1473 TRACE cinder.openstack.common.rpc.amqp     return getattr(proxyobj, method)(ctxt, **kwargs)
2012-11-20 11:02:18 1473 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.7/dist-packages/cinder/scheduler/manager.py", line 98, in _schedule
2012-11-20 11:02:18 1473 TRACE cinder.openstack.common.rpc.amqp     db.volume_update(context, volume_id, {'status': 'error'})
2012-11-20 11:02:18 1473 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.7/contextlib.py", line 24, in __exit__
2012-11-20 11:02:18 1473 TRACE cinder.openstack.common.rpc.amqp     self.gen.next()
2012-11-20 11:02:18 1473 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.7/dist-packages/cinder/scheduler/manager.py", line 94, in _schedule
2012-11-20 11:02:18 1473 TRACE cinder.openstack.common.rpc.amqp     return driver_method(*args, **kwargs)
2012-11-20 11:02:18 1473 TRACE cinder.openstack.common.rpc.amqp   File "/usr/lib/python2.7/dist-packages/cinder/scheduler/simple.py", line 78, in schedule_create_volume
2012-11-20 11:02:18 1473 TRACE cinder.openstack.common.rpc.amqp     raise exception.NoValidHost(reason=msg)
2012-11-20 11:02:18 1473 TRACE cinder.openstack.common.rpc.amqp NoValidHost: No valid host was found. Is the appropriate service running?
2012-11-20 11:02:18 1473 TRACE cinder.openstack.common.rpc.amqp 

==> cinder-api.log <==
2012-11-20 11:02:19 INFO cinder.api.openstack.wsgi [req-197d4420-a135-49e8-ba8c-9a5f860843a1 ed04d6e1628c4f43a6b20829f7910720 934fb5ed6e9a4accac8a24531b8238f1] GET http://192.168.0.12:8776/v1/934fb5ed6e9a4accac8a24531b8238f1/volumes/detail
2012-11-20 11:02:19 DEBUG cinder.api.openstack.wsgi [req-197d4420-a135-49e8-ba8c-9a5f860843a1 ed04d6e1628c4f43a6b20829f7910720 934fb5ed6e9a4accac8a24531b8238f1] Unrecognized Content-Type provided in request get_body /usr/lib/python2.7/dist-packages/cinder/api/openstack/wsgi.py:695
2012-11-20 11:02:19 DEBUG cinder.api.openstack.volume.volumes [req-197d4420-a135-49e8-ba8c-9a5f860843a1 ed04d6e1628c4f43a6b20829f7910720 934fb5ed6e9a4accac8a24531b8238f1] Removing options '' from query remove_invalid_options /usr/lib/python2.7/dist-packages/cinder/api/openstack/volume/volumes.py:356
2012-11-20 11:02:19 AUDIT cinder.api.openstack.volume.volumes [req-197d4420-a135-49e8-ba8c-9a5f860843a1 ed04d6e1628c4f43a6b20829f7910720 934fb5ed6e9a4accac8a24531b8238f1] vol=<cinder.db.sqlalchemy.models.Volume object at 0x3070710>
2012-11-20 11:02:19 INFO cinder.api.openstack.wsgi [req-197d4420-a135-49e8-ba8c-9a5f860843a1 ed04d6e1628c4f43a6b20829f7910720 934fb5ed6e9a4accac8a24531b8238f1] http://192.168.0.12:8776/v1/934fb5ed6e9a4accac8a24531b8238f1/volumes/detail returned with HTTP 200

#########################################################
mysql> select * from cinder.volumes;
+---------------------+---------------------+---------------------+---------+--------------------------------------+--------+----------------------------------+----------------------------------+------------+------+-------------------+---------------+------------+-------------+----------+---------------+---------------------+-------------+---------------------+--------------+---------------------+-------------------+---------------+-------------+----------------+
| created_at          | updated_at          | deleted_at          | deleted | id                                   | ec2_id | user_id                          | project_id                       | host       | size | availability_zone | instance_uuid | mountpoint | attach_time | status   | attach_status | scheduled_at        | launched_at | terminated_at       | display_name | display_description | provider_location | provider_auth | snapshot_id | volume_type_id |
+---------------------+---------------------+---------------------+---------+--------------------------------------+--------+----------------------------------+----------------------------------+------------+------+-------------------+---------------+------------+-------------+----------+---------------+---------------------+-------------+---------------------+--------------+---------------------+-------------------+---------------+-------------+----------------+

| 2012-11-20 10:02:18 | 2012-11-20 10:02:18 | NULL                |       0 | e997a477-3e13-43d6-a089-0c4f135aa446 | NULL   | ed04d6e1628c4f43a6b20829f7910720 | 934fb5ed6e9a4accac8a24531b8238f1 | NULL       |    5 | nova              | NULL          | NULL       | NULL        | error    | detached      | NULL                | NULL        | NULL                | test_vol1    |                     | NULL              | NULL          | NULL        |           NULL |
+---------------------+---------------------+---------------------+---------+--------------------------------------+--------+----------------------------------+----------------------------------+------------+------+-------------------+---------------+------------+-------------+----------+---------------+---------------------+-------------+---------------------+--------------+---------------------+-------------------+---------------+-------------+----------------+

==> access.log <==
192.168.0.229 - - [20/Nov/2012:10:02:23 +0000] "POST /horizon/nova/volumes/create/? HTTP/1.1" 200 466 "http://192.168.0.13/horizon/nova/volumes/"; "Mozilla/5.0 (X11; Linux i686; rv:16.0) Gecko/20100101 Firefox/16.0"

==> error.log <==
[Tue Nov 20 10:02:24 2012] [error] unable to retrieve service catalog with token
[Tue Nov 20 10:02:24 2012] [error] Traceback (most recent call last):
[Tue Nov 20 10:02:24 2012] [error]   File "/usr/lib/python2.7/dist-packages/keystoneclient/v2_0/client.py", line 132, in _extract_service_catalog
[Tue Nov 20 10:02:24 2012] [error]     endpoint_type='adminURL')
[Tue Nov 20 10:02:24 2012] [error]   File "/usr/lib/python2.7/dist-packages/keystoneclient/service_catalog.py", line 62, in url_for
[Tue Nov 20 10:02:24 2012] [error]     raise exceptions.EndpointNotFound('Endpoint not found.')
[Tue Nov 20 10:02:24 2012] [error] EndpointNotFound: Endpoint not found.

==> access.log <==
192.168.0.229 - - [20/Nov/2012:10:02:24 +0000] "GET /horizon/nova/volumes/ HTTP/1.1" 200 3158 "http://192.168.0.13/horizon/nova/volumes/"; "Mozilla/5.0 (X11; Linux i686; rv:16.0) Gecko/20100101 Firefox/16.0"
192.168.0.229 - - [20/Nov/2012:10:02:24 +0000] "GET /horizon/i18n/js/horizon/ HTTP/1.1" 200 2424 "http://192.168.0.13/horizon/nova/volumes/"; "Mozilla/5.0 (X11; Linux i686; rv:16.0) Gecko/20100101 Firefox/16.0"
192.168.0.229 - - [20/Nov/2012:10:02:25 +0000] "GET /static/dashboard/fonts/Anivers_Regular-webfont.woff?2c3db88030ec HTTP/1.1" 304 188 "http://192.168.0.13/static/dashboard/css/9feb0b911869.css"; "Mozilla/5.0 (X11; Linux i686; rv:16.0) Gecko/20100101 Firefox/16.0"

Attachment: nova.conf
Description: Binary data

Attachment: api-paste.ini
Description: Binary data

Attachment: cinder.conf
Description: Binary data