openstack yoga volume creation fails

Question

We are trying to create cinder volume. Cinder API accepts the request, but volumes are stuck in creating state. This happens regardless of the backend used (i.e. also with lvm). Seems like some timeouts happening between cinder api and the rest of the processes. How to resolve this? Any leads are highly appreciated.

Here’s an excerpt from cinder-api logs:

req-00001bfc-808d-4525-904d-207e40ac1e2d
9c8f8ded6e5947278acc0e5f10d0c7bf 949326f6d40c4d49a93fffac8b958b49 - -
default default] POST
http://10.10.1.83:8776/v3/949326f6d40c4d49a93fffac8b958b49/volumes
2022-08-11 17:17:01.415 21 INFO cinder.api.v3.volumes [None
req-00001bfc-808d-4525-904d-207e40ac1e2d
9c8f8ded6e5947278acc0e5f10d0c7bf 949326f6d40c4d49a93fffac8b958b49 - -
default default] Create volume of 4 GB 2022-08-11 17:17:01.435 21 INFO
cinder.volume.api [None req-00001bfc-808d-4525-904d-207e40ac1e2d
9c8f8ded6e5947278acc0e5f10d0c7bf 949326f6d40c4d49a93fffac8b958b49 - -
default default] Availability Zones retrieved successfully. 2022-08-11
17:17:01.619 21 INFO cinder.volume.api [None
req-00001bfc-808d-4525-904d-207e40ac1e2d
9c8f8ded6e5947278acc0e5f10d0c7bf 949326f6d40c4d49a93fffac8b958b49 - -
default default] Create volume request issued successfully. 2022-08-11
17:17:01.620 21 INFO cinder.api.openstack.wsgi [None
req-00001bfc-808d-4525-904d-207e40ac1e2d
9c8f8ded6e5947278acc0e5f10d0c7bf 949326f6d40c4d49a93fffac8b958b49 - -
default default]
http://10.10.1.83:8776/v3/949326f6d40c4d49a93fffac8b958b49/volumes
returned with HTTP 202 2022-08-11 17:17:11.119 23 INFO
cinder.api.openstack.wsgi [None
req-a50d2c2f-784b-481e-a34a-48f34225eed2 - - - - - -] GET
http://10.10.1.80:8776/ 2022-08-11 17:17:11.120 23 INFO
cinder.api.openstack.wsgi [None
req-a50d2c2f-784b-481e-a34a-48f34225eed2 - - - - - -]
http://10.10.1.80:8776/ returned with HTTP 300 2022-08-11 17:17:26.317
19 INFO cinder.api.openstack.wsgi [None
req-5ffc061d-f253-45fa-ad32-5d3bb3f2274a
9c8f8ded6e5947278acc0e5f10d0c7bf 949326f6d40c4d49a93fffac8b958b49 - -
default default] GET
http://10.10.1.83:8776/v3/949326f6d40c4d49a93fffac8b958b49/volumes/detail?all_tenants=1&name=test1
2022-08-11 17:17:26.341 19 INFO cinder.volume.api [None
req-5ffc061d-f253-45fa-ad32-5d3bb3f2274a
9c8f8ded6e5947278acc0e5f10d0c7bf 949326f6d40c4d49a93fffac8b958b49 - -
default default] Get all volumes completed successfully. 2022-08-11
17:17:26.354 19 INFO cinder.api.openstack.wsgi [None
req-5ffc061d-f253-45fa-ad32-5d3bb3f2274a
9c8f8ded6e5947278acc0e5f10d0c7bf 949326f6d40c4d49a93fffac8b958b49 - -
default default]
http://10.10.1.83:8776/v3/949326f6d40c4d49a93fffac8b958b49/volumes/detail?all_tenants=1&name=test1
returned with HTTP 200 2022-08-11 17:17:28.081 21 INFO
cinder.api.openstack.wsgi [None
req-a2a433a3-50e6-4f2f-923b-21b0251338ca
9c8f8ded6e5947278acc0e5f10d0c7bf 949326f6d40c4d49a93fffac8b958b49 - -
default default] GET
http://10.10.1.83:8776/v3/949326f6d40c4d49a93fffac8b958b49/scheduler-stats/get_pools?detail=true
2022-08-11 17:17:28.359 22 ERROR cinder.api.middleware.fault [None
req-8ffc0660-49a5-4533-a60d-b4494d039203
9c8f8ded6e5947278acc0e5f10d0c7bf 949326f6d40c4d49a93fffac8b958b49 - -
default default] Caught error: <class
'oslo_messaging.exceptions.MessagingTimeout'> Timed out waiting for a
reply to message ID 56b3bf40bf824e1085283682367d1793:
oslo_messaging.exceptions.MessagingTimeout: Timed out waiting for a
reply to message ID 56b3bf40bf824e1085283682367d1793 2022-08-11
17:17:28.359 22 ERROR cinder.api.middleware.fault Traceback (most
recent call last): 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault   File
"/var/lib/kolla/venv/lib/python3.10/site-packages/oslo_messaging/_drivers/amqpdriver.py",
line 441, in get 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault  return
self._queues[msg_id].get(block=True, timeout=timeout) 2022-08-11
17:17:28.359 22 ERROR cinder.api.middleware.fault   File
"/usr/lib/python3.10/queue.py", line 179, in get 2022-08-11
17:17:28.359 22 ERROR cinder.api.middleware.fault  raise Empty
2022-08-11 17:17:28.359 22 ERROR cinder.api.middleware.fault
_queue.Empty 2022-08-11 17:17:28.359 22 ERROR cinder.api.middleware.fault 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault During handling of the above exception,
another exception occurred: 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault Traceback (most recent call last):
2022-08-11 17:17:28.359 22 ERROR cinder.api.middleware.fault   File
"/var/lib/kolla/venv/lib/python3.10/site-packages/cinder/api/middleware/fault.py",
line 84, in __call__ 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault  return req.get_response(self.application)
2022-08-11 17:17:28.359 22 ERROR cinder.api.middleware.fault   File
"/var/lib/kolla/venv/lib/python3.10/site-packages/webob/request.py",
line 1313, in send 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault  status, headers, app_iter =
self.call_application( 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault   File
"/var/lib/kolla/venv/lib/python3.10/site-packages/webob/request.py",
line 1278, in call_application 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault  app_iter = application(self.environ,
start_response) 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault   File
"/var/lib/kolla/venv/lib/python3.10/site-packages/webob/dec.py", line
143, in __call__ 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault  return resp(environ, start_response)
2022-08-11 17:17:28.359 22 ERROR cinder.api.middleware.fault   File
"/var/lib/kolla/venv/lib/python3.10/site-packages/webob/dec.py", line
129, in __call__ 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault  resp = self.call_func(req, *args, **kw)
2022-08-11 17:17:28.359 22 ERROR cinder.api.middleware.fault   File
"/var/lib/kolla/venv/lib/python3.10/site-packages/webob/dec.py", line
193, in call_func 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault  return self.func(req, *args, **kwargs)
2022-08-11 17:17:28.359 22 ERROR cinder.api.middleware.fault   File
"/var/lib/kolla/venv/lib/python3.10/site-packages/osprofiler/web.py",
line 111, in __call__ 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault  return
request.get_response(self.application) 2022-08-11 17:17:28.359 22
ERROR cinder.api.middleware.fault   File
"/var/lib/kolla/venv/lib/python3.10/site-packages/webob/request.py",
line 1313, in send 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault  status, headers, app_iter =
self.call_application( 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault   File
"/var/lib/kolla/venv/lib/python3.10/site-packages/webob/request.py",
line 1278, in call_application 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault  app_iter = application(self.environ,
start_response) 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault   File
"/var/lib/kolla/venv/lib/python3.10/site-packages/webob/dec.py", line
129, in __call__ 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault  resp = self.call_func(req, *args, **kw)
2022-08-11 17:17:28.359 22 ERROR cinder.api.middleware.fault   File
"/var/lib/kolla/venv/lib/python3.10/site-packages/webob/dec.py", line
193, in call_func 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault  return self.func(req, *args, **kwargs)
2022-08-11 17:17:28.359 22 ERROR cinder.api.middleware.fault   File
"/var/lib/kolla/venv/lib/python3.10/site-packages/keystonemiddleware/auth_token/__init__.py",
line 341, in __call__ 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault  response = req.get_response(self._app)
2022-08-11 17:17:28.359 22 ERROR cinder.api.middleware.fault   File
"/var/lib/kolla/venv/lib/python3.10/site-packages/webob/request.py",
line 1313, in send 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault  status, headers, app_iter =
self.call_application( 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault   File
"/var/lib/kolla/venv/lib/python3.10/site-packages/webob/request.py",
line 1278, in call_application 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault  app_iter = application(self.environ,
start_response) 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault   File
"/var/lib/kolla/venv/lib/python3.10/site-packages/webob/dec.py", line
143, in __call__ 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault  return resp(environ, start_response)
2022-08-11 17:17:28.359 22 ERROR cinder.api.middleware.fault   File
"/var/lib/kolla/venv/lib/python3.10/site-packages/webob/dec.py", line
143, in __call__ 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault  return resp(environ, start_response)
2022-08-11 17:17:28.359 22 ERROR cinder.api.middleware.fault   File
"/var/lib/kolla/venv/lib/python3.10/site-packages/routes/middleware.py",
line 153, in __call__ 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault  response = self.app(environ,
start_response) 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault   File
"/var/lib/kolla/venv/lib/python3.10/site-packages/webob/dec.py", line
143, in __call__ 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault  return resp(environ, start_response)
2022-08-11 17:17:28.359 22 ERROR cinder.api.middleware.fault   File
"/var/lib/kolla/venv/lib/python3.10/site-packages/webob/dec.py", line
129, in __call__ 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault  resp = self.call_func(req, *args, **kw)
2022-08-11 17:17:28.359 22 ERROR cinder.api.middleware.fault   File
"/var/lib/kolla/venv/lib/python3.10/site-packages/webob/dec.py", line
193, in call_func 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault  return self.func(req, *args, **kwargs)
2022-08-11 17:17:28.359 22 ERROR cinder.api.middleware.fault   File
"/var/lib/kolla/venv/lib/python3.10/site-packages/cinder/api/openstack/wsgi.py",
line 839, in __call__ 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault  return self._process_stack(request,
action, action_args, 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault   File
"/var/lib/kolla/venv/lib/python3.10/site-packages/cinder/api/openstack/wsgi.py",
line 900, in _process_stack 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault  action_result = self.dispatch(meth,
request, action_args) 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault   File
"/var/lib/kolla/venv/lib/python3.10/site-packages/cinder/api/openstack/wsgi.py",
line 995, in dispatch 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault  return method(req=request, **action_args)
2022-08-11 17:17:28.359 22 ERROR cinder.api.middleware.fault   File
"/var/lib/kolla/venv/lib/python3.10/site-packages/cinder/api/contrib/scheduler_stats.py",
line 60, in get_pools 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault  pools =
self.scheduler_api.get_pools(context, filters=filters) 2022-08-11
17:17:28.359 22 ERROR cinder.api.middleware.fault   File
"/var/lib/kolla/venv/lib/python3.10/site-packages/cinder/scheduler/rpcapi.py",
line 199, in get_pools 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault  return cctxt.call(ctxt, 'get_pools',
filters=filters) 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault   File
"/var/lib/kolla/venv/lib/python3.10/site-packages/oslo_messaging/rpc/client.py",
line 189, in call 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault  result = self.transport._send( 2022-08-11
17:17:28.359 22 ERROR cinder.api.middleware.fault   File
"/var/lib/kolla/venv/lib/python3.10/site-packages/oslo_messaging/transport.py",
line 123, in _send 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault  return self._driver.send(target, ctxt,
message, 2022-08-11 17:17:28.359 22 ERROR cinder.api.middleware.fault 
File
"/var/lib/kolla/venv/lib/python3.10/site-packages/oslo_messaging/_drivers/amqpdriver.py",
line 689, in send 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault  return self._send(target, ctxt, message,
wait_for_reply, timeout, 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault   File
"/var/lib/kolla/venv/lib/python3.10/site-packages/oslo_messaging/_drivers/amqpdriver.py",
line 678, in _send 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault  result = self._waiter.wait(msg_id,
timeout, 2022-08-11 17:17:28.359 22 ERROR cinder.api.middleware.fault 
File
"/var/lib/kolla/venv/lib/python3.10/site-packages/oslo_messaging/_drivers/amqpdriver.py",
line 567, in wait 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault  message = self.waiters.get(msg_id,
timeout=timeout) 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault   File
"/var/lib/kolla/venv/lib/python3.10/site-packages/oslo_messaging/_drivers/amqpdriver.py",
line 443, in get 2022-08-11 17:17:28.359 22 ERROR
cinder.api.middleware.fault  raise oslo_messaging.MessagingTimeout(
2022-08-11 17:17:28.359 22 ERROR cinder.api.middleware.fault
oslo_messaging.exceptions.MessagingTimeout: Timed out waiting for a
reply to message ID 56b3bf40bf824e1085283682367d1793 2022-08-11
17:17:28.359 22 ERROR cinder.api.middleware.fault 2022-08-11
17:17:28.362 22 INFO cinder.api.middleware.fault [None
req-8ffc0660-49a5-4533-a60d-b4494d039203
9c8f8ded6e5947278acc0e5f10d0c7bf 949326f6d40c4d49a93fffac8b958b49 - -
default default]
http://10.10.1.83:8776/v3/949326f6d40c4d49a93fffac8b958b49/scheduler-stats/get_pools?detail=true
returned with HTTP HTTPStatus.INTERNAL_SERVER_ERROR

You should check your rabbitmq logs, everything related to messaging points to rabbitmq. Does `openstack volume service list` show it as up? — eblock, Aug 17 '22 at 08:35
Thanks for taking your time to reply.. I couldn't figure it out from the logs earlier , since we have less time we just restarted cinder and rabbitmq and that fixed the issue. — xrkr, Aug 19 '22 at 11:49
If restarting fixed it I suggest to look out for any traces pointing to resource bottlenecks, like max open files or something like that. IIRC we had an issue a while ago when we noticed rabbitmq interruptions and noticed we had notifications enabled but no consumer. After we disabled the notifications rabbit consumed way less resources and worked more stable. But as I wrote, there is some bottleneck which I recommend to find or you'll end up with a cronjob restarting services. ;-) — eblock, Aug 19 '22 at 12:10
@eblock Thanks for your valuable suggestions. Will certainly look into it — xrkr, Aug 25 '22 at 10:07

openstack yoga volume creation fails

0 Answers0