Cinder

Volume or Snapshot not found ERROR in c-api log after successful tempest run

Bug #1243485 reported by David Kranz on 2013-10-23

This bug affects 2 people

Affects		Status	Importance	Assigned to	Milestone
	Cinder	Fix Released	Low	John Griffith	Cinder 2014.1 "icehouse"

Bug Description

Happens a log, for example in http://logs.openstack.org/81/52181/8/check/check-tempest-devstack-vm-postgres-full/aa99a8c/logs/screen-c-api.txt.gz

2013-10-23 01:20:17.784 22210 ERROR cinder.api.middleware.fault [req-fec0ce89-321d-4cac-9a13-11edb6270993 bcf3db5a242f42d9b2e05d2adf9e4b13 6240d8b99d584ebd87a89b63e39f3a0b] Caught error: Snapshot 7e7b9afe-d872-4ae0-b8d7-42b326dbb978 could not be found.
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault Traceback (most recent call last):
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/cinder/cinder/api/middleware/fault.py", line 77, in __call__
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault return req.get_response(self.application)
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault File "/usr/local/lib/python2.7/dist-packages/webob/request.py", line 1296, in send
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault application, catch_exc_info=False)
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault File "/usr/local/lib/python2.7/dist-packages/webob/request.py", line 1260, in call_application
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault app_iter = application(self.environ, start_response)
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault return resp(environ, start_response)
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/python-keystoneclient/keystoneclient/middleware/auth_token.py", line 571, in __call__
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault return self.app(env, start_response)
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault return resp(environ, start_response)
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault return resp(environ, start_response)
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/routes/middleware.py", line 131, in __call__
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault response = self.app(environ, start_response)
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault return resp(environ, start_response)
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 130, in __call__
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault resp = self.call_func(req, *args, **self.kwargs)
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 195, in call_func
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault return self.func(req, *args, **kwargs)
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/cinder/cinder/api/openstack/wsgi.py", line 827, in __call__
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault content_type, body, accept)
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/cinder/cinder/api/openstack/wsgi.py", line 875, in _process_stack
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault action_result = self.dispatch(meth, request, action_args)
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/cinder/cinder/api/openstack/wsgi.py", line 951, in dispatch
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault return method(req=request, **action_args)
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/cinder/cinder/api/v1/volumes.py", line 383, in create
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault snapshot_id)
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/cinder/cinder/volume/api.py", line 330, in get_snapshot
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault rv = self.db.snapshot_get(context, snapshot_id)
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/cinder/cinder/db/api.py", line 267, in snapshot_get
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault return IMPL.snapshot_get(context, snapshot_id)
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/cinder/cinder/db/sqlalchemy/api.py", line 138, in wrapper
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault return f(*args, **kwargs)
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/cinder/cinder/db/sqlalchemy/api.py", line 1480, in snapshot_get
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault return _snapshot_get(context, snapshot_id)
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/cinder/cinder/db/sqlalchemy/api.py", line 138, in wrapper
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault return f(*args, **kwargs)
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/cinder/cinder/db/sqlalchemy/api.py", line 1473, in _snapshot_get
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault raise exception.SnapshotNotFound(snapshot_id=snapshot_id)
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault SnapshotNotFound: Snapshot 7e7b9afe-d872-4ae0-b8d7-42b326dbb978 could not be found.
2013-10-23 01:20:17.784 22210 TRACE cinder.api.middleware.fault
2013-10-23 01:20:17.786 22210 INFO cinder.api.middleware.fault [req-fec0ce89-321d-4cac-9a13-11edb6270993 bcf3db5a242f42d9b2e05d2adf9e4b13 6240d8b99d584ebd87a89b63e39f3a0b] http://127.0.0.1:8776/v1/6240d8b99d584ebd87a89b63e39f3a0b/volumes returned with HTTP 404
2013-10-23 01:20:17.797 22210 DEBUG keystoneclient.middleware.auth_token [-] Authenticating user token __call__ /opt/stack/new/python-keystoneclient/keystoneclient/middleware/auth_token.py:558
2013-10-23 01:20:17.797 22210 DEBUG keystoneclient.middleware.auth_token [-] Removing headers from request environment: X-Identity-Status,X-Domain-Id,X-Domain-Name,X-Project-Id,X-Project-Name,X-Project-Domain-Id,X-Project-Domain-Name,X-User-Id,X-User-Name,X-User-Domain-Id,X-User-Domain-Name,X-Roles,X-Service-Catalog,X-User,X-Tenant-Id,X-Tenant-Name,X-Tenant,X-Role _remove_auth_headers /opt/stack/new/python-keystoneclient/keystoneclient/middleware/auth_token.py:617
2013-10-23 01:20:17.798 22210 DEBUG keystoneclient.middleware.auth_token [-] Returning cached token ba5f0f940d4cc2f687d5825436378d55 _cache_get /opt/stack/new/python-keystoneclient/keystoneclient/middleware/auth_token.py:1016
2013-10-23 01:20:17.798 22210 DEBUG keystoneclient.middleware.auth_token [-] Received request from user: bcf3db5a242f42d9b2e05d2adf9e4b13 with project_id : 6240d8b99d584ebd87a89b63e39f3a0b and roles: _member_ _build_user_headers /opt/stack/new/python-keystoneclient/keystoneclient/middleware/auth_token.py:922
2013-10-23 01:20:17.799 22210 DEBUG routes.middleware [-] Matched POST /6240d8b99d584ebd87a89b63e39f3a0b/volumes __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:100
2013-10-23 01:20:17.799 22210 DEBUG routes.middleware [-] Route path: '/{project_id}/volumes', defaults: {'action': u'create', 'controller': <cinder.api.openstack.wsgi.Resource object at 0x4809910>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:102
2013-10-23 01:20:17.799 22210 DEBUG routes.middleware [-] Match dict: {'action': u'create', 'controller': <cinder.api.openstack.wsgi.Resource object at 0x4809910>, 'project_id': u'6240d8b99d584ebd87a89b63e39f3a0b'} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:103
2013-10-23 01:20:17.799 22210 INFO cinder.api.openstack.wsgi [req-2de5058a-06d4-468f-be2a-e50928757e25 bcf3db5a242f42d9b2e05d2adf9e4b13 6240d8b99d584ebd87a89b63e39f3a0b] POST http://127.0.0.1:8776/v1/6240d8b99d584ebd87a89b63e39f3a0b/volumes
2013-10-23 01:20:17.800 22210 DEBUG cinder.api.v1.volumes [req-2de5058a-06d4-468f-be2a-e50928757e25 bcf3db5a242f42d9b2e05d2adf9e4b13 6240d8b99d584ebd87a89b63e39f3a0b] Create volume request body: {'volume': {'scheduler_hints': {}, 'metadata': {u'Type': u'work'}, 'display_name': u'Volume--tempest-572743380', 'source_volid': u'e4974f44-969d-4cef-944d-2fd9b2b78458', 'size': u'1'}} create /opt/stack/new/cinder/cinder/api/v1/volumes.py:358
2013-10-23 01:20:17.813 22210 WARNING cinder.quota [req-1f98a6d8-005d-4976-a9ee-68c9a0ff4c63 fcd199daea8940918ded6d1a9dd8862a 487a496cac7f4b639ebc6bcb85ce87bf] Deprecated: Default quota for resource: gigabytes is set by the default quota flag: quota_gigabytes, it is now deprecated. Please use the the default quota class for default quota.
2013-10-23 01:20:17.813 22210 WARNING cinder.quota [req-1f98a6d8-005d-4976-a9ee-68c9a0ff4c63 fcd199daea8940918ded6d1a9dd8862a 487a496cac7f4b639ebc6bcb85ce87bf] Deprecated: Default quota for resource: volumes is set by the default quota flag: quota_volumes, it is now deprecated. Please use the the default quota class for default quota.
2013-10-23 01:20:17.817 22210 ERROR cinder.api.middleware.fault [req-2de5058a-06d4-468f-be2a-e50928757e25 bcf3db5a242f42d9b2e05d2adf9e4b13 6240d8b99d584ebd87a89b63e39f3a0b] Caught error: Volume e4974f44-969d-4cef-944d-2fd9b2b78458 could not be found.
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault Traceback (most recent call last):
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/cinder/cinder/api/middleware/fault.py", line 77, in __call__
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault return req.get_response(self.application)
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault File "/usr/local/lib/python2.7/dist-packages/webob/request.py", line 1296, in send
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault application, catch_exc_info=False)
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault File "/usr/local/lib/python2.7/dist-packages/webob/request.py", line 1260, in call_application
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault app_iter = application(self.environ, start_response)
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault return resp(environ, start_response)
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/python-keystoneclient/keystoneclient/middleware/auth_token.py", line 571, in __call__
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault return self.app(env, start_response)
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault return resp(environ, start_response)
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault return resp(environ, start_response)
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/routes/middleware.py", line 131, in __call__
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault response = self.app(environ, start_response)
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault return resp(environ, start_response)
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 130, in __call__
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault resp = self.call_func(req, *args, **self.kwargs)
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 195, in call_func
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault return self.func(req, *args, **kwargs)
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/cinder/cinder/api/openstack/wsgi.py", line 827, in __call__
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault content_type, body, accept)
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/cinder/cinder/api/openstack/wsgi.py", line 875, in _process_stack
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault action_result = self.dispatch(meth, request, action_args)
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/cinder/cinder/api/openstack/wsgi.py", line 951, in dispatch
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault return method(req=request, **action_args)
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/cinder/cinder/api/v1/volumes.py", line 390, in create
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault source_volid)
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/cinder/cinder/volume/api.py", line 335, in get_volume
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault rv = self.db.volume_get(context, volume_id)
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/cinder/cinder/db/api.py", line 213, in volume_get
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault return IMPL.volume_get(context, volume_id)
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/cinder/cinder/db/sqlalchemy/api.py", line 138, in wrapper
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault return f(*args, **kwargs)
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/cinder/cinder/db/sqlalchemy/api.py", line 1149, in volume_get
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault return _volume_get(context, volume_id)
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/cinder/cinder/db/sqlalchemy/api.py", line 138, in wrapper
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault return f(*args, **kwargs)
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/cinder/cinder/db/sqlalchemy/api.py", line 1142, in _volume_get
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault raise exception.VolumeNotFound(volume_id=volume_id)
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault VolumeNotFound: Volume e4974f44-969d-4cef-944d-2fd9b2b78458 could not be found.
2013-10-23 01:20:17.817 22210 TRACE cinder.api.middleware.fault

2013-10-23 01:23:50.139 22210 ERROR cinder.api.middleware.fault [req-3c68c3cd-7647-4717-a5be-5e1a0bffcab9 c562188b400e44a3b9d3900495ecf748 5dada9a2750641eab97cc64931d55961] Caught error: Snapshot 6095dd59-1e8a-46d5-bfee-4d2dccbf7f91 could not be found.
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault Traceback (most recent call last):
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/cinder/cinder/api/middleware/fault.py", line 77, in __call__
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault return req.get_response(self.application)
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault File "/usr/local/lib/python2.7/dist-packages/webob/request.py", line 1296, in send
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault application, catch_exc_info=False)
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault File "/usr/local/lib/python2.7/dist-packages/webob/request.py", line 1260, in call_application
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault app_iter = application(self.environ, start_response)
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault return resp(environ, start_response)
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/python-keystoneclient/keystoneclient/middleware/auth_token.py", line 571, in __call__
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault return self.app(env, start_response)
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault return resp(environ, start_response)
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault return resp(environ, start_response)
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault File "/usr/lib/python2.7/dist-packages/routes/middleware.py", line 131, in __call__
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault response = self.app(environ, start_response)
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 144, in __call__
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault return resp(environ, start_response)
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 130, in __call__
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault resp = self.call_func(req, *args, **self.kwargs)
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault File "/usr/local/lib/python2.7/dist-packages/webob/dec.py", line 195, in call_func
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault return self.func(req, *args, **kwargs)
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/cinder/cinder/api/openstack/wsgi.py", line 827, in __call__
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault content_type, body, accept)
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/cinder/cinder/api/openstack/wsgi.py", line 875, in _process_stack
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault action_result = self.dispatch(meth, request, action_args)
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/cinder/cinder/api/openstack/wsgi.py", line 951, in dispatch
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault return method(req=request, **action_args)
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/cinder/cinder/api/v1/volumes.py", line 383, in create
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault snapshot_id)
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/cinder/cinder/volume/api.py", line 330, in get_snapshot
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault rv = self.db.snapshot_get(context, snapshot_id)
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/cinder/cinder/db/api.py", line 267, in snapshot_get
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault return IMPL.snapshot_get(context, snapshot_id)
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/cinder/cinder/db/sqlalchemy/api.py", line 138, in wrapper
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault return f(*args, **kwargs)
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/cinder/cinder/db/sqlalchemy/api.py", line 1480, in snapshot_get
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault return _snapshot_get(context, snapshot_id)
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/cinder/cinder/db/sqlalchemy/api.py", line 138, in wrapper
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault return f(*args, **kwargs)
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault File "/opt/stack/new/cinder/cinder/db/sqlalchemy/api.py", line 1473, in _snapshot_get
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault raise exception.SnapshotNotFound(snapshot_id=snapshot_id)
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault SnapshotNotFound: Snapshot 6095dd59-1e8a-46d5-bfee-4d2dccbf7f91 could not be found.
2013-10-23 01:23:50.139 22210 TRACE cinder.api.middleware.fault
2013-10-23 01:23:50.140 22210 INFO cinder.api.middleware.fault [req-3c68c3cd-7647-4717-a5be-5e1a0bffcab9 c562188b400e44a3b9d3900495ecf748 5dada9a2750641eab97cc64931d55961] http://127.0.0.1:8776/v1/5dada9a2750641eab97cc64931d55961/volumes returned with HTTP 404

Revision history for this message

John Griffith (john-griffith) wrote on 2013-10-23:

So I pointed this out before, so long as we're doing negative tests in tempest (ie "get non-existent volume") we're going to have error messages in the logs.

That being said, we shouldn't trace and that I'll get fixed up. The error message however won't go away.

Changed in cinder:
status:	New → Triaged
importance:	Undecided → Low
assignee:	nobody → John Griffith (john-griffith)

Revision history for this message

David Kranz (david-kranz) wrote on 2013-10-23:

I thought there was consensus that an ERROR in a server log should indicate a problem that needs operator attention or that there is a bug in OpenStack code that should be reported. It is fine to log something if a client request is invalid but it should be at DEBUG or INFO level. The work that is generating these bug reports has the near-term goal to start failing builds if there are ERRORs in logs.

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2013-10-23: Fix proposed to cinder (master)

Fix proposed to branch: master
Review: https://review.openstack.org/53443

Changed in cinder:
status:	Triaged → In Progress

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2013-10-24: Fix merged to cinder (master)

Reviewed: https://review.openstack.org/53443
Committed: http://github.com/openstack/cinder/commit/4adf35778b3aae3db99a90a1bbb94e668ec7963d
Submitter: Jenkins
Branch: master

commit 4adf35778b3aae3db99a90a1bbb94e668ec7963d
Author: John Griffith <email address hidden>
Date: Wed Oct 23 20:08:30 2013 +0000

Handle NotFound exceptions in API

    There were a number of calls in the API that
    weren't catching NotFound exceptions. The result is
    unhandled exception traces and errors in the logs on good
    runs in tempest.

    Basicly any negative test that requests a non-existent element
    would result in an unhandled exception. This patch adds try/except
    around the volume_api.getxxx calls in cinder/api/... methods to
    clean this up.

Closes-bug: #1243485

Change-Id: I902acc7f4fdbc20fdb1a68697679417694c5533e

Changed in cinder:
status:	In Progress → Fix Committed

John Griffith (john-griffith) on 2013-12-03

Changed in cinder:
milestone:	none → icehouse-1

Thierry Carrez (ttx) on 2013-12-04

Changed in cinder:
status:	Fix Committed → Fix Released

Thierry Carrez (ttx) on 2014-04-17

Changed in cinder:
milestone:	icehouse-1 → 2014.1

Report a bug

This report contains Public information

Everyone can see this information.

You are

Subscribing...

Edit bug mail

Other bug subscribers

Remote bug watches

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